exp 136: stream completion-side wall audit

[danReynolds]

Hypothesis

Exp 135 found the writer-isolate handler is only ~22-25% of A11c overlap burst wall — the remaining ~75% lives on the main isolate. The completion-side microtask scheduling cost counter entry in signals.json#stream-rerun-dispatch.blockedOnMeasurement is what gates the next dispatch implementation experiment.

This measurement experiment ships that counter. The hypothesis: of the ~75% main-isolate share, the synchronous post-await body of StreamEngine._requery (bookkeeping, hash-changed shortcut, entry.emit, trailing _flushQueue re-entry) plus the StreamEntry.emit fanout for-loop account for a measurable, structurally bounded share that future dispatch experiments must clear.

Approach

• Four new profile-mode counters: streamCompleteUs, streamCompleteCount, streamEmitUs, streamEmitCount. All gated behind kProfileMode so release builds tree-shake the recording.
• Instrument StreamEngine._requery: start the stopwatch right after the selectIfChanged await resolves; record in the existing finally after _flushQueue re-enters. The cross-isolate round-trip never inflates the wall.
• Instrument StreamEntry.emit: wrap the subscriber for-loop only. streamEmitUs is a strict subset of streamCompleteUs.
• New audit harness benchmark/profile/stream_completion_audit.dart reuses the audit_workloads.dart A11c / keyed-PK scenarios exp 119 / 121 / 135 share. Reports raw counters and derived fractions including accounted / wall = (invalidate_us + complete_us) / wall_us.
• Existing test/profile_counters_test.dart extended to round-trip the new keys through snapshot / reset.

Full writeup: experiments/136-stream-completion-counter.md.

Results

Four repeated passes (a/b/c/d) — d is the saved aggregate at benchmark/profile/results/exp-136-stream-completion-aggregate.md:

workload	wall_ms (a/b/c/d)	complete / wall	invalidate / wall	accounted / wall	us per complete
A11c baseline (0 streams x 500)	37.4 / 32.8 / 32.8 / 32.4	0 / 0 / 0 / 0 %	0 / 0 / 0 / 0 %	0 / 0 / 0 / 0 %	n/a
A11c disjoint (50 streams x 500)	42.3 / 38.8 / 37.6 / 37.3	0 / 0 / 0 / 0 %	18.9 / 21.7 / 21.0 / 21.1 %	18.9 / 21.7 / 21.0 / 21.1 %	n/a
A11c overlap (50 streams x 500)	89.5 / 87.4 / 86.3 / 91.7	29.8 / 29.5 / 29.8 / 31.7 %	15.1 / 14.7 / 15.0 / 14.9 %	44.9 / 44.2 / 44.8 / 46.7 %	7.1 / 6.9 / 6.8 / 7.4 µs
keyed PK subs (50 streams x 200)	20.1 / 19.4 / 19.4 / 23.7	21.6 / 20.8 / 22.2 / 19.5 %	15.3 / 15.5 / 15.2 / 13.9 %	36.9 / 36.3 / 37.3 / 33.5 %	4.1 / 3.8 / 4.1 / 4.1 µs

Sanity: dispatcher_parked_total = 0, dispatcher_wake_retry_total = 0, dispatcher_max_parked_concurrent = 0 on every workload — exp 120 / 122 still hold.

Headline reading:

• A11c overlap: complete_us ~30% of wall (very tight band across 4 passes), emit_us <0.3% (hash-suppression keeps emissions to ~20-35 per 500-write burst). Combined with exp 121's invalidate_us (~15%), synchronous main-isolate stream-engine code accounts for ~45% of wall. The remaining ~55% is framework microtask scheduling, async/await chaining, reader-pool internals, and subscriber callback dispatch the counters cannot reach.
• A11c disjoint: complete_us = 0 (column elision filters every re-query at invalidation time, so _requery never fires).
• Keyed-PK: ~20-22% complete + ~14-15% invalidate, per-handler ~4 µs across ~1,050 handlers per burst.

Outcome

Accept for review — measurement. Closes the last blockedOnMeasurement entry in stream-rerun-dispatch direction. The next dispatch implementation experiment must clear a per-handler complete_us target on A11c overlap (~7 µs of ~3,750 handlers per burst) reproducibly across a 5-run release suite. Three speculative follow-ups are now evaluable: _flushQueue re-entry collapse, hash-suppressed completion fast-path, per-completion batching — none committed.

Test plan

• dart analyze --fatal-infos lib/ benchmark/profile/ test/profile_counters_test.dart
• dart test test/profile_counters_test.dart test/stream_test.dart test/stream_invalidation_coalescing_test.dart test/stream_dependency_shapes_test.dart test/stream_cache_hit_reliability_test.dart test/stream_overflow_fallback_test.dart test/stream_trigger_cascade_test.dart — all pass
• dart run benchmark/generate_history.dart — parsed 115 experiments, 118 benchmark runs
• 4 repeated audit passes (dart run -DRESQLITE_PROFILE=true benchmark/profile/stream_completion_audit.dart --markdown) with stable bands per the table above

🤖 Generated with Claude Code

[Copilot]

Pull request overview

Adds profile-mode instrumentation and audit harnesses to quantify stream “completion-side” main-isolate wall time (and writer-side handler vs SQLite time) so future stream dispatch experiments can be gated by concrete counters rather than wall-time noise.

Changes:

• Introduces new ProfileCounters keys for writer handler/SQLite wall and stream completion/emit wall, plus snapshot/reset plumbing for writer-isolate counters.
• Instruments StreamEngine._requery and StreamEntry.emit to record completion-side counters (gated behind kProfileMode).
• Adds/extends benchmark audit harnesses, experiment writeups, signals metadata, and tests to validate counter snapshot/reset wiring.

Reviewed changes

Copilot reviewed 18 out of 18 changed files in this pull request and generated 3 comments.

Show a summary per file

File	Description
test/profile_counters_test.dart	Extends snapshot/diff/reset tests to include new writer + stream completion counters.
test/database_test.dart	Adds tests ensuring writer counter snapshot/reset APIs round-trip keys without throwing.
lib/src/writer/writer.dart	Adds writer-isolate counter snapshot/reset RPC helpers on the main isolate.
lib/src/writer/write_worker.dart	Implements writer-isolate snapshot/reset requests and instruments handler + SQLite wall timers.
lib/src/stream_engine.dart	Instruments _requery completion path and emit fanout loop for new counters.
lib/src/profile_counters.dart	Adds new counter fields/keys and wires them into snapshot/reset.
lib/src/database.dart	Exposes writer-isolate counter snapshot/reset APIs at Database level.
benchmark/profile/audit_workloads.dart	Resets and merges writer-isolate counters into shared audit scenario results.
benchmark/profile/writer_step_wall_audit.dart	New exp-135 harness reporting writer handler vs SQLite wall fractions.
benchmark/profile/stream_completion_audit.dart	New exp-136 harness reporting completion/emit wall fractions and derived metrics.
benchmark/profile/results/exp-135-writer-step-wall-aggregate.md	Saved aggregate output from exp-135 harness.
benchmark/profile/results/exp-136-stream-completion-aggregate.md	Saved aggregate output from exp-136 harness.
experiments/135-writer-step-wall-audit.md	New experiment writeup documenting approach/results for exp 135.
experiments/136-stream-completion-counter.md	New experiment writeup documenting approach/results for exp 136.
experiments/signals.json	Updates direction narrative, clears blockedOnMeasurement, and adds entries for 135/136.
experiments/README.md	Adds experiment index entries for 135 and 136.
experiments/JOURNAL.md	Adds guidance on cross-isolate counter export via snapshot RPC.
docs/experiments/history.json	Regenerates published experiment history to include 135/136.

---

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

[danReynolds]

Closing this older exp 136 branch as superseded. PR #110 now carries the exp 135 writer-dispatch measurement lane, and PR #113 carries the cleaner current exp 136 completion-side scheduling measurement without the older stacked writer-counter changes. Keeping this open would duplicate the experiment queue rather than add new signal.