Exp 136: completion-side reader-handler scheduling counter

[danReynolds]

Hypothesis

After exp 120 and exp 121, signals.json#stream-rerun-dispatch.blockedOnMeasurement listed two named gating measurements: writer-isolate wall split (handled by in-flight exp 135) and completion-side microtask scheduling cost counter (this PR). On A11c overlap, the bulk of remaining main-isolate wall should land in the reader worker port handler chain. Building the counter resolves the entry — accepts the area if the fraction is large, or rules it out if small.

Approach

• ProfileCounters gains four main-isolate fields: completionHandlerUs / completionHandlerCount (reader-pool worker port handler synchronous body) and streamEmitUs / streamEmitCount (StreamEntry.emit subscriber-fanout loop). Since _WorkerSlot.request uses Completer<Object?>.sync(), the handler counter captures the whole _dispatch resume / _requery continuation / entry.emit / _flushQueue chain in one stopwatch.
• audit_workloads.dart gains an optional countersAfterDrain snapshot and switches A11c's fixed-50ms drain to the same quiet-window pattern keyed-PK already uses. Existing exp 119 / exp 121 audits ignore the new field and continue using the burst-end counters.
• New harness benchmark/profile/completion_scheduling_audit.dart formats the A11c (baseline / disjoint / overlap) + keyed-PK report.

Results

Four repeated passes; aggregate at benchmark/profile/results/exp-136-completion-scheduling-aggregate.md. Pass-d numbers shown; other passes match the same band.

workload	wall_ms	drain_ms	total_ms	completion / total	µs / completion	emit / completion
A11c baseline (0 streams)	53.1	0.0	53.1	—	—	—
A11c disjoint (50 streams)	42.1	54.0	96.2	0%	—	—
A11c overlap (50 streams)	107.1	102.6	209.7	22–27%	11–15 µs	< 1%
keyed PK (50 streams)	24.6	203.5	228.1	4–5%	8–9 µs	< 1%

Reader-completion chain is the largest reachable main-isolate slice on A11c overlap. 99.2% of 3,700–3,900 replies per burst short-circuit via selectIfChanged hash (28–31 actual subscriber emits), so subscriber-fanout is not the cost — per-call wall is bootstrap-shaped (Future resolution + hash check + _flushQueue admit). On disjoint the counter is 0 because exp 106 column elision blocks every re-query; on keyed-PK absolute completion wall is 11 ms.

dispatcher_parked_total = 0, dispatcher_wake_retry_total = 0, and dispatcher_max_parked_concurrent = 0 on every workload — exp 120 / exp 122 hold post-instrumentation.

Outcome

Accepted — measurement. Closes the completion-side microtask scheduling cost counter entry in signals.json#stream-rerun-dispatch.blockedOnMeasurement. Makes reader-reply batching the bounded implementation candidate that follows; a future experiment in that direction must drop completion_us / total_us on A11c overlap and stay neutral on disjoint and keyed-PK (otherwise the release-suite delta is workload-specific). After this lands together with in-flight exp 135 (writer-isolate split), the stream-rerun-dispatch.blockedOnMeasurement array is empty.

Test plan

• dart analyze --fatal-infos on edited files (profile_counters.dart, stream_engine.dart, reader_pool.dart, audit_workloads.dart, completion_scheduling_audit.dart) — clean.
• dart test test/database_test.dart — 47/47 pass.
• dart test test/stream_test.dart test/stream_invalidation_coalescing_test.dart test/stream_dependency_shapes_test.dart — pass.
• dart run -DRESQLITE_PROFILE=true benchmark/profile/invalidation_traversal_audit.dart — exp 121's audit still produces in-band numbers (invalidate 14.7% of overlap burst wall).
• dart run -DRESQLITE_PROFILE=true benchmark/profile/completion_scheduling_audit.dart --markdown — four passes, aggregate committed.

🤖 Generated with Claude Code

[Copilot]

Pull request overview

Measurement-only experiment that adds profile-mode counters for the main-isolate reader-completion handler chain (completion_handler_us/count) and StreamEntry.emit fanout (stream_emit_us/count), plus a new audit harness to read them. Concludes that reader-completion handling is 22–27% of A11c overlap total wall, making reader-reply batching the next bounded candidate; subscriber fanout (<1%) is not.

Changes:

• Add four ProfileCounters fields and instrument _WorkerSlot normal-reply branch and StreamEntry.emit under kProfileMode.
• Extend audit_workloads.dart with an optional post-drain counters snapshot and switch A11c drain to the quiet-window pattern.
• Add completion_scheduling_audit.dart harness, aggregate result, experiment writeup, journal entries, and signals.json bookkeeping (closes the blockedOnMeasurement entry, archives 119, adds exp 136 to keyPriors).

Reviewed changes

Copilot reviewed 10 out of 10 changed files in this pull request and generated no comments.

Show a summary per file

File	Description
lib/src/profile_counters.dart	Adds four completion/emit counters with snapshot+reset wiring
lib/src/reader/reader_pool.dart	Wraps normal-reply handler body in profile-mode stopwatch
lib/src/stream_engine.dart	Wraps StreamEntry.emit fanout loop in profile-mode stopwatch
benchmark/profile/audit_workloads.dart	Adds countersAfterDrain/drainUs and quiet-window A11c drain
benchmark/profile/completion_scheduling_audit.dart	New harness rendering the markdown report
benchmark/profile/results/exp-136-completion-scheduling-aggregate.md	Committed pass-d aggregate report
experiments/136-completion-microtask-counter.md	Experiment writeup with hypothesis/results/decision
experiments/JOURNAL.md	Two new lessons (drain-snapshot timing, worktree pub get)
experiments/README.md	Adds exp 136 to In Review row
experiments/signals.json	Updates currentRead/keyPriors/archive/blockedOnMeasurement; adds exp 136 entry

---

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.