From 88a75bcd62bf87a2050a2fe8fe3d51ee7be70fb9 Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Sun, 6 Sep 2026 23:37:57 -0400 Subject: [PATCH] refactor(platform-probes): route every probe's output through one sink Stage 1 of peeling `windows-platform-probes` off `mikegrier/deferred-namespace-ops` (#56). It comes first because everything else in that crate's remaining work is built on it: the new probes all report through `report`, and `lib.rs` on `main` has no such module. The repository's architectural pre-step says an output abstraction is introduced at the *first* occurrence, and these eight probes had grown a `println!` per finding. Each now composes its whole report as text and hands it to `emit`, so the real stream is named in `report` and nowhere else. Retargeting a probe -- to a file, a buffer, a test -- stops being a rewrite. `report` is deliberately small: a `Report` sink trait, a `Stdout` implementation, a `Captured` one for tests, and `emit`/`emit_report`. Its unit tests cover what a caller can get wrong rather than what the trait obviously does -- line order preserved, a trailing newline not becoming a blank line, an interior blank line surviving, and a block emitted line-at-a-time. A mutation run over `report.rs` found those five insufficient, and the gap was the one that mattered: `::line` replaced with `()` survived the whole suite. `Captured` is what every in-process test uses, so nothing exercised the implementation the probes actually run with -- a no-op there means every probe runs, exits zero, and prints nothing, which is the failure mode that looks most like success. Covering it needs a real child process, since stable Rust cannot redirect this process's own stdout, which is what makes `tests/a_probe_writes_its_report_to_stdout.rs` an integration test by the repository's criterion rather than by preference. It runs `probe-error-mode` -- no privileges, no particular hardware -- and asserts the report exists, opens with the host banner, and carries more than that banner. Confirmed load-bearing: the mutation run goes from 5 caught / 1 missed to **6 caught / 0 missed**. Every probe's report now opens with `windows-placement-probe`'s banner naming the machine and whether the measurement is tainted. That is what makes a captured report safe to paste somewhere: without it a finding can be compared against a machine it does not describe. Rendering it inside the report rather than printing it separately is the point -- it travels with the text. Two Cargo.toml changes, both required by the above: - `windows-placement-probe` as a path dependency, for that banner. - The `version = "0.1.3"` pin dropped from `windows-threadpool-sys`. A `version` beside a `path` is consulted only when packaging, but cargo still requires the path crate's version to satisfy it on *every* build -- so a pin left behind by a release breaks workspace resolution rather than just this crate's. This crate is `publish = false` (verified, not assumed), so the pin bought nothing. The comment states the policy so the next dependency added here does not reintroduce one. Verified by running, not only by building: - `cargo check --all-targets` on this package alone against `main`'s tree, which is what establishes the subset is self-contained rather than merely part of a working branch. - Workspace `clippy --all-targets --all-features` clean; `fmt --check` clean. - The `report` tests are wired and actually execute -- checked by name, because a `tests.rs` that is never declared is a silent no-op. - `probe-error-mode` run end to end: it opens with the host banner and its findings are intact. A refactor of code whose entire output is a report is not verified by compiling it. - `check-publishable`, `check-workflow-refs`, and the encoding check all pass. Three defects a code review found in the first draft of this commit, fixed here rather than deferred: - **Buffering the report meant a panic destroyed it.** Each `render` composed into a local `String` and returned it, so nothing reached stdout unless it returned normally -- while `worker_context` composes several completed findings and then calls an observation documented to panic three ways, and `cancel_io` asserts after its first case. Printing line-by-line had made partial output automatic; the refactor silently gave that up, which for an instrument whose purpose is that a failure be diagnosable throws away exactly the information worth keeping. `main` is now one `emit_report(render)` call that owns the buffer, catches an unwind, emits what was composed, and resumes the panic -- so the exit status and message are unchanged and the partial report is added to them. Verified by injecting a panic mid-`render`: the already-measured lines print and the process still exits 101. - **`writeln_to` had no callers.** Its doc claimed a convention the crate did not follow -- 156 `let _ = writeln!` sites across the eight probes -- and it could not have served most of them anyway, since it takes `&str` while nearly every site is formatted. A `pub` item on a library target is exempt from `dead_code`, so nothing flagged it. Removed, with its test replaced by one for `emit_report`. - **The module doc claimed "All fourteen" probes route through the sink.** There are eight; the count came from the originating branch, which is precisely the error a stage-1 peel invites. The invariant is now stated without a number, so it stays true as probes are added. A second review round found the test for that first fix did not test it, and that is the more useful finding of the two: - **The panic test never called the function it was named for.** It re-implemented catch-emit-resume against a `Captured` and asserted against its own copy, so the property held in the test and nothing tied it to `report.rs`. Deleting the `resume_unwind` would have left it green -- and a probe that swallows its panic prints a partial report and exits **0**, which is the failure that looks most like success, and the exact defect the fix existed to prevent. The logic now lives in `emit_report_to`, taking the sink as an argument, with `emit_report` a one-line `Stdout` wrapper; the test drives the real function through a `Captured` and asserts both halves -- the finished lines survive, *and* the panic reaches the caller. Verified by sabotage in both directions: deleting the `resume_unwind` fails the second assertion, deleting the `emit` fails the first, and each leaves the other passing. A mutation run had reported 6/6 caught over the old test, which is worth recording -- whole- function-body mutants never generate the single-branch deletion, so a green mutants run is not evidence that every branch is bound. It is now 7/7. - **Buffering still loses everything when termination does not unwind.** Ctrl-C (the default Windows console handler terminates the process) and an abort from a panic during unwinding both discard the buffer, where the line-by-line printing this commit replaces would have kept it. The sharpest case is `probe-cancel-io`, which runs about twenty seconds precisely when the wedge it hunts for occurs -- precisely when a reader interrupts. This is not fixed here. The honest fix is renderers writing into a `Report` as they go rather than into a `String`, which restores streaming for every termination mode and keeps `Captured` working; that changes every renderer and is a different design rather than a defect in this one. So the bound is stated on `emit_report`, the trade-off it comes from is recorded as [The report is buffered, and what that costs] in the crate's DESIGN-NOTES, and the fix is **queued** as milestone M1 of a new `crates/windows-platform-probes/CHECKLIST.md` -- not left as prose in a design note, which this repository treats as orphaned rather than scheduled. The crate had a PLANS.md but no checklist; its pending work was tracked in the workspace `CHECKLIST-thread-ambient.md`, which is feature-scoped and deleted when that feature completes, so durable follow-up could not live there. A third review round found three stale restatements, two of them made stale by this commit -- the blast-radius sweep the repository asks for, which I had run inside the crate and not outside it: - **`CHECKLIST-mutation-survivors.md` MS-2.1 was invalidated.** It recorded that "twelve of these probes still print directly rather than through the `Report` sink" and that the sink's checklist "is not in this repository yet", so whoever picked it up would think the prerequisite was blocked on an off-repository branch item when it had just landed. Corrected -- but not to the reviewer's reading. The 2026-09-02 sweep measured a **fourteen**-probe tree, and six of those (`core_affinity`, `peer_index_cache`, `doorbell_cost`, `queue_contention`, `request_cost`, `topology`) exist only on the originating branch, so "zero probes now print directly" is true of this repository and not of what the sweep scored. The item now says which tree it measured, that the eight probes here route through the sink, and that what remains of `SH-13.4` is the six that are still branch-only. - **`report.rs`'s one-stream rationale asserted something the crate contradicts.** It justified having no `problem` method with "none of them is a diagnostic competing with the report" -- while `Impersonation::drop` does `eprintln!` a `RevertToSelf` warning, reachable from `probe-worker-context` on exactly the panic path `emit_report_to` exists to serve. A load-bearing premise, since the next contributor weighing a second stream reads it. Restated: nothing in a *report* is a diagnostic, and that warning belongs to the process rather than the measurement, which is why stderr already separates it -- an argument for one stream that survives the counter-example instead of denying it. - **A count went stale the moment this commit added a line.** The DESIGN-NOTES said `worker_context` "composes seven completed findings" before its panicking call; seven was right on `main` and this commit's banner made it eight statements and nine lines, while `report.rs`'s parallel sentence said "several" and stayed true. Two further copies in this message were wrong the same way, and a third said "seven other modules" when the branch has six left after `report`. All now unnumbered or corrected, which is the only form that does not rot. A fourth round, on the opened PR, raised three points; two were right and one was not: - **The copyright header on the two new `report` files did not match the crate.** They carried `// Copyright (c) 2026 Mike Grier`, taken verbatim from the originating branch, while all nineteen other files here use `// Copyright (c) Mike Grier.` -- and the third file this commit adds already used the crate's form, so the two new ones were inconsistent even with their own change. Aligned; the crate is now one form throughout. Worth noting the repository as a whole is the other way round (290 files with the year against 114 without), so this is local consistency chosen over global, on the grounds that a reader scans a crate. - **`Report` was reported as an unused import in the test module. It is not.** `Captured::line` is a trait method, so the trait must be in scope; removing the import produces three `E0599`s ("no method named `line` found for struct `Captured`"), which is how this was settled rather than by reading. Clippy over `--all-targets --all-features` was already clean, which it could not have been had the import been dead. No change made. A fifth round found that comment wrong in eight more places, and it was wrong because of this commit's own first fix: - **"The only place that names the real stream" was false in every probe's `main`.** It was true of the first draft, where `main` read `emit(&mut Stdout, &render())` and did name the stream. Round 1 replaced that with `emit_report(render)` to stop a panic destroying the report -- and from then on `main` named no stream at all, while the comment above it still claimed to be the one place that did. The stream is named at `report.rs:65` (`println!`) and `report.rs:145` (`&mut Stdout`); `Stdout` does not appear in any bin. Eight identical copies, each corrected to say what `main` really is: the probe's whole output policy in one line, choosing no stream. The same sentence had also propagated into the DESIGN-NOTES decision and this message, both fixed here. That is three rounds running in which the finding was a correction that had not propagated rather than an original defect, and this one was self-inflicted -- a fix in one file invalidating a comment in eight others, with nothing to detect it. Exactly the failure CONTRACT INTEGRITY names. A sixth round found three more, all correct: - **Another claim that did not survive the change.** The module doc said each conversion was checked by "capturing the probe's output before and after and requiring the two to match" -- while the same conversion prepends a host banner, so the two cannot match. Restated: every pre-existing line must match in the same order, and the banner is the one deliberate difference, the only one permitted. Same class as the previous two rounds, and the third instance in this PR of a sentence that was true when written and falsified by a later part of the same change. - **Two file references written as inline code rather than links.** The repository asks that a reference a reader is meant to open be a relative markdown link, and that this applies to source files as well as documents. Both were mine, added in the third and fourth rounds. Fixed; targets verified to resolve. The bare filenames elsewhere in `CHECKLIST-mutation-survivors.md` (`fs.rs`, `watcher.rs`, ...) are deliberately left: they are identifiers inside a survivor listing, not navigation targets, and they predate this commit. Deliberately excluded, so this stays reviewable: the six other modules `lib.rs` gains on the branch, the new probe binaries, and the topology tests in `src/tests.rs`. Those are later stages and each depends on this one. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- CHECKLIST-mutation-survivors.md | 27 ++- Cargo.lock | 1 + PLANS.md | 1 + crates/windows-platform-probes/CHECKLIST.md | 55 ++++++ crates/windows-platform-probes/Cargo.toml | 18 +- .../windows-platform-probes/DESIGN-NOTES.md | 45 ++++- crates/windows-platform-probes/PLANS.md | 1 + .../src/bin/cancel_io.rs | 94 ++++++++-- .../src/bin/completion_port.rs | 122 +++++++++--- .../src/bin/device_map.rs | 129 +++++++++---- .../src/bin/error_mode.rs | 57 +++++- .../src/bin/handle_state.rs | 54 ++++-- .../windows-platform-probes/src/bin/ioring.rs | 109 ++++++++--- .../src/bin/pool_growth.rs | 80 ++++++-- .../src/bin/worker_context.rs | 85 ++++++--- crates/windows-platform-probes/src/lib.rs | 1 + crates/windows-platform-probes/src/report.rs | 173 ++++++++++++++++++ .../src/report/tests.rs | 110 +++++++++++ .../a_probe_writes_its_report_to_stdout.rs | 72 ++++++++ 19 files changed, 1057 insertions(+), 177 deletions(-) create mode 100644 crates/windows-platform-probes/CHECKLIST.md create mode 100644 crates/windows-platform-probes/src/report.rs create mode 100644 crates/windows-platform-probes/src/report/tests.rs create mode 100644 crates/windows-platform-probes/tests/a_probe_writes_its_report_to_stdout.rs diff --git a/CHECKLIST-mutation-survivors.md b/CHECKLIST-mutation-survivors.md index 6c6193eba..25fb74035 100644 --- a/CHECKLIST-mutation-survivors.md +++ b/CHECKLIST-mutation-survivors.md @@ -77,15 +77,28 @@ to the engineer, not to whoever picks up this checklist. - [ ] **MS-2.1** -- **`windows-platform-probes`: 511 survivors, 17% caught.** See [windows-platform-probes.md](mutation-sweeps/2026-09-02/windows-platform-probes.md). - Fourteen executable probes you *run* to answer a question about Windows, not a - library with a test surface; `publish = false` at version `0.0.0`. Most of the + Executable probes you *run* to answer a question about Windows, not a library + with a test surface; `publish = false` at version `0.0.0`. Most of the survivors are `main`-adjacent code no test was ever going to reach. Judging this crate by mutation score is measuring the wrong thing. - A related, separately-tracked item: twelve of these probes still print - directly rather than through the `Report` sink, tracked as `SH-13.4` on the - branch that ships the topology and queue crates. That checklist is not in this - repository yet, so this deliberately names the item rather than linking a file - that does not exist. Doing that first would make some of this reachable. + **The sweep measured a fourteen-probe tree, of which eight are in this + repository** -- `core_affinity`, `peer_index_cache`, `doorbell_cost`, + `queue_contention`, `request_cost` and `topology` were only ever on the + originating branch, so six of the fourteen sections in the sweep report have no + counterpart here yet. Read the totals with that in mind before scoping any of + it. + A related, separately-tracked item, **partly discharged**: at sweep time twelve + of those fourteen probes printed directly rather than through a `Report` sink, + tracked as `SH-13.4` on the branch that ships the topology and queue crates. + The sink has since landed here + ([crates/windows-platform-probes/src/report.rs](crates/windows-platform-probes/src/report.rs)) + and all eight probes in this repository route through it, so what remains of + `SH-13.4` is the six branch-only probes, and it stays named rather than linked + because that branch checklist is still not in this repository. The crate's own + durable work now has a home to link: + [crates/windows-platform-probes/CHECKLIST.md](crates/windows-platform-probes/CHECKLIST.md). + For the eight that landed, the "would make some of this reachable" prerequisite + is met -- each `main` is one line and each report is a `String` a test can read. - [ ] **MS-2.2** -- **`windows-file-watcher-example-test-harness`: 69 survivors.** See [windows-file-watcher-example-test-harness.md](mutation-sweeps/2026-09-02/windows-file-watcher-example-test-harness.md). diff --git a/Cargo.lock b/Cargo.lock index 7b40a6ac3..176b48503 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -216,6 +216,7 @@ dependencies = [ name = "windows-platform-probes" version = "0.0.0" dependencies = [ + "windows-placement-probe", "windows-sys", "windows-threadpool-sys", ] diff --git a/PLANS.md b/PLANS.md index 99e7599d2..3d9617bae 100644 --- a/PLANS.md +++ b/PLANS.md @@ -20,6 +20,7 @@ plans tracker: [crates/windows-file-enumeration-sys/PLANS.md](crates/windows-fil | [CHECKLIST-thread-ambient.md](CHECKLIST-thread-ambient.md) | in progress | M22-M23: extract the captured-context composite into `windows-thread-ambient-sys`, a standalone platform layer that captures a thread's ambient state and applies it on another thread. M24-M26: `windows-namespace-request-sys`, marshalable Win32 namespace call parameter sets, over a round-one entry list audited from three real consumers (this repository's watcher and enumeration crates, and `MikeGrier/Globazog-rs`) rather than guessed. M27: `windows-platform-probes`, a durable home for the measurements this workspace's designs rest on, under a three-tier scheme (asserted / ignored / binary-only) where every tier is compiled by an ordinary build. Feature-scoped and deleted when complete; it is the whole of the `mikegrier/thread-ambient` branch's work, and is deliberately separate from the deferred namespace-facility items in [CHECKLIST.md](CHECKLIST.md). | [crates/windows-thread-ambient-sys/DESIGN-NOTES.md](crates/windows-thread-ambient-sys/DESIGN-NOTES.md) | | [crates/windows-overlapped-io-sys/CHECKLIST.md](crates/windows-overlapped-io-sys/CHECKLIST.md) | not started | M14: finish the contract audit -- categories 1, 2, 6, 8, 9 were not examined -- and sweep `outstanding()` for the advisory-predicate hazard. | [crates/windows-overlapped-io-sys/DESIGN-NOTES.md](crates/windows-overlapped-io-sys/DESIGN-NOTES.md) | | [crates/windows-ioring-sys/CHECKLIST.md](crates/windows-ioring-sys/CHECKLIST.md) | in progress | Memory-safe Rust over the Windows `IoRing` submission/completion ring, as a new crate. M1-M7 (ring lifecycle through the `ring-copy` topology-aligned sample) are complete and archived. The parked, pinned-thread `M6+` work and the new M10 contract audit remain. | [crates/windows-ioring-sys/DESIGN-NOTES.md](crates/windows-ioring-sys/DESIGN-NOTES.md) | +| [crates/windows-platform-probes/CHECKLIST.md](crates/windows-platform-probes/CHECKLIST.md) | not started | M1: stream a probe's report as it is measured. The one-sink refactor has each renderer compose its report into a `String`, which buys the seam that lets a probe's findings be asserted rather than eyeballed, and gives up output appearing as it is measured. `emit_report` recovers that for an unwinding panic only; Ctrl-C and an abort during unwinding still discard the buffer. Costs most on `probe-cancel-io`, which runs about twenty seconds precisely when the wedge it hunts for occurs -- precisely when a reader interrupts. | [crates/windows-platform-probes/DESIGN-NOTES.md](crates/windows-platform-probes/DESIGN-NOTES.md#d-buffered-report) | | [CHECKLIST-mutation-survivors.md](CHECKLIST-mutation-survivors.md) | not started | Work queued from the workspace-wide cargo-mutants sweep of 2026-09-02, whose findings are kept in [mutation-sweeps/2026-09-02/](mutation-sweeps/2026-09-02/README.md) rather than re-derived -- the run took roughly fourteen hours. 2,792 caught, 1,112 survived, 198 timed out. **The headline numbers mislead in three ways and the README says how**: a timeout in a blocking-API crate is usually a detection that lost its name rather than a gap (measured: one of `windows-waitable-queues`' 120 timeouts fails four tests in 0.00s when re-injected alone), a low score on an executable probe crate is measuring the wrong thing, and three kinds of survivor -- equivalent mutants, unreachable code, and constants that want a `const` assertion -- are not missing tests at all. M1 covers the shipping crates; M2 holds the two crates that are not libraries and whose scope is an engineer's decision; M3 re-runs and prunes rather than hand-editing the tool's output into a second source of truth. | [mutation-sweeps/2026-09-02/README.md](mutation-sweeps/2026-09-02/README.md) | Add a row here when new work is planned, against [CHECKLIST.md](CHECKLIST.md) or any crate's. diff --git a/crates/windows-platform-probes/CHECKLIST.md b/crates/windows-platform-probes/CHECKLIST.md new file mode 100644 index 000000000..ea01dcd05 --- /dev/null +++ b/crates/windows-platform-probes/CHECKLIST.md @@ -0,0 +1,55 @@ +# Checklist: windows-platform-probes + +Design decisions are in [DESIGN-NOTES.md](DESIGN-NOTES.md). This crate's *creation* is tracked +separately, in the workspace [CHECKLIST-thread-ambient.md](../../CHECKLIST-thread-ambient.md) milestone +M27; that file is feature-scoped and is deleted when its feature completes, so durable follow-up work +for the crate belongs here instead. + +## M1 -- Stream a probe's report as it is measured + +The report sink introduced with [src/report.rs](src/report.rs) has each renderer compose its whole +report into a `String`, which `emit_report` then hands to a [`Report`]. That buys the seam the crate +wanted -- a probe's findings can be asserted rather than eyeballed -- and it gave up a property the +previous line-by-line `println!` had for free: output appearing as it is measured. + +`emit_report` recovers it for an **unwinding panic** only, by catching, emitting what was composed, and +resuming. A termination that does not unwind still discards the buffer: + +- **Ctrl-C.** The default Windows console handler terminates the process; no unwind runs. +- **Abort from a panic raised while already unwinding.** + +The case that costs most is `probe-cancel-io`: four attempts against a five-second watchdog, so about +twenty seconds, and it runs that long *precisely when the wedge it hunts for occurs* -- which is +precisely when a reader gives up and interrupts. The measurement most worth having is the one most +likely to be thrown away. + +See [DESIGN-NOTES.md](DESIGN-NOTES.md) -> [The report is buffered, and what that +costs](DESIGN-NOTES.md#d-buffered-report) for why it was built this way and why the fix is a separate +piece of work rather than a correction to that one. + +- [ ] **M1.1** -- Decide how a formatted line reaches the sink, because that choice is what makes the + rest mechanical. Every renderer today writes through `let _ = writeln!(out, ...)` against a + `String`'s `fmt::Write` -- roughly 156 sites across the eight probes -- so the sink must accept + *formatted* output, not just `&str`, or every site grows a `format!` and an allocation per line. + The options differ in what they cost callers, and the choice is the engineer's: + (a) give `Report` a method taking `fmt::Arguments` plus a `report_line!` macro, so a call site stays + one line and reads almost as it does now; + (b) implement `fmt::Write` for the sink types, so `writeln!(out, ...)` keeps working verbatim against + a `&mut dyn Report` -- smallest diff at the call sites, but `fmt::Write` is line-agnostic, so the sink + must split on newlines internally and `Captured`'s one-line-per-entry guarantee has to be re-established + rather than assumed; + (c) leave the renderers writing to a `String` and flush it to the sink at each line boundary, which + streams without touching the call sites but keeps two buffers. + +- [ ] **M1.2** -- Convert the eight renderers to write into the sink as they measure, and simplify + `emit_report` accordingly: once lines leave as they are produced, catching the unwind is no longer + what makes partial output work, and the `catch_unwind`/`resume_unwind` pair should be removed rather + than left as machinery that no longer earns its place. Keep `Captured` working -- it is what every + in-process test asserts against. + +- [ ] **M1.3** -- Verify by interruption, not by reasoning. Sending Ctrl-C to a probe part-way through + must leave the already-measured lines on the terminal; today it leaves nothing. Assert the in-process + half (a renderer that panics mid-report still has its finished lines in a `Captured`) as a unit test, + and record the Ctrl-C observation in [DESIGN-NOTES.md](DESIGN-NOTES.md) -- an interactive signal is not + something to assert in CI, but it is the property the milestone exists for, so it must be measured + once rather than assumed. diff --git a/crates/windows-platform-probes/Cargo.toml b/crates/windows-platform-probes/Cargo.toml index 185b2206c..b1a41e4ec 100644 --- a/crates/windows-platform-probes/Cargo.toml +++ b/crates/windows-platform-probes/Cargo.toml @@ -48,10 +48,26 @@ name = "probe-pool-growth" path = "src/bin/pool_growth.rs" [dependencies] +# **Every workspace dependency below is path-only, with no `version`**, because +# this crate is never distributed at all -- not to a registry, and not as a +# released binary either, unlike `windows-placement-probe` next door. These +# probes are a development instrument, run from a checkout, and `publish = false` +# above is the whole story. +# +# A `version` beside a `path` is consulted only when the depending crate is +# packaged, but cargo still requires the path crate's own version to satisfy it +# at every build -- so a pin left behind by a bump breaks the whole workspace's +# resolution rather than only this crate's. +# # The pool-growth probe measures the shipping API rather than a # reimplementation of the SDK's inline environment helpers, so it depends on the # real crate. -windows-threadpool-sys = { version = "0.1.3", path = "../windows-threadpool-sys" } +windows-threadpool-sys = { path = "../windows-threadpool-sys" } +# Every probe's report opens with a line naming the machine that produced it and +# whether the measurement is tainted, so a captured finding cannot be pasted +# somewhere and compared against something it does not describe. That banner is +# `windows-placement-probe`'s to render, not a second copy here. +windows-placement-probe = { path = "../windows-placement-probe" } [dependencies.windows-sys] version = "0.61.2" diff --git a/crates/windows-platform-probes/DESIGN-NOTES.md b/crates/windows-platform-probes/DESIGN-NOTES.md index b3d530db2..5d7b11673 100644 --- a/crates/windows-platform-probes/DESIGN-NOTES.md +++ b/crates/windows-platform-probes/DESIGN-NOTES.md @@ -1,7 +1,9 @@ # Design notes: windows-platform-probes -Decisions for this crate. Pending work is in the workspace -[CHECKLIST-thread-ambient.md](../../CHECKLIST-thread-ambient.md), milestone M27. +Decisions for this crate. Pending work is in [CHECKLIST.md](CHECKLIST.md); the +crate's *creation* is tracked separately in the workspace +[CHECKLIST-thread-ambient.md](../../CHECKLIST-thread-ambient.md), milestone M27, +which is feature-scoped and deleted when that feature completes. ## A probe is a function that returns an observation, never a program that prints one @@ -457,3 +459,42 @@ characters, so no mangling occurred -- an accident of environment, not of architecture. It would fail on any host with a longer user name, on either architecture. Recorded here because it is exactly the kind of result this comparison exists to classify correctly: a red build that is **not** a finding. + +## The report is buffered, and what that costs + + + +Every probe's output goes through one sink: the renderer composes its report into +a `String` and `emit_report` hands it to a [`Report`]. That is what the +repository's architectural pre-step asks for -- the real stream is named in +`report` and nowhere else, so a probe's `main` is one line that chooses no stream +at all -- and it is what lets a test assert a probe's findings instead of a human +reading them off a terminal. + +It also gave something up. Printing line-by-line meant whatever had been measured +was already on the terminal; buffering means nothing is, until the renderer +returns. These probes call into measurements documented to panic -- +`worker_context`'s impersonating observation panics three ways, and its renderer +composes several completed findings before reaching it -- stated without a count +deliberately, because the number moves whenever a line is added, and a stale count +is the drift this repository keeps paying for -- so this is not hypothetical. For an +instrument whose whole purpose is that a failure be diagnosable, how far it got is +exactly the information worth keeping. + +`emit_report` recovers it for an unwinding panic: catch, emit what was composed, +resume, so the exit status and message are unchanged and the partial report is +added to them rather than substituted. **It does not recover it for a termination +that does not unwind** -- Ctrl-C, which the default Windows console handler serves +by terminating the process, and an abort from a panic raised during unwinding. + +That bound is known rather than overlooked, and it is not a defect in +`emit_report` to be patched there: the fix is renderers writing into a [`Report`] +as they measure rather than into a `String`, which restores streaming for *every* +termination mode and makes the catch/resume machinery unnecessary. That changes +every renderer and the shape of the sink trait, so it is queued as its own work -- +[CHECKLIST.md](CHECKLIST.md) milestone M1 -- rather than folded into the commit +that introduced the sink. + +The ordering was deliberate. The sink had to exist before the probes could be +peeled off their originating branch in reviewable stages, and a design that +streams is a different design, not a later revision of this one. diff --git a/crates/windows-platform-probes/PLANS.md b/crates/windows-platform-probes/PLANS.md index 6e557be85..e2aa1b16a 100644 --- a/crates/windows-platform-probes/PLANS.md +++ b/crates/windows-platform-probes/PLANS.md @@ -4,4 +4,5 @@ Design decisions are in [DESIGN-NOTES.md](DESIGN-NOTES.md). | Path to CHECKLIST.md | Status | Brief description | Design Notes | |---|---|---|---| +| [CHECKLIST.md](CHECKLIST.md) | not started | M1: stream a probe's report as it is measured. The report sink buffers each report into a `String`, so a termination that does not unwind -- Ctrl-C, or an abort during unwinding -- discards it, where the line-by-line printing it replaced kept it. Costs most on `probe-cancel-io`, which runs about twenty seconds precisely when the wedge it hunts for occurs. | [DESIGN-NOTES.md](DESIGN-NOTES.md#d-buffered-report) | | [../../CHECKLIST-thread-ambient.md](../../CHECKLIST-thread-ambient.md) | in progress | M27: create the crate, migrate this session's probes into it under the three-tier scheme, and queue migration of the nine earlier measurements that still live only in git-ignored scratch. | [DESIGN-NOTES.md](DESIGN-NOTES.md) | diff --git a/crates/windows-platform-probes/src/bin/cancel_io.rs b/crates/windows-platform-probes/src/bin/cancel_io.rs index 013801aee..cbf1c88be 100644 --- a/crates/windows-platform-probes/src/bin/cancel_io.rs +++ b/crates/windows-platform-probes/src/bin/cancel_io.rs @@ -11,9 +11,11 @@ //! is a call that can fail to return, so every case here runs behind a //! watchdog; a wedged `#[test]` would take the whole suite with it. +use std::fmt::Write as _; use windows_platform_probes::cancel_io::{ CancelOutcome, WATCHDOG, cancel_against_busy_thread, cancel_against_idle_thread, }; +use windows_platform_probes::report::emit_report; fn describe(outcome: CancelOutcome) -> String { match outcome { @@ -26,37 +28,91 @@ fn describe(outcome: CancelOutcome) -> String { } fn main() { - println!("== is CancelSynchronousIo safe to point at a shared thread? ==\n"); - println!("watchdog: {WATCHDOG:?} per attempt\n"); + // The probe's whole output policy, and it is one line: hand the renderer to + // the sink. Nothing here or below names a stream -- that is chosen once, in + // `report`, so retargeting a probe is not a rewrite. + emit_report(render); +} + +/// The probe's whole report, as text. +fn render(out: &mut String) { + // First line of the report, and part of the returned text rather than + // written out here: a captured report must carry the line naming the + // machine that produced it, and the taint marker with it. Without it a + // finding can be pasted anywhere and compared against anything. + let _ = writeln!( + out, + "{}", + windows_placement_probe::fingerprint::banner_line() + ); + let _ = writeln!( + out, + "== is CancelSynchronousIo safe to point at a shared thread? ==\n" + ); + let _ = writeln!(out, "watchdog: {WATCHDOG:?} per attempt\n"); - println!("case 1: cancel against a thread with no I/O outstanding"); + let _ = writeln!( + out, + "case 1: cancel against a thread with no I/O outstanding" + ); let idle = cancel_against_idle_thread(); - println!(" {}", describe(idle)); - println!( + let _ = writeln!(out, " {}", describe(idle)); + let _ = writeln!( + out, " -> a point-in-time cancel finds nothing here; a standing request\n against the thread would not." ); - println!("\ncase 2: cancel against a thread hammering synchronous reads"); + let _ = writeln!( + out, + "\ncase 2: cancel against a thread hammering synchronous reads" + ); let busy = cancel_against_busy_thread(4); for (attempt, outcome) in busy.iter().enumerate() { - println!(" attempt {}: {}", attempt + 1, describe(*outcome)); + let _ = writeln!(out, " attempt {}: {}", attempt + 1, describe(*outcome)); } let wedged = busy.iter().any(|outcome| !outcome.returned()); - println!("\nconclusion:"); + let _ = writeln!(out, "\nconclusion:"); if wedged { - println!(" CancelSynchronousIo DID NOT RETURN against a thread that keeps"); - println!(" re-entering synchronous I/O. In the proposed mid-flight"); - println!(" cancellation design the canceller is a control-plane thread and"); - println!(" the target is a shared pool worker -- so a control plane can be"); - println!(" wedged by the very thing it is trying to rescue."); - println!(" This is why mid-flight cancellation stays deferred."); + let _ = writeln!( + out, + " CancelSynchronousIo DID NOT RETURN against a thread that keeps" + ); + let _ = writeln!( + out, + " re-entering synchronous I/O. In the proposed mid-flight" + ); + let _ = writeln!( + out, + " cancellation design the canceller is a control-plane thread and" + ); + let _ = writeln!( + out, + " the target is a shared pool worker -- so a control plane can be" + ); + let _ = writeln!(out, " wedged by the very thing it is trying to rescue."); + let _ = writeln!(out, " This is why mid-flight cancellation stays deferred."); } else { - println!(" every attempt returned on this host and this Windows build."); - println!(" That does NOT clear the design: the original measurement wedged"); - println!(" with four identical noninvasive samples over twelve seconds, so"); - println!(" a non-wedge here is a timing difference rather than a refutation."); - println!(" Re-run, and vary the hammer loop, before concluding otherwise."); + let _ = writeln!( + out, + " every attempt returned on this host and this Windows build." + ); + let _ = writeln!( + out, + " That does NOT clear the design: the original measurement wedged" + ); + let _ = writeln!( + out, + " with four identical noninvasive samples over twelve seconds, so" + ); + let _ = writeln!( + out, + " a non-wedge here is a timing difference rather than a refutation." + ); + let _ = writeln!( + out, + " Re-run, and vary the hammer loop, before concluding otherwise." + ); } } diff --git a/crates/windows-platform-probes/src/bin/completion_port.rs b/crates/windows-platform-probes/src/bin/completion_port.rs index 3b67a218e..2b3a9977e 100644 --- a/crates/windows-platform-probes/src/bin/completion_port.rs +++ b/crates/windows-platform-probes/src/bin/completion_port.rs @@ -13,11 +13,14 @@ //! completion arrived, and so read a clean failure -- result code //! `ERROR_INVALID_PARAMETER`, zero bytes -- as a success. +use std::fmt::Write as _; use windows_platform_probes::completion_port::{CompletionPortFinding, ReadAttempt, measure}; use windows_platform_probes::ioring::IoRingSupport; +use windows_platform_probes::report::emit_report; -fn describe(label: &str, attempt: ReadAttempt) { - println!( +fn describe(out: &mut String, label: &str, attempt: ReadAttempt) { + let _ = writeln!( + out, " {label:<46} result={:#010x} bytes={} first={:#04x} [{}]", attempt.result_code, attempt.bytes, @@ -26,26 +29,34 @@ fn describe(label: &str, attempt: ReadAttempt) { ); } -fn report(finding: CompletionPortFinding) { - println!("a PASS needs all three: success code, full byte count, and the fill byte.\n"); +fn report(out: &mut String, finding: CompletionPortFinding) { + let _ = writeln!( + out, + "a PASS needs all three: success code, full byte count, and the fill byte.\n" + ); describe( + out, "case 1 CONTROL: no association at all", finding.control_unassociated, ); describe( + out, "case 2 TEST: associated, then IoRing read", finding.after_iocp_association, ); describe( + out, "case 3a: IoRing read BEFORE association", finding.before_late_association, ); describe( + out, "case 3b: IoRing read AFTER association", finding.after_late_association, ); - println!( + let _ = writeln!( + out, " {:<46} [{}]", "case 4 CONTROL: overlapped read via the port", if finding.port_still_works { @@ -55,54 +66,115 @@ fn report(finding: CompletionPortFinding) { } ); describe( + out, "case 5a: IoRing BEFORE CreateThreadpoolIo", finding.before_threadpool_io, ); describe( + out, "case 5b: IoRing AFTER CreateThreadpoolIo", finding.after_threadpool_io, ); - println!("\n--- verdict ---"); + let _ = writeln!(out, "\n--- verdict ---"); if !finding.is_valid() { - println!(" INVALID: a negative control failed, so nothing can be concluded."); - println!(" The probe is broken rather than the platform answering."); + let _ = writeln!( + out, + " INVALID: a negative control failed, so nothing can be concluded." + ); + let _ = writeln!( + out, + " The probe is broken rather than the platform answering." + ); return; } if finding.association_forecloses_ioring() { - println!(" IOCP association FORECLOSES IoRing use of the same handle."); + let _ = writeln!( + out, + " IOCP association FORECLOSES IoRing use of the same handle." + ); if finding.port_still_works { - println!(" The handle is still healthy -- it completes through the port -- so it"); - println!(" is the IoRing path specifically that is refused, not the handle."); + let _ = writeln!( + out, + " The handle is still healthy -- it completes through the port -- so it" + ); + let _ = writeln!( + out, + " is the IoRing path specifically that is refused, not the handle." + ); } else { - println!(" NOTE: the port control also failed, so the handle may be broken"); - println!(" outright rather than only the IoRing path being refused."); + let _ = writeln!( + out, + " NOTE: the port control also failed, so the handle may be broken" + ); + let _ = writeln!( + out, + " outright rather than only the IoRing path being refused." + ); } } else { - println!(" COEXIST: association does NOT prevent IoRing use of the handle."); - println!(" This contradicts the reading windows-namespace-request-sys rests on;"); - println!(" the handle-destination fork would need revisiting."); + let _ = writeln!( + out, + " COEXIST: association does NOT prevent IoRing use of the handle." + ); + let _ = writeln!( + out, + " This contradicts the reading windows-namespace-request-sys rests on;" + ); + let _ = writeln!(out, " the handle-destination fork would need revisiting."); } if finding.threadpool_io_forecloses_ioring() { - println!("\n CreateThreadpoolIo forecloses it the SAME way. That is the path this"); - println!(" workspace actually uses, so the consequence lands on"); - println!(" windows-threadpool-sys's own users."); + let _ = writeln!( + out, + "\n CreateThreadpoolIo forecloses it the SAME way. That is the path this" + ); + let _ = writeln!( + out, + " workspace actually uses, so the consequence lands on" + ); + let _ = writeln!(out, " windows-threadpool-sys's own users."); } else { - println!("\n CreateThreadpoolIo does NOT foreclose it, which differs from raw IOCP."); - println!(" Worth knowing: the two are not interchangeable for this purpose."); + let _ = writeln!( + out, + "\n CreateThreadpoolIo does NOT foreclose it, which differs from raw IOCP." + ); + let _ = writeln!( + out, + " Worth knowing: the two are not interchangeable for this purpose." + ); } } fn main() { - println!("== IOCP association vs IoRing, on one handle ==\n"); + // The probe's whole output policy, and it is one line: hand the renderer to + // the sink. Nothing here or below names a stream -- that is chosen once, in + // `report`, so retargeting a probe is not a rewrite. + emit_report(render); +} + +/// The probe's whole report, as text. +fn render(out: &mut String) { + // First line of the report, and part of the returned text rather than + // written out here: a captured report must carry the line naming the + // machine that produced it, and the taint marker with it. Without it a + // finding can be pasted anywhere and compared against anything. + let _ = writeln!( + out, + "{}", + windows_placement_probe::fingerprint::banner_line() + ); + let _ = writeln!(out, "== IOCP association vs IoRing, on one handle ==\n"); match measure() { IoRingSupport::Unavailable => { - println!("this host has no usable IoRing, so nothing was measured."); - println!("('cannot ask' is not 'the answer is no'.)"); + let _ = writeln!( + out, + "this host has no usable IoRing, so nothing was measured." + ); + let _ = writeln!(out, "('cannot ask' is not 'the answer is no'.)"); } - IoRingSupport::Measured(finding) => report(finding), + IoRingSupport::Measured(finding) => report(out, finding), } } diff --git a/crates/windows-platform-probes/src/bin/device_map.rs b/crates/windows-platform-probes/src/bin/device_map.rs index 6e26ea402..f087a0688 100644 --- a/crates/windows-platform-probes/src/bin/device_map.rs +++ b/crates/windows-platform-probes/src/bin/device_map.rs @@ -13,65 +13,128 @@ //! path resolved on a submitting thread and opened on a worker under a captured //! token can name a different device. +use std::fmt::Write as _; use windows_platform_probes::device_map::{SubstDrive, measure_with_subst}; +use windows_platform_probes::report::emit_report; fn main() { - println!("== does impersonation change the DOS device map? ==\n"); + // The probe's whole output policy, and it is one line: hand the renderer to + // the sink. Nothing here or below names a stream -- that is chosen once, in + // `report`, so retargeting a probe is not a rewrite. + emit_report(render); +} + +/// The probe's whole report, as text. +fn render(out: &mut String) { + // First line of the report, and part of the returned text rather than + // written out here: a captured report must carry the line naming the + // machine that produced it, and the taint marker with it. Without it a + // finding can be pasted anywhere and compared against anything. + let _ = writeln!( + out, + "{}", + windows_placement_probe::fingerprint::banner_line() + ); + let _ = writeln!(out, "== does impersonation change the DOS device map? ==\n"); let Some(drive) = SubstDrive::claim("binary") else { - println!("no free drive letter on this host, so the probe cannot run."); - println!("(Reported rather than measured: a probe that cannot set up its"); - println!("fixture must say so instead of producing a misleading negative.)"); + let _ = writeln!( + out, + "no free drive letter on this host, so the probe cannot run." + ); + let _ = writeln!( + out, + "(Reported rather than measured: a probe that cannot set up its" + ); + let _ = writeln!( + out, + "fixture must say so instead of producing a misleading negative.)" + ); return; }; - println!( + let _ = writeln!( + out, "using {} as a subst-style link to {}\n", drive.letter(), drive.target() ); let finding = measure_with_subst(&drive); - let describe = - |label: &str, observation: &windows_platform_probes::device_map::MapObservation| { - println!("{label}"); - println!( - " {} -> {}", - observation.letter, - observation - .target - .as_deref() - .unwrap_or("(not found in this map)") - ); - match observation.logon_session { - Some((low, high)) => println!(" logon session LUID: {high:08x}:{low:08x}"), - None => println!(" logon session LUID: (not impersonating)"), + // Takes the buffer as an argument rather than capturing it, so that `out` + // stays available to the lines below. A closure capturing it mutably would + // hold the borrow across every later write. + fn describe( + out: &mut String, + label: &str, + observation: &windows_platform_probes::device_map::MapObservation, + ) { + let _ = writeln!(out, "{label}"); + let _ = writeln!( + out, + " {} -> {}", + observation.letter, + observation + .target + .as_deref() + .unwrap_or("(not found in this map)") + ); + match observation.logon_session { + Some((low, high)) => { + let _ = writeln!(out, " logon session LUID: {high:08x}:{low:08x}"); } - }; + None => { + let _ = writeln!(out, " logon session LUID: (not impersonating)"); + } + } + } - describe("our own session:", &finding.own_session); - println!(); + describe(out, "our own session:", &finding.own_session); + let _ = writeln!(out); describe( + out, "impersonating the anonymous session:", &finding.anonymous_session, ); - println!("\ncontrol:"); - println!( + let _ = writeln!(out, "\ncontrol:"); + let _ = writeln!( + out, " the two contexts are different logon sessions: {}", finding.sessions_differ() ); - println!("\nconclusion:"); + let _ = writeln!(out, "\nconclusion:"); if finding.impersonation_changes_the_map() { - println!(" the SAME drive letter, on the SAME thread, resolves differently"); - println!(" depending on the token in effect. A path resolved on a submitter"); - println!(" and opened on a worker under a captured token can name a"); - println!(" different device -- which is why lexical resolution does not"); - println!(" close that hazard."); + let _ = writeln!( + out, + " the SAME drive letter, on the SAME thread, resolves differently" + ); + let _ = writeln!( + out, + " depending on the token in effect. A path resolved on a submitter" + ); + let _ = writeln!( + out, + " and opened on a worker under a captured token can name a" + ); + let _ = writeln!( + out, + " different device -- which is why lexical resolution does not" + ); + let _ = writeln!(out, " close that hazard."); } else { - println!(" the letter resolved the same way in both contexts. Either the"); - println!(" finding has changed, or the impersonation did not take effect --"); - println!(" check the control above before believing the former."); + let _ = writeln!( + out, + " the letter resolved the same way in both contexts. Either the" + ); + let _ = writeln!( + out, + " finding has changed, or the impersonation did not take effect --" + ); + let _ = writeln!( + out, + " check the control above before believing the former." + ); } } diff --git a/crates/windows-platform-probes/src/bin/error_mode.rs b/crates/windows-platform-probes/src/bin/error_mode.rs index 43a01611b..71078ef33 100644 --- a/crates/windows-platform-probes/src/bin/error_mode.rs +++ b/crates/windows-platform-probes/src/bin/error_mode.rs @@ -13,10 +13,13 @@ //! the one observation a test must not: the alignment bit's process-scope //! stickiness is irreversible, so it is demonstrated here and nowhere else. +use std::fmt::Write as _; + use windows_platform_probes::error_mode::{ alignment_bit_is_sticky_at_process_scope, bits, combined_invalid_installs_nothing, probe_bit, settable_bits, thread_mode_independent_of_process, }; +use windows_platform_probes::report::emit_report; fn name(bit: u32) -> &'static str { match bit { @@ -29,7 +32,31 @@ fn name(bit: u32) -> &'static str { } fn main() { - println!("--- each bit on its own, set then read back ---"); + // The probe's whole output policy, and it is one line: hand the renderer to + // the sink. Nothing here or below names a stream -- that is chosen once, in + // `report`, so retargeting a probe is not a rewrite. + emit_report(render); +} + +/// The probe's whole report, as text. +/// +/// **This one measures as it renders**, unlike its siblings, and the coupling is +/// real rather than laziness: the last observation permanently alters this +/// process (see `alignment_bit_is_sticky_at_process_scope`), so the order in +/// which the observations are taken is part of what is being reported. Splitting +/// measurement from rendering would invite a later reordering that silently +/// changes the result. +fn render(out: &mut String) { + // First line of the report, and part of the returned text rather than + // written out here: a captured report must carry the line naming the + // machine that produced it, and the taint marker with it. Without it a + // finding can be pasted anywhere and compared against anything. + let _ = writeln!( + out, + "{}", + windows_placement_probe::fingerprint::banner_line() + ); + let _ = writeln!(out, "--- each bit on its own, set then read back ---"); for bit in [ bits::FAIL_CRITICAL_ERRORS, bits::NO_GP_FAULT_ERROR_BOX, @@ -44,7 +71,8 @@ fn main() { } else { "REJECTED" }; - println!( + let _ = writeln!( + out, "{} ok={} last_error={:<5} read_back=0x{:04X} -> {verdict}", name(bit), outcome.set_ok, @@ -53,11 +81,12 @@ fn main() { ); } - println!("\nsettable mask: 0x{:04X}", settable_bits()); + let _ = writeln!(out, "\nsettable mask: 0x{:04X}", settable_bits()); let (installed_nothing, read_back) = combined_invalid_installs_nothing(); - println!("\n--- one invalid bit alongside two valid ones ---"); - println!( + let _ = writeln!(out, "\n--- one invalid bit alongside two valid ones ---"); + let _ = writeln!( + out, "read back 0x{read_back:04X} -> {}", if installed_nothing { "the WHOLE call failed; none of the valid bits was installed" @@ -67,8 +96,9 @@ fn main() { ); let observation = thread_mode_independent_of_process(); - println!("\n--- process mode versus thread mode ---"); - println!( + let _ = writeln!(out, "\n--- process mode versus thread mode ---"); + let _ = writeln!( + out, "process=0x{:04X} thread=0x{:04X} -> {}", observation.process_mode, observation.thread_mode, @@ -79,10 +109,17 @@ fn main() { } ); - println!("\n--- irreversible: the alignment bit at process scope ---"); - println!("(this permanently alters this process, which is why no test does it)"); + let _ = writeln!( + out, + "\n--- irreversible: the alignment bit at process scope ---" + ); + let _ = writeln!( + out, + "(this permanently alters this process, which is why no test does it)" + ); let (before, after) = alignment_bit_is_sticky_at_process_scope(); - println!( + let _ = writeln!( + out, "before=0x{before:04X} after restore attempt=0x{after:04X} -> {}", if after & bits::NO_ALIGNMENT_FAULT_EXCEPT != 0 { "STICKY: the restore was ignored" diff --git a/crates/windows-platform-probes/src/bin/handle_state.rs b/crates/windows-platform-probes/src/bin/handle_state.rs index b2eadbaa1..c7570ec9b 100644 --- a/crates/windows-platform-probes/src/bin/handle_state.rs +++ b/crates/windows-platform-probes/src/bin/handle_state.rs @@ -11,22 +11,42 @@ //! observations themselves -- the actual file names each handle returned -- //! which is what makes a surprising result diagnosable rather than merely red. +use std::fmt::Write as _; use windows_platform_probes::handle_state::{ Fixture, SingleShot, closing_duplicate_preserves_source, duplicate_shares_cursor, ground_truth, query_disturbs_cursor, separate_opens_are_independent, }; +use windows_platform_probes::report::emit_report; fn main() { + // The probe's whole output policy, and it is one line: hand the renderer to + // the sink. Nothing here or below names a stream -- that is chosen once, in + // `report`, so retargeting a probe is not a rewrite. + emit_report(render); +} + +/// The probe's whole report, as text. +fn render(out: &mut String) { + // First line of the report, and part of the returned text rather than + // written out here: a captured report must carry the line naming the + // machine that produced it, and the taint marker with it. Without it a + // finding can be pasted anywhere and compared against anything. + let _ = writeln!( + out, + "{}", + windows_placement_probe::fingerprint::banner_line() + ); let fixture = Fixture::new("bin"); let truth = ground_truth(&fixture); - println!("--- ground truth (one handle, start to finish) ---"); - println!("{} entries: {truth:?}\n", truth.len()); + let _ = writeln!(out, "--- ground truth (one handle, start to finish) ---"); + let _ = writeln!(out, "{} entries: {truth:?}\n", truth.len()); let observation = duplicate_shares_cursor(&fixture); - println!("--- does a duplicate share the cursor? ---"); - println!("source (restart) -> {:?}", observation.source_first); - println!("duplicate (continue) -> {:?}", observation.other_next); - println!( + let _ = writeln!(out, "--- does a duplicate share the cursor? ---"); + let _ = writeln!(out, "source (restart) -> {:?}", observation.source_first); + let _ = writeln!(out, "duplicate (continue) -> {:?}", observation.other_next); + let _ = writeln!( + out, " -> {}\n", if observation.continued(&truth) { "SHARED: the duplicate continued where the source stopped" @@ -38,10 +58,11 @@ fn main() { ); let control = separate_opens_are_independent(&fixture); - println!("--- control: two separate opens ---"); - println!("open #1 (restart) -> {:?}", control.source_first); - println!("open #2 (continue) -> {:?}", control.other_next); - println!( + let _ = writeln!(out, "--- control: two separate opens ---"); + let _ = writeln!(out, "open #1 (restart) -> {:?}", control.source_first); + let _ = writeln!(out, "open #2 (continue) -> {:?}", control.other_next); + let _ = writeln!( + out, " -> {}\n", if control.restarted() { "INDEPENDENT, as expected -- so the result above is attributable to duplication" @@ -50,8 +71,9 @@ fn main() { } ); - println!("--- does closing the duplicate break the source? ---"); - println!( + let _ = writeln!(out, "--- does closing the duplicate break the source? ---"); + let _ = writeln!( + out, " -> {}\n", if closing_duplicate_preserves_source(&fixture) { "no: the source kept enumerating" @@ -60,7 +82,10 @@ fn main() { } ); - println!("--- does an interleaved single-shot query move the cursor? ---"); + let _ = writeln!( + out, + "--- does an interleaved single-shot query move the cursor? ---" + ); for (query, on_duplicate) in [ (SingleShot::BasicInfo, false), (SingleShot::IdInfo, false), @@ -68,7 +93,8 @@ fn main() { (SingleShot::BasicInfo, true), ] { let (succeeded, disturbed) = query_disturbs_cursor(&fixture, query, on_duplicate, &truth); - println!( + let _ = writeln!( + out, "{query:?}{} succeeded={succeeded} -> {}", if on_duplicate { " (on the duplicate)" diff --git a/crates/windows-platform-probes/src/bin/ioring.rs b/crates/windows-platform-probes/src/bin/ioring.rs index 929dfbeef..862490b7f 100644 --- a/crates/windows-platform-probes/src/bin/ioring.rs +++ b/crates/windows-platform-probes/src/bin/ioring.rs @@ -11,62 +11,123 @@ //! this reports "cannot measure" rather than a false negative on a host that //! has no ring. +use std::fmt::Write as _; use windows_platform_probes::ioring::{ IoRingSupport, is_available, measure_registration, measure_thread_agnosticism, }; +use windows_platform_probes::report::emit_report; fn main() { - println!("== IoRing registration and thread agnosticism ==\n"); + // The probe's whole output policy, and it is one line: hand the renderer to + // the sink. Nothing here or below names a stream -- that is chosen once, in + // `report`, so retargeting a probe is not a rewrite. + emit_report(render); +} + +/// The probe's whole report, as text. +fn render(out: &mut String) { + // First line of the report, and part of the returned text rather than + // written out here: a captured report must carry the line naming the + // machine that produced it, and the taint marker with it. Without it a + // finding can be pasted anywhere and compared against anything. + let _ = writeln!( + out, + "{}", + windows_placement_probe::fingerprint::banner_line() + ); + let _ = writeln!(out, "== IoRing registration and thread agnosticism ==\n"); if !is_available() { - println!("this host has no usable IoRing, so nothing was measured."); - println!("(Reported rather than measured: 'we could not ask' and 'the answer"); - println!("is no' are different facts, and conflating them is how a design note"); - println!("ends up citing a measurement that never ran.)"); + let _ = writeln!( + out, + "this host has no usable IoRing, so nothing was measured." + ); + let _ = writeln!( + out, + "(Reported rather than measured: 'we could not ask' and 'the answer" + ); + let _ = writeln!( + out, + "is no' are different facts, and conflating them is how a design note" + ); + let _ = writeln!(out, "ends up citing a measurement that never ran.)"); return; } - println!("registration semantics:"); + let _ = writeln!(out, "registration semantics:"); match measure_registration() { - IoRingSupport::Unavailable => println!(" (no ring)"), + IoRingSupport::Unavailable => { + let _ = writeln!(out, " (no ring)"); + } IoRingSupport::Measured(observed) => { - println!( + let _ = writeln!( + out, " after re-registering ONE handle: index 0 usable {}, index 1 usable {}", observed.index_zero_usable_after_second, observed.index_one_usable_after_second ); if observed.replaces() { - println!(" -> REPLACES the whole table, which is what"); - println!(" windows-ioring-sys assumes and refuses a second call on."); + let _ = writeln!(out, " -> REPLACES the whole table, which is what"); + let _ = writeln!( + out, + " windows-ioring-sys assumes and refuses a second call on." + ); } else if observed.appends() { - println!(" -> APPENDS. windows-ioring-sys's index bookkeeping would be"); - println!(" WRONG and its refusal a needless restriction."); + let _ = writeln!( + out, + " -> APPENDS. windows-ioring-sys's index bookkeeping would be" + ); + let _ = writeln!(out, " WRONG and its refusal a needless restriction."); } else { - println!(" -> neither: even index 0 stopped working, so the probe"); - println!(" broke rather than the platform answering."); + let _ = writeln!( + out, + " -> neither: even index 0 stopped working, so the probe" + ); + let _ = writeln!(out, " broke rather than the platform answering."); } } } - println!("\nthread agnosticism:"); + let _ = writeln!(out, "\nthread agnosticism:"); match measure_thread_agnosticism() { - IoRingSupport::Unavailable => println!(" (no ring)"), + IoRingSupport::Unavailable => { + let _ = writeln!(out, " (no ring)"); + } IoRingSupport::Measured(observed) => { - println!( + let _ = writeln!( + out, " pending at submitter exit: {} | result code: {:#010x} | \ transferred the fill byte: {}", observed.pending_at_submitter_exit, observed.result_code, observed.filled ); if !observed.pending_at_submitter_exit { - println!(" -> the read had ALREADY completed, so this run measured"); - println!(" nothing about thread affinity either way."); + let _ = writeln!( + out, + " -> the read had ALREADY completed, so this run measured" + ); + let _ = writeln!(out, " nothing about thread affinity either way."); } if observed.survives_submitter_exit() { - println!(" -> an operation OUTLIVES the thread that submitted it, so a"); - println!(" design whose threads are transient by construction is safe."); + let _ = writeln!( + out, + " -> an operation OUTLIVES the thread that submitted it, so a" + ); + let _ = writeln!( + out, + " design whose threads are transient by construction is safe." + ); } else { - println!(" -> the operation did NOT survive its submitter. Every thread"); - println!(" in the proposed design is transient, so this would fail"); - println!(" only under load -- the worst place to discover it."); + let _ = writeln!( + out, + " -> the operation did NOT survive its submitter. Every thread" + ); + let _ = writeln!( + out, + " in the proposed design is transient, so this would fail" + ); + let _ = writeln!( + out, + " only under load -- the worst place to discover it." + ); } } } diff --git a/crates/windows-platform-probes/src/bin/pool_growth.rs b/crates/windows-platform-probes/src/bin/pool_growth.rs index 88ad8fe6b..7d73e1ae1 100644 --- a/crates/windows-platform-probes/src/bin/pool_growth.rs +++ b/crates/windows-platform-probes/src/bin/pool_growth.rs @@ -11,57 +11,97 @@ //! exceed it, and gets there promptly); this binary prints the numbers, which //! is what a new architecture actually needs to be re-measured against. +use std::fmt::Write as _; use windows_platform_probes::pool_growth::{measure_growth, measure_raise_while_saturated}; +use windows_platform_probes::report::emit_report; -fn report(label: &str, maximum: u32, submissions: usize, runs_long: bool) { +/// Measure one configuration and append its block to `out`. +/// +/// Takes the buffer rather than printing: a helper that wrote to stdout while +/// its caller composed a string would emit its lines *before* the caller's, +/// reordering the report even though every line still appeared. +fn report(out: &mut String, label: &str, maximum: u32, submissions: usize, runs_long: bool) { let observed = measure_growth(maximum, submissions, runs_long); - println!("{label}"); - println!( + let _ = writeln!(out, "{label}"); + let _ = writeln!( + out, " max {} / submitted {} -> started while blocked {}, distinct threads {}", observed.maximum, observed.submitted, observed.started_while_blocked, observed.distinct_threads ); - println!( + let _ = writeln!( + out, " saturated {} | one thread each {} | slowest arrival {:?}", observed.saturated(), observed.one_thread_each(), observed.slowest_arrival() ); - println!(" arrivals (us): {:?}", observed.arrivals_us); + let _ = writeln!(out, " arrivals (us): {:?}", observed.arrivals_us); } fn main() { - println!("== how a blocked pool grows ==\n"); + // The probe's whole output policy, and it is one line: hand the renderer to + // the sink. Nothing here or below names a stream -- that is chosen once, in + // `report`, so retargeting a probe is not a rewrite. + emit_report(render); +} + +/// The probe's whole report, as text. +fn render(out: &mut String) { + // First line of the report, and part of the returned text rather than + // written out here: a captured report must carry the line naming the + // machine that produced it, and the taint marker with it. Without it a + // finding can be pasted anywhere and compared against anything. + let _ = writeln!( + out, + "{}", + windows_placement_probe::fingerprint::banner_line() + ); + let _ = writeln!(out, "== how a blocked pool grows ==\n"); - report("P1 growth curve, max 4:", 4, 8, false); - println!(); - report("P1 growth curve, max 8:", 8, 16, false); - println!(); - report("P2 the same, runs-long:", 4, 8, true); - println!(); + report(out, "P1 growth curve, max 4:", 4, 8, false); + let _ = writeln!(out); + report(out, "P1 growth curve, max 8:", 8, 16, false); + let _ = writeln!(out); + report(out, "P2 the same, runs-long:", 4, 8, true); + let _ = writeln!(out); let raise = measure_raise_while_saturated(2, 6, 8); - println!("P3 raise while saturated (2 -> 6):"); + let _ = writeln!(out, "P3 raise while saturated (2 -> 6):"); if raise.saturated_before_raise() { - println!( + let _ = writeln!( + out, " extra work started {:?} after the maximum was raised", raise.delay ); } else { - println!( + let _ = writeln!( + out, " NOT saturated before the raise ({} of {} started), so the delay", raise.started_before_raise, raise.base_max ); - println!(" below times growth toward the base maximum, not the raise."); - println!(" elapsed: {:?}", raise.delay); + let _ = writeln!( + out, + " below times growth toward the base maximum, not the raise." + ); + let _ = writeln!(out, " elapsed: {:?}", raise.delay); } if !raise.took_effect { - println!(" the settle window expired with no extra callback started."); + let _ = writeln!( + out, + " the settle window expired with no extra callback started." + ); } - println!("\nnote: every number here is from this host and this Windows build."); - println!("Re-run on another architecture rather than assuming they carry over."); + let _ = writeln!( + out, + "\nnote: every number here is from this host and this Windows build." + ); + let _ = writeln!( + out, + "Re-run on another architecture rather than assuming they carry over." + ); } diff --git a/crates/windows-platform-probes/src/bin/worker_context.rs b/crates/windows-platform-probes/src/bin/worker_context.rs index d51ff3ab7..b1352d729 100644 --- a/crates/windows-platform-probes/src/bin/worker_context.rs +++ b/crates/windows-platform-probes/src/bin/worker_context.rs @@ -12,55 +12,96 @@ //! measurement can be eyeballed on a new host or a new Windows build without //! reading a test's output. +use std::fmt::Write as _; +use windows_platform_probes::report::emit_report; use windows_platform_probes::worker_context::{ observe_on_worker, observe_on_worker_while_impersonating, }; fn main() { - println!("== what a thread-pool worker is handed ==\n"); + // The probe's whole output policy, and it is one line: hand the renderer to + // the sink. Nothing here or below names a stream -- that is chosen once, in + // `report`, so retargeting a probe is not a rewrite. + emit_report(render); +} + +/// The probe's whole report, as text. +fn render(out: &mut String) { + // First line of the report, and part of the returned text rather than + // written out here: a captured report must carry the line naming the + // machine that produced it, and the taint marker with it. Without it a + // finding can be pasted anywhere and compared against anything. + let _ = writeln!( + out, + "{}", + windows_placement_probe::fingerprint::banner_line() + ); + let _ = writeln!(out, "== what a thread-pool worker is handed ==\n"); let plain = observe_on_worker(); - println!("submitted with no impersonation:"); - println!(" has thread token : {}", plain.has_thread_token); - println!(" OpenThreadToken err: {}", plain.open_token_error); - println!(" thread error mode : {:#06x}", plain.error_mode); - println!(" -> unimpersonated : {}", plain.is_unimpersonated()); - println!( + let _ = writeln!(out, "submitted with no impersonation:"); + let _ = writeln!(out, " has thread token : {}", plain.has_thread_token); + let _ = writeln!(out, " OpenThreadToken err: {}", plain.open_token_error); + let _ = writeln!(out, " thread error mode : {:#06x}", plain.error_mode); + let _ = writeln!(out, " -> unimpersonated : {}", plain.is_unimpersonated()); + let _ = writeln!( + out, " -> critical-error handler enabled: {}", plain.critical_error_handler_enabled() ); let impersonating = observe_on_worker_while_impersonating(); let worker = impersonating.worker; - println!( + let _ = writeln!( + out, " submitted WHILE the submitter impersonates:" ); - println!( + let _ = writeln!( + out, " submitter has token: {}", impersonating.submitter.has_thread_token ); - println!(" worker has token : {}", worker.has_thread_token); - println!(" OpenThreadToken err: {}", worker.open_token_error); - println!(" thread error mode : {:#06x}", worker.error_mode); - println!(" -> unimpersonated : {}", worker.is_unimpersonated()); - println!(" -> they disagree : {}", impersonating.disagree()); + let _ = writeln!(out, " worker has token : {}", worker.has_thread_token); + let _ = writeln!(out, " OpenThreadToken err: {}", worker.open_token_error); + let _ = writeln!(out, " thread error mode : {:#06x}", worker.error_mode); + let _ = writeln!(out, " -> unimpersonated : {}", worker.is_unimpersonated()); + let _ = writeln!(out, " -> they disagree : {}", impersonating.disagree()); - println!( + let _ = writeln!( + out, " conclusion:" ); if impersonating.disagree() { - println!(" a worker does NOT inherit the submitter's token, so identity"); - println!(" must be captured and applied explicitly."); + let _ = writeln!( + out, + " a worker does NOT inherit the submitter's token, so identity" + ); + let _ = writeln!(out, " must be captured and applied explicitly."); } else { - println!(" UNEXPECTED: the worker inherited a token. The ambient crate's"); - println!(" premise no longer holds and its design needs revisiting."); + let _ = writeln!( + out, + " UNEXPECTED: the worker inherited a token. The ambient crate's" + ); + let _ = writeln!( + out, + " premise no longer holds and its design needs revisiting." + ); } if plain.critical_error_handler_enabled() { - println!(" a worker's critical-error handler is ENABLED, so a hard device"); - println!(" error can put a modal dialog on shared infrastructure."); + let _ = writeln!( + out, + " a worker's critical-error handler is ENABLED, so a hard device" + ); + let _ = writeln!( + out, + " error can put a modal dialog on shared infrastructure." + ); } else { - println!(" UNEXPECTED: a worker starts with the handler suppressed."); + let _ = writeln!( + out, + " UNEXPECTED: a worker starts with the handler suppressed." + ); } } diff --git a/crates/windows-platform-probes/src/lib.rs b/crates/windows-platform-probes/src/lib.rs index f809ab729..bc3e537ff 100644 --- a/crates/windows-platform-probes/src/lib.rs +++ b/crates/windows-platform-probes/src/lib.rs @@ -116,6 +116,7 @@ pub mod error_mode; pub mod handle_state; pub mod ioring; pub mod pool_growth; +pub mod report; pub mod worker_context; #[cfg(test)] diff --git a/crates/windows-platform-probes/src/report.rs b/crates/windows-platform-probes/src/report.rs new file mode 100644 index 000000000..d2402a19c --- /dev/null +++ b/crates/windows-platform-probes/src/report.rs @@ -0,0 +1,173 @@ +// Copyright (c) Mike Grier. +//! The one place a probe writes. +//! +//! # Why an abstraction for something as simple as printing +//! +//! The repository's rule is that a tool introduces an output abstraction at its +//! *first* output site, so that the storage target and the formatting stay +//! separable from the call sites that compose the content. A probe that calls +//! `println!` from fifty places has welded the two together: its findings can +//! only be observed by running the process and capturing a stream, so nothing +//! about its report can be asserted, diffed against a previous run, or written +//! anywhere but a terminal. +//! +//! That is a real loss for a probe specifically. These binaries exist so a +//! claim in a design note can be **re-run rather than re-argued**, which means +//! their output is evidence -- and evidence that can only be eyeballed is +//! weaker than evidence a test can read. +//! +//! # What this is, and what it deliberately is not +//! +//! A sink, not a logging framework: one method, no levels, no filtering, no +//! formatting policy. Callers still own their text. +//! +//! Only one stream, unlike the placement probe's near-identical sink, because +//! nothing a probe puts in its *report* is a diagnostic: every line of it is a +//! finding, so a `problem` method would have no callers here. +//! +//! The crate does emit one diagnostic, and it is the exception that shows why +//! the split is unnecessary rather than one that undermines it. +//! `Impersonation::drop` warns on stderr when `RevertToSelf` fails during an +//! unwind, because panicking from `Drop` mid-unwind would abort and replace a +//! diagnosable failure with one that explains nothing. That warning is not part +//! of any report and must not be: it belongs to the process, not to the +//! measurement, and stderr already separates it. Routing it through this sink +//! would mix it into the evidence stdout carries. +//! +//! # Every probe routes through this +//! +//! Every probe in this crate, with no exceptions -- stated without a count on +//! purpose, so the claim stays true as probes are added. Each conversion was +//! checked by capturing the probe's output before and after and requiring every +//! pre-existing line to match, in the same order. Not byte-for-byte: the +//! conversion also prepends the host banner, which is the one deliberate +//! difference and the only one permitted. +//! +//! **That check has to be positional**, which is worth recording because the +//! obvious tool is not. The defect a conversion introduces is a helper that +//! still writes to stdout while its caller composes a string: every line still +//! appears, but the helper's lines arrive *first*, so the report is reordered. +//! PowerShell's `Compare-Object` compares collections as sets and calls that +//! identical -- it passed three genuinely broken probes here before the +//! comparison was redone line-by-line. + +use std::panic::{AssertUnwindSafe, catch_unwind, resume_unwind}; + +/// Somewhere a probe's report can go. +pub trait Report { + /// Emit one line. + fn line(&mut self, text: &str); +} + +/// The real stream. +pub struct Stdout; + +impl Report for Stdout { + fn line(&mut self, text: &str) { + println!("{text}"); + } +} + +/// A report that keeps what it was given. +/// +/// The point of the whole abstraction: a probe's findings become a value a test +/// can read, rather than bytes only a terminal ever sees. +#[derive(Debug, Default)] +pub struct Captured { + /// Lines written, in order. + pub lines: Vec, +} + +impl Report for Captured { + fn line(&mut self, text: &str) { + self.lines.push(text.to_owned()); + } +} + +impl Captured { + /// The report as one string, as a reader would see it. + #[must_use] + pub fn text(&self) -> String { + self.lines.join("\n") + } +} + +/// Write a rendered block to `report`, one line at a time. +/// +/// A `render_*` function produces a whole block with embedded newlines and a +/// [`Report`] speaks in lines, so this is the join between them. Splitting +/// rather than passing the block through keeps [`Captured`] line-addressable, +/// which is what lets a test name a row instead of searching the whole document +/// for a substring. +/// +/// A trailing newline does not produce an extra empty line, because +/// `str::lines` does not yield one -- so a renderer may end its block either way +/// without changing what a reader sees. +pub fn emit(report: &mut impl Report, block: &str) { + for line in block.lines() { + report.line(line); + } +} + +/// Compose a report and emit it, **including when composing it panics**. +/// +/// Every probe's `main` is one call to this. The buffer is owned here rather +/// than inside the renderer so that a measurement which aborts part-way still +/// prints what it had already established. +/// +/// That is not hypothetical bookkeeping. These probes call into measurements +/// documented to panic -- `worker_context`'s impersonating observation panics if +/// the token cannot be duplicated or applied, or if the worker never reports -- +/// and each renderer composes several completed findings *before* reaching one. +/// Printing line-by-line used to make that automatic: whatever had been measured +/// was already on the terminal. Buffering the whole report to hand it to a +/// [`Report`] silently gave that up, and for an instrument the point of which is +/// that a failure be diagnosable, how far it got is exactly the information +/// worth keeping. +/// +/// The panic is resumed afterwards, so the exit status and the message are +/// unchanged; the partial report is added to them, not substituted for them. +/// +/// **This restores the streaming property for unwinding panics only, and that +/// bound is known rather than overlooked.** A termination that does not unwind +/// still loses the buffer, where printing line-by-line would have kept it: Ctrl-C +/// (the default Windows console handler terminates the process outright), and an +/// abort from a panic raised during unwinding. The case that costs most is +/// `probe-cancel-io`, which can run four attempts at a five-second watchdog -- +/// so about twenty seconds, precisely when the wedge it hunts for occurs, which +/// is precisely when a reader interrupts it. +/// +/// Fixing it properly means the renderers writing into a [`Report`] as they go +/// rather than into a `String`, which keeps [`Captured`] working for tests and +/// streams for real runs. That is a different design rather than an oversight in +/// this one -- it changes every renderer -- so it is queued as its own work: +/// milestone `M1` of [CHECKLIST.md](../CHECKLIST.md), with the reasoning in +/// [DESIGN-NOTES.md](../DESIGN-NOTES.md#d-buffered-report). +pub fn emit_report(render: impl FnOnce(&mut String)) { + emit_report_to(&mut Stdout, render); +} + +/// [`emit_report`] against an arbitrary sink. +/// +/// Exists so the catch-emit-resume logic is what a test executes, rather than a +/// second copy of that shape written in the test. The first version of the test +/// re-implemented it against a [`Captured`] and so would have passed with the +/// `resume_unwind` below deleted -- which would leave a probe printing a partial +/// report and exiting **0**, the failure that looks most like success. +pub fn emit_report_to(report: &mut impl Report, render: impl FnOnce(&mut String)) { + let mut out = String::new(); + + // `AssertUnwindSafe` because the only state crossing the boundary is this + // buffer, and a partially written report is precisely what is wanted here + // rather than a hazard to be guarded against. + let outcome = catch_unwind(AssertUnwindSafe(|| render(&mut out))); + + emit(report, &out); + + if let Err(payload) = outcome { + resume_unwind(payload); + } +} + +#[cfg(test)] +mod tests; diff --git a/crates/windows-platform-probes/src/report/tests.rs b/crates/windows-platform-probes/src/report/tests.rs new file mode 100644 index 000000000..384490c0f --- /dev/null +++ b/crates/windows-platform-probes/src/report/tests.rs @@ -0,0 +1,110 @@ +// Copyright (c) Mike Grier. +//! Tests for the report sink. +//! +//! These are small, and that is the point: the sink's whole job is to be the +//! seam that lets a probe's *findings* be asserted rather than eyeballed. What +//! is worth pinning here is the seam's own behaviour, so that a test written +//! against a probe's report can trust what it is reading. + +use std::fmt::Write as _; +use std::panic::{AssertUnwindSafe, catch_unwind}; + +use super::{Captured, Report, emit, emit_report_to}; + +#[test] +fn a_captured_report_keeps_its_lines_in_order() { + // Order is the property a probe's report depends on most: its tables are + // rows under a header, and a sink that reordered them would turn a correct + // measurement into a wrong one. + let mut captured = Captured::default(); + captured.line("header"); + captured.line("row one"); + captured.line("row two"); + + assert_eq!(captured.lines, ["header", "row one", "row two"]); + assert_eq!(captured.text(), "header\nrow one\nrow two"); +} + +#[test] +fn emitting_a_block_gives_the_report_one_line_at_a_time() { + // What makes a captured report addressable by line rather than by substring + // search -- so a test can say "the third row" instead of hoping a phrase is + // unique in the document. + let mut captured = Captured::default(); + emit(&mut captured, "one\ntwo\nthree"); + + assert_eq!(captured.lines, ["one", "two", "three"]); +} + +#[test] +fn a_trailing_newline_does_not_become_an_extra_blank_line() { + // A renderer may end its block with a newline or without one, and the two + // must look the same to a reader. Otherwise every `render_*` function would + // have to agree on a convention that nothing enforces, and the first one to + // drift would add a blank line nobody could account for. + let mut with = Captured::default(); + let mut without = Captured::default(); + emit(&mut with, "one\ntwo\n"); + emit(&mut without, "one\ntwo"); + + assert_eq!(with.lines, without.lines); +} + +#[test] +fn an_interior_blank_line_survives() { + // The other side of the previous test, and the reason it cannot simply + // filter empties: these reports use blank lines to separate sections, so a + // sink that swallowed them would run the tables together. + let mut captured = Captured::default(); + emit(&mut captured, "section\n\nnext"); + + assert_eq!(captured.lines, ["section", "", "next"]); +} + +#[test] +fn a_renderer_that_panics_still_has_its_finished_lines_emitted() { + // The property `emit_report` exists for, exercised through the real + // function rather than through a second copy of its shape. + // + // An earlier version of this test re-implemented catch-emit-resume against a + // `Captured` and never called into `report` at all. It would have passed + // with the `resume_unwind` deleted -- and a probe that swallowed its panic + // would print a partial report and exit **0**, which is the failure that + // looks most like success. Hence `emit_report_to`: same logic, injectable + // sink. + let mut captured = Captured::default(); + + let outcome = catch_unwind(AssertUnwindSafe(|| { + emit_report_to(&mut captured, |out| { + let _ = writeln!(out, "measured before the failure"); + panic!("a measurement aborted"); + }); + })); + + // Both halves matter, and each fails a different mutation. Without the + // first, deleting the `emit` leaves the test green; without the second, + // deleting the `resume_unwind` does. + assert_eq!( + captured.lines, + ["measured before the failure"], + "what was already established must survive the abort" + ); + assert!( + outcome.is_err(), + "the panic must reach the caller, or the probe exits 0 having failed" + ); +} + +#[test] +fn a_renderer_that_returns_normally_reports_every_line_and_does_not_panic() { + // The other side of the same function: the ordinary path must be unaffected + // by the machinery that exists for the failing one. + let mut captured = Captured::default(); + + emit_report_to(&mut captured, |out| { + let _ = writeln!(out, "first"); + let _ = writeln!(out, "second"); + }); + + assert_eq!(captured.lines, ["first", "second"]); +} diff --git a/crates/windows-platform-probes/tests/a_probe_writes_its_report_to_stdout.rs b/crates/windows-platform-probes/tests/a_probe_writes_its_report_to_stdout.rs new file mode 100644 index 000000000..e93ac68ef --- /dev/null +++ b/crates/windows-platform-probes/tests/a_probe_writes_its_report_to_stdout.rs @@ -0,0 +1,72 @@ +// Copyright (c) Mike Grier. + +//! The one thing the unit tests cannot reach: that `Stdout` actually writes. +//! +//! `report::Captured` makes a probe's findings a value a test can read, and the +//! unit tests use it for everything. But that means every in-process test passes +//! whether or not `report::Stdout` -- the implementation every probe uses in +//! production -- emits anything at all. +//! +//! Found by mutation testing rather than by inspection: replacing +//! `::line` with `()` survived the whole suite. A no-op +//! there means every probe in this crate runs, exits zero, and prints nothing, +//! which is the failure mode that looks most like success. +//! +//! Stable Rust cannot redirect this process's own stdout, so covering it needs a +//! real child process. That makes this an integration test by the repository's +//! own criterion -- it crosses a process boundary -- rather than by preference. + +use std::process::Command; + +/// A probe is exercised rather than the sink tested directly, because the sink +/// is only interesting as the thing a probe uses. +/// +/// `probe-error-mode` is the one picked: it needs no privileges, no particular +/// hardware, and no device, so it behaves the same on a developer's machine and +/// on a CI runner. `CARGO_BIN_EXE_*` is set by cargo for integration tests, so +/// the path is the binary this build produced rather than whatever is on PATH. +#[test] +fn a_probe_run_as_a_process_prints_its_report() { + let output = Command::new(env!("CARGO_BIN_EXE_probe-error-mode")) + .output() + .expect("run the probe"); + + assert!( + output.status.success(), + "the probe exited with {:?}; stderr: {}", + output.status.code(), + String::from_utf8_lossy(&output.stderr) + ); + + let stdout = String::from_utf8(output.stdout).expect("a probe's report is UTF-8"); + + // The assertion that kills the mutant. Everything below it is about the + // report being *right*; this one is about it existing at all. + assert!( + !stdout.trim().is_empty(), + "the probe produced no output, so nothing it measured reached anyone" + ); + + let lines: Vec<&str> = stdout.lines().collect(); + + // The banner is rendered into the report rather than printed beside it, so + // that a captured report carries the machine it describes. If it ever stops + // being the first line, a pasted finding can be compared against hardware it + // was not measured on. + // + // Matched on the `host:` prefix alone, which `banner_line` emits on both its + // success and its topology-discovery-failed paths -- so this holds on a + // machine where discovery fails, and does not encode this machine's shape. + assert!( + lines[0].starts_with("host:"), + "the report's first line should be the host banner, was: {:?}", + lines[0] + ); + + // A banner and nothing else would satisfy everything above while the + // findings themselves went missing. + assert!( + lines.len() > 1, + "the report was only its banner; the probe's own findings are missing" + ); +}