Stream every probe's report as it is measured - #85
Conversation
…an stream into
Completed item: M1.1: Decide how a formatted line reaches the sink, because that
choice is what makes the rest mechanical.
Option (b) of the three the item offered: `LineSink`, an adapter implementing
`std::fmt::Write` over a `&mut dyn Report`.
The item's own estimate decided the question once it was re-measured. It said
"upwards of 160" `writeln!` sites; there are 504 across the production
renderers, written into the `&mut String` of about twenty functions. Option (a),
a `Report` method taking `fmt::Arguments` plus a macro, is the most explicit and
would have rewritten every one of those 504 -- affordable at 160, not at 504.
Option (b) moves the twenty signatures and leaves the 504 untouched, because
`String` implements `fmt::Write` too and a call site cannot tell the difference.
Option (c) was declined as a half-measure that keeps two buffers.
The cost the item predicted for (b) is real and is paid here rather than
deferred. `fmt::Write` is line-agnostic -- `write_str` receives fragments,
multiple lines, or a bare newline -- while `Report` speaks in lines and
`Captured` is addressable by line, so the sink holds a partial line and emits
only completed ones.
Seven tests pin that, and the two properties easiest to get wrong were verified
by sabotage rather than by reading:
- A report whose final call is `write!` rather than `writeln!` must still emit
that line; `finish` does it. Removing it fails two tests. Without it a report
loses exactly its last row, which is invisible except as an absence.
- `split('\n')`, not `lines()`: only the former distinguishes text that ended on
a newline from text that did not, which is what decides whether the tail is a
finished line or a partial one. Substituting `lines()` fails three tests.
One test asserts the correspondence M1.2 will depend on -- that writing through
the sink gives a reader exactly what composing a `String` and handing it to
`emit` gives today -- so the conversion can be mechanical rather than a silent
change to every report.
No renderer is converted yet; that is M1.2, and the buffering decision is marked
as being superseded rather than rewritten, because it still describes the code
until then.
Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
…tch-and-resume Completed item: M1.2: Convert every renderer to write into the sink as it measures, and simplify `emit_report` accordingly. All sixteen probes now take `out: &mut dyn std::fmt::Write` and their lines reach the `Report` as they are composed. The `catch_unwind`/`resume_unwind` pair is deleted rather than kept: with lines leaving as they are produced there is no buffer to rescue, so it would have been machinery that no longer earned its place -- and it would have kept implying that partial output depends on the panic unwinding, which is the limitation this milestone removes. `Captured` is untouched and its tests pass unchanged. The 504 `writeln!` call sites are untouched, which is what M1.1 chose option (b) for. Three probes needed more than a signature change, because they never went through `emit_report` at all: `core_affinity`, `peer_index_cache` and `queue_contention` each composed a `String` and called `emit` directly. They are branch-local and so missed the round that fixed the same bypass in the peeled probes, which means this crate's "every probe routes through this, with no exceptions" claim was false in three places. `core_affinity` additionally measured in `main`'s argument list, ahead of the renderer, so a topology read that failed produced no banner and no indication of which probe had died; it now measures after the banner and reports that failure as a failure to observe the host rather than as a finding about it. **Verifying that no report changed needed a control, and that is the part worth keeping.** A direct before/after comparison flagged nine of fifteen reports -- which is not evidence, because these probes print measured nanoseconds and branch their verdicts on them. Running the same build twice differed by as much or more: `peer-index-cache` differs on 22 lines between two runs of one build, against 20 across the conversion. The twelve deterministic reports were structurally identical before and after. A before/after diff on a probe means nothing without that control, and it would have been easy to read the raw differences as either a regression or noise without measuring which. The panic test's assertions are unchanged, which is the point: the property held by machinery before and holds by construction now. Its explanation is rewritten, because it named a `resume_unwind` that no longer exists. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
…nterrupted probe Completed item: M1.3: Verify by interruption, not by reasoning. Completes M1, which is archived to COMPLETED-CHECKLIST.md and its PLANS.md row updated. **The unit test this item specified would not have caught a regression.** It asked for "a renderer that panics mid-report still has its finished lines in a `Captured`", and that passes under a buffered report too -- emit the buffer after catching the unwind and it holds, which is exactly what the pre-M1.2 code did. What distinguishes streaming is not what a reader has at the end but WHEN the sink receives it. So `a_line_reaches_the_sink_before_the_renderer_returns` observes the sink from inside the renderer, through an `Rc<RefCell<..>>` shared with a `Report` impl, and asserts a completed line is already there while rendering continues. Restoring the old buffered `emit_report_to` fails it with its own message. **The interruption half is measured, with a control.** `probe-queue-contention` takes about 65 seconds; started with stdout redirected and killed at 8 seconds, the streaming build had 114 bytes on disk -- the host banner and the heading -- and the pre-M1.2 build, built from `246687e` and run through the identical sequence, had 0. The control is what makes it evidence. Reading 114 bytes from the new build shows only that something was written; reading zero from the old one shows the change caused it. `TerminateProcess` was used rather than Ctrl-C, deliberately and as the stronger case: Ctrl-C runs the default console handler and lets the runtime unwind its exit path, while `TerminateProcess` runs nothing at all, so anything still in a userspace buffer is lost outright. A report that survives it survives a Ctrl-C. Recorded in DESIGN-NOTES with the reason it works at all: Rust's `Stdout` wraps a `LineWriter` and flushes at each newline even when redirected, so a line has reached the OS before the next is composed. Had stdout been block-buffered this milestone would have needed a per-line flush as well. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
…probes Every figure M1 recorded was measured on a branch carrying sixteen probes, three of which are not in this crate. Carried over unchanged, the numbers would describe a build a reader of this history cannot produce, and cite probes they cannot find. So each was measured again here. - Call sites: 332 across 18 renderer signatures, not 504 across twenty. The argument is unchanged and the conclusion is the same -- an option costing "rewrite every call site" is affordable at 160 and is not at 332 -- but the estimate this crate can check is 332. - Interruption: the 65-second subject does not exist here, and the longest probe in this crate runs 0.8 s. Re-measured on `probe-doorbell-cost` at a 300 ms kill, six runs per build, each run recording whether the process was still alive when killed rather than inferring it from the byte count: streaming captured 129 characters on six of six, the pre-conversion build 0 on six of six. - Determinism control: 4 of 13 reports differ across the change, while the same-build-twice control differs in 5, by the same amount or more in every case. `probe-cancel-io` is the sharpest: not deterministic, yet it matched across the change, so a before/after diff read alone would have counted it as evidence from a probe that varies run to run. Also corrects the claim that three probes bypassed `emit_report`. That is true of three branch-local probes and false of every probe here, where the one-sink refactor already holds -- which is precisely why converting this crate is one function plus one line per renderer. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
There was a problem hiding this comment.
🟡 Changes recommended
There is at least one verified documentation inconsistency in changed code (LineSink rustdoc cites an outdated call-site count) that should be corrected before merge.
Once you've addressed the issues Copilot identified, you can request another Copilot review.
Pull request overview
This PR converts windows-platform-probes report rendering from buffered String composition to line-by-line streaming into a Report, so already-measured output is preserved even if the process is interrupted or aborts mid-run.
Changes:
- Introduces
LineSink(fmt::Writeadapter) to stream formatted output intoReportone completed line at a time. - Updates
emit_report/emit_report_toand all probe renderers to write to&mut dyn fmt::Write(removing the oldcatch_unwind/resume_unwindbuffering path). - Adds focused unit tests for line reassembly semantics and updates planning/design docs to reflect the completed milestone.
File summaries
| File | Description |
|---|---|
| PLANS.md | Marks the streaming-report milestone as in progress with M1 completed/archived and M2 remaining. |
| crates/windows-platform-probes/src/report.rs | Adds LineSink, switches emit APIs to &mut dyn fmt::Write, and removes catch/emit/resume buffering logic. |
| crates/windows-platform-probes/src/report/tests.rs | Adds unit tests that pin LineSink’s line reassembly behavior and streaming-on-panic semantics. |
| crates/windows-platform-probes/src/long_path_report.rs | Updates renderer API to &mut dyn fmt::Write. |
| crates/windows-platform-probes/src/bin/worker_context.rs | Updates renderer API to &mut dyn fmt::Write. |
| crates/windows-platform-probes/src/bin/topology.rs | Updates renderer API and switches from push_str to write! for fmt::Write compatibility. |
| crates/windows-platform-probes/src/bin/request_cost.rs | Updates renderer API to &mut dyn fmt::Write. |
| crates/windows-platform-probes/src/bin/pool_growth.rs | Updates helper + renderer APIs to &mut dyn fmt::Write. |
| crates/windows-platform-probes/src/bin/ioring.rs | Updates renderer API to &mut dyn fmt::Write. |
| crates/windows-platform-probes/src/bin/handle_state.rs | Updates renderer API to &mut dyn fmt::Write. |
| crates/windows-platform-probes/src/bin/error_mode.rs | Updates renderer API to &mut dyn fmt::Write. |
| crates/windows-platform-probes/src/bin/doorbell_cost.rs | Updates renderer API to &mut dyn fmt::Write. |
| crates/windows-platform-probes/src/bin/device_map.rs | Updates renderer + helper APIs to &mut dyn fmt::Write. |
| crates/windows-platform-probes/src/bin/completion_port.rs | Updates renderer + helpers to &mut dyn fmt::Write. |
| crates/windows-platform-probes/src/bin/cancel_io.rs | Updates renderer API to &mut dyn fmt::Write. |
| crates/windows-platform-probes/DESIGN-NOTES.md | Records the new streaming design and marks the prior buffered-report decision as superseded. |
| crates/windows-platform-probes/CHECKLIST.md | Removes the completed M1 section, leaving M2 as remaining work. |
| crates/windows-platform-probes/COMPLETED-CHECKLIST.md | Archives M1 work items and supporting evidence as completed history. |
Review details
- Files reviewed: 18/18 changed files
- Comments generated: 1
- Review effort level: Lite
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
Co-authored-by: Copilot Autofix powered by AI <175728472+Copilot@users.noreply.github.com>
There was a problem hiding this comment.
🟢 Approval recommended
The streaming conversion is consistent and well-tested; the remaining feedback is limited to small documentation/performance refinements.
Review details
Suppressed comments (1)
Previously missed (1) — in code that hasn't changed since the last review.
crates/windows-platform-probes/src/report.rs:157
LineSink::write_strcurrently usesstd::mem::take(&mut self.partial)for every newline, which drops the accumulatedStringeach time and can force a re-allocation for the next line. You can reuse the existing buffer by emitting fromself.partial, clearing it, and then appending the next piece.
- Files reviewed: 18/18 changed files
- Comments generated: 1
- Review effort level: Lite
| /// A [`Report`] a renderer can `writeln!` into directly. | ||
| /// | ||
| /// is arithmetic. Every renderer writes through `writeln!(out, ...)` against a | ||
| /// `String`, at **332 sites** across this crate; a sink method taking | ||
| /// `fmt::Arguments` would have been explicit but would have rewritten every one | ||
| /// of them, while `String` already implements `fmt::Write`, so a sink that does | ||
| /// too lets those sites stand untouched and moves only 18 renderer signatures. | ||
| /// signatures. The recorded reasoning is in | ||
| /// [DESIGN-NOTES.md](../DESIGN-NOTES.md#d-streaming-report). |
Peels the streaming-report slice ("A") out of #56.
A probe's report was composed into a
Stringand printed at the end, so a run that did not exit normally -- Ctrl-C, a hard kill, an abort during unwinding -- discarded everything it had already measured. That cost most on the probes that run longest, which are exactly the ones worth interrupting.What changed
LineSinkimplementsfmt::Writeover a&mut dyn Report, holding a partial line and emitting completed ones.emit_reportandemit_report_tonow takeimpl FnOnce(&mut dyn fmt::Write)instead of&mut String, and every renderer takesout: &mut dyn std::fmt::Write.The signature was chosen by counting, not by taste. A
Reportmethod takingfmt::Argumentswould have been more explicit but would have rewritten all 332writeln!sites;fmt::Writemoves 18 signatures and leaves the 332 untouched, becauseStringimplementsfmt::Writetoo and a call site cannot tell the difference. M1 had estimated "upwards of 160" sites -- re-measuring at the moment the estimate became a decision is what picked the option.The
catch_unwind/resume_unwindpair is deleted: with lines leaving as they are produced there is no buffer to rescue, and keeping it would imply partial output still depends on the panic unwinding.There is deliberately no
Dropimpl onLineSink. Flushing a trailing unterminated fragment would need one, and aDropthat writes can panic while unwinding -- which aborts, replacing a diagnosable failure with one that explains nothing. An unterminated fragment is not a finding, so the trade is one-sided.Evidence
The unit test as originally specified would not have caught a regression. "A renderer that panics mid-report still has its finished lines" passes under a buffered report too -- emit the buffer after catching the unwind and it holds, which is what the old code did. What distinguishes streaming is not what a reader has at the end but when the sink receives it, so
a_line_reaches_the_sink_before_the_renderer_returnsobserves the sink from inside the renderer through a sharedRc<RefCell<..>>. Restoring the old bufferedemit_report_tofails it with its own message.split('\n')rather thanlines()is load-bearing -- only the former distinguishes text ending on a newline from text that does not. Sabotaging it fails 3 tests; removingfinishfails 2.Interruption is measured, with a control.
probe-doorbell-cost(~0.8 s, the longest-running probe here), stdout redirected, killed at 300 ms, six runs per build, each run recording whether the process was still alive at the kill rather than inferring it from the byte count:TerminateProcesswas used rather than Ctrl-C deliberately: it runs no handler at all, where Ctrl-C still lets the runtime unwind its exit path, so surviving it subsumes the interactive case. Any of it works only because Rust'sStdoutwraps aLineWriterthat flushes at each newline even when redirected -- block-buffered stdout would have needed an explicit per-line flush.No report changed, and that needed a control too. A direct before/after diff flags 4 of 13 reports -- which is not evidence, since these probes print measured nanoseconds. Running the same build twice differs in 5, by the same amount or more in every case.
probe-cancel-iois the sharpest: not deterministic, yet it matched across the change, so a before/after diff read alone would have counted it as evidence from a probe that varies run to run. The 8 reports the control showed to be genuinely deterministic were byte-identical.Note for review
Every figure M1 originally recorded was measured on a branch carrying sixteen probes, three of which are not in this crate. Rather than carry numbers describing a build no reader here can produce, each was re-measured against this crate in the final commit -- 332 sites not 504,
probe-doorbell-costnotprobe-queue-contention, 13 probes not 16. The conclusions are unchanged; the evidence is now reproducible from this branch alone.158 tests pass;
cargo check --all-targetsis warning-free workspace-wide; clippy and fmt clean.