From ae1e39f52977e0b7b612fc4fa7d49af6b49a3ea1 Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 08:33:38 -0400 Subject: [PATCH 01/17] feat(platform-probes): measure what a doorbell and a namespace request cost Fifth slice peeled off `mikegrier/deferred-namespace-ops` (#56), after #79, #80, #81 and #82. Two probes, peeled together because neither answers its question alone. The two-layer ring design assumes signalling a waiting consumer is expensive enough to be worth avoiding, and proposes an eventcount -- publish intent to park, re-check the queue, then wait -- so a producer rings the doorbell only on the empty-to-non-empty edge. Publish-recheck-park is exactly where lost wakeups live, so building it because the cost was *assumed* would be taking on the highest-risk part of the design without evidence. `probe-doorbell-cost` supplies that evidence: `SetEvent` against an already signalled event, a full set/reset cycle, a satisfied wait, and an empty `SubmitIoRing`, each against an uncontended `fetch_add` floor. It also times a real park-and-wake round trip, which is what is actually paid when the consumer sleeps rather than spins. `probe-request-cost` asks the other half. The submission queue was specified to carry POD descriptors with no allocation on push, and a deferred `CreateFileW` carries a path, which is neither -- so that requirement and the namespace plane's needs cannot both hold as written. `windows-namespace-request-sys` already solves the hard part by making an `OpenFile` an owned, `Send` parameter set, so the queue can carry a request by value; what remains is what building one costs against the doorbell that would carry it. Read alone, either probe invites the wrong conclusion; read together they say whether the queue's mechanics or the request's own cost deserves the attention. Both run `--release` in CI, and only these two do. Every other probe here measures BEHAVIOUR -- what an API refuses, what a handle reports -- which does not change with the optimisation level. These two compare operations tens of nanoseconds apart, where the loop and closure indirection around each measured call carry overhead that does not shrink uniformly across them, and the ratios are what the design reads. The park-and-wake handshake is bounded rather than INFINITE deliberately: its first implementation DEADLOCKED, because an auto-reset event does not count signals and the waiter's count never caught up. Two tests pin that it completes, and they are bounded by construction -- a probe that can hang is a probe that can hang a build. Also adds the two probe-table rows in `lib.rs` that the source branch never had. The table is headed "what each probe establishes" and lists binary-only probes, so omitting these two made it wrong about its own scope. Measured on an x86_64 16p/8c host: a doorbell cycle costs 255x an uncontended atomic, a real park-and-wake round trip 43x that again, and building a pathed request 212 ns. The doorbell probe declines to derive a "doorbell is N% of a syscall" figure from its own `SubmitIoRing` number, because 214 ns is too cheap for a kernel transition and is almost certainly short-circuiting in user mode -- a confident wrong answer being worse than no answer. --- .github/workflows/ci.yml | 25 ++ Cargo.lock | 1 + crates/windows-platform-probes/Cargo.toml | 15 + .../src/bin/doorbell_cost.rs | 193 ++++++++++++ .../src/bin/request_cost.rs | 281 +++++++++++++++++ .../src/doorbell_cost.rs | 287 ++++++++++++++++++ crates/windows-platform-probes/src/lib.rs | 6 +- .../src/request_cost.rs | 250 +++++++++++++++ crates/windows-platform-probes/src/tests.rs | 43 +++ 9 files changed, 1100 insertions(+), 1 deletion(-) create mode 100644 crates/windows-platform-probes/src/bin/doorbell_cost.rs create mode 100644 crates/windows-platform-probes/src/bin/request_cost.rs create mode 100644 crates/windows-platform-probes/src/doorbell_cost.rs create mode 100644 crates/windows-platform-probes/src/request_cost.rs diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 67895fa08..907ed1a51 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -266,6 +266,31 @@ jobs: - name: probe magnitudes (topology) if: '!cancelled()' run: cargo run -p windows-platform-probes --bin probe-topology --locked + # `--release` on the next two, and ONLY on those two, because they are the + # only probes here that report nanoseconds. Everything above measures + # BEHAVIOUR -- what an API refuses, what a handle reports, which errors + # appear -- and that does not change with the optimisation level, so those + # keep the dev profile and the build time it saves. + # + # These two do not have that luxury. They compare operations a few tens of + # nanoseconds apart, and in an unoptimized build the loop, the closure + # indirection, and the request construction around each measured call + # carry overhead that does not shrink uniformly across them. The RATIOS + # are what the design reads -- "a doorbell is x% of a submit", "a captured + # handle costs Nx a built request" -- and a ratio of two figures each + # inflated by a different amount is not the shipping one. + # + # Decides how much machinery the two-layer ring's doorbell needs. Its + # park-and-wake handshake is bounded rather than INFINITE on purpose: the + # first version of it deadlocked, because an auto-reset event does not + # count signals and the waiter's count never caught up. A probe that can + # hang is a probe that can hang a build. + - name: probe magnitudes (doorbell cost) + run: cargo run -p windows-platform-probes --bin probe-doorbell-cost --locked --release + # Read with the doorbell probe above: together they say whether the + # queue's mechanics or the request's own cost deserves the attention. + - name: probe magnitudes (request cost) + run: cargo run -p windows-platform-probes --bin probe-request-cost --locked --release # Both halves of the long-path pair, deliberately. Either alone says # nothing: the finding is the *difference* between two executables that # differ only in whether `build.rs` embedded the `longPathAware` manifest, diff --git a/Cargo.lock b/Cargo.lock index 140169c83..350590843 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -216,6 +216,7 @@ dependencies = [ name = "windows-platform-probes" version = "0.0.0" dependencies = [ + "windows-namespace-request-sys", "windows-placement-probe", "windows-sys", "windows-threadpool-sys", diff --git a/crates/windows-platform-probes/Cargo.toml b/crates/windows-platform-probes/Cargo.toml index 88cf25858..807d09fe5 100644 --- a/crates/windows-platform-probes/Cargo.toml +++ b/crates/windows-platform-probes/Cargo.toml @@ -51,6 +51,14 @@ path = "src/bin/pool_growth.rs" name = "probe-topology" path = "src/bin/topology.rs" +[[bin]] +name = "probe-doorbell-cost" +path = "src/bin/doorbell_cost.rs" + +[[bin]] +name = "probe-request-cost" +path = "src/bin/request_cost.rs" + # These two are the same code, and that is the measurement: they differ only in # whether `build.rs` embeds the `longPathAware` manifest, which is not a runtime # switch and so cannot be a flag on one binary. @@ -87,6 +95,10 @@ windows-topology-sys = { path = "../windows-topology-sys" } # 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" } +# The request-cost probe measures the real request type the design would put on +# a queue, not a stand-in, for the same reason the topology probe reads the +# shipping parse: a reimplementation would measure the reimplementation. +windows-namespace-request-sys = { path = "../windows-namespace-request-sys" } # The long-path probe measures a length against `MAX_PATH`, and `MAX_PATH` counts # UTF-16 code units. `OsStr::len` counts Rust's platform encoding -- WTF-8 here -- # so the two disagree the moment a non-ASCII character appears in `%TEMP%`, which @@ -115,6 +127,9 @@ features = [ "Win32_System_Diagnostics_Debug", "Win32_System_IO", "Win32_System_Pipes", + # GetSystemDirectoryW, so the request probe measures the real system + # directory instead of assuming Windows is installed on C:. + "Win32_System_SystemInformation", "Win32_System_SystemServices", "Win32_System_Threading", ] diff --git a/crates/windows-platform-probes/src/bin/doorbell_cost.rs b/crates/windows-platform-probes/src/bin/doorbell_cost.rs new file mode 100644 index 000000000..80d0c429d --- /dev/null +++ b/crates/windows-platform-probes/src/bin/doorbell_cost.rs @@ -0,0 +1,193 @@ +// Copyright (c) Mike Grier. + +//! Prints how expensive a doorbell is relative to the syscall it would guard. +//! +//! **An experiment, not a component.** These probes measure platform behaviour +//! and are not for production use. Do not call them from production code, and +//! do not lift a technique out of here. See this crate's DESIGN-NOTES.md. +//! +//! This decides whether the two-layer ring design needs an eventcount at all. +//! If a doorbell is a meaningful fraction of `SubmitIoRing`, the skip-when-busy +//! rules are load-bearing. If it is noise, a simple always-signal queue is +//! adequate and the more delicate protocol -- publish intent, re-check, park -- +//! can wait for evidence that it is worth its lost-wakeup risk. + +use std::fmt::Write as _; +use windows_platform_probes::doorbell_cost::{Observation, measure, measure_park_and_wake}; + +use windows_platform_probes::report::{Stdout, emit}; + +fn main() { + // The only place that names the real stream. Everything above composes + // text; nothing above knows where it goes. + emit( + &mut Stdout, + &render(&measure(), measure_park_and_wake(20_000)), + ); +} + +/// The probe's whole report, as text. +fn render(observation: &Observation, park: Option) -> String { + let mut out = String::new(); + // 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 + // timing number can be pasted anywhere and compared against anything. + let _ = writeln!( + out, + "{}", + windows_placement_probe::fingerprint::banner_line() + ); + let _ = writeln!( + out, + "== what does a doorbell cost, against the syscall it guards? ==\n" + ); + + let _ = writeln!(out, "{:<30} {:>12}", "operation", "ns/op"); + for timing in &observation.timings { + let _ = writeln!(out, "{:<30} {:>12.1}", timing.label, timing.nanos_per_op); + } + + match park { + Some(ns) => { + let _ = writeln!(out, "{:<30} {:>12.1}", "park_and_wake round trip", ns); + } + None => { + let _ = writeln!( + out, + "{:<30} {:>12}", + "park_and_wake round trip", "TIMED OUT" + ); + } + } + + let _ = writeln!(out, "\ninterpretation:"); + + if let Some(atomic) = observation.get("atomic_fetch_add") + && let Some(doorbell) = observation.get("set_reset_event") + && atomic > 0.0 + { + let _ = writeln!( + out, + " a doorbell cycle costs {:.0}x an uncontended atomic ({:.0} ns vs {:.1} ns).", + doorbell / atomic, + doorbell, + atomic + ); + if let Some(park) = park { + let _ = writeln!( + out, + " an actual park-and-wake round trip costs {:.0}x that again ({:.0} ns),", + park / doorbell, + park + ); + let _ = writeln!( + out, + " which is what is paid when the consumer genuinely sleeps." + ); + } + } + + // Deliberately NOT expressed as a share of the empty submit. See below. + if let Some(submit) = observation.submit_nanos { + let _ = writeln!( + out, + "\n CAUTION: an empty SubmitIoRing measured {submit:.0} ns, which is far too" + ); + let _ = writeln!( + out, + " cheap for a kernel transition -- it is almost certainly short-" + ); + let _ = writeln!( + out, + " circuiting in user mode when there is nothing queued. It is" + ); + let _ = writeln!( + out, + " therefore NOT a fair denominator, and any 'doorbell is N% of a" + ); + let _ = writeln!( + out, + " syscall' figure derived from it would be a confident wrong answer." + ); + let _ = writeln!( + out, + " The honest denominator is the cost of the real work a submission" + ); + let _ = writeln!(out, " carries, which this probe does not measure."); + } + + // What can be said without a denominator: how much batching it takes for + // the doorbell to disappear, which is the lever the design actually has. + if let Some(doorbell) = observation.get("set_reset_event") + && let Some(atomic) = observation.get("atomic_fetch_add") + && atomic > 0.0 + { + let _ = writeln!( + out, + "\n batching is the lever, and it is a strong one. One doorbell per" + ); + let _ = writeln!(out, " drained batch costs, per operation:"); + for batch in [1_u32, 8, 32, 128] { + let _ = writeln!( + out, + " batch of {batch:>4}: {:>7.1} ns/op ({:.1}x an atomic)", + doorbell / f64::from(batch), + doorbell / f64::from(batch) / atomic + ); + } + let break_even = (doorbell / atomic).ceil() as u32; + let _ = writeln!( + out, + " so at a batch of about {break_even}, the doorbell costs less per" + ); + let _ = writeln!(out, " operation than the atomic push it accompanies."); + } + + let _ = writeln!( + out, + "\n => The skip-when-busy rule is a refinement, not a prerequisite." + ); + let _ = writeln!( + out, + " Batching alone drives the doorbell below the cost of the push," + ); + let _ = writeln!( + out, + " so a first implementation can always-signal and stay honest." + ); + let _ = writeln!( + out, + " Adopt the eventcount when a measurement against real work" + ); + let _ = writeln!(out, " justifies its lost-wakeup risk -- not before."); + + let atomic = observation.get("atomic_fetch_add").unwrap_or(f64::NAN); + let already = observation + .get("set_event_already_signalled") + .unwrap_or(f64::NAN); + let cycle = observation.get("set_reset_event").unwrap_or(f64::NAN); + let wait0 = observation.get("wait_zero_signalled").unwrap_or(f64::NAN); + let _ = writeln!( + out, + concat!( + r#"{{"reason":"x-probe-doorbell-cost","arch":"{}","atomic_ns":{:.1},"#, + r#""set_event_already_signalled_ns":{:.1},"set_reset_event_ns":{:.1},"#, + r#""wait_zero_signalled_ns":{:.1},"park_and_wake_round_trip_ns":{},"#, + r#""submit_io_ring_empty_ns":{},"doorbell_share_of_submit":{}}}"# + ), + std::env::consts::ARCH, + atomic, + already, + cycle, + wait0, + park.map_or("null".to_string(), |n| format!("{n:.1}")), + observation + .submit_nanos + .map_or("null".to_string(), |n| format!("{n:.1}")), + observation + .doorbell_share_of_submit() + .map_or("null".to_string(), |s| format!("{s:.4}")), + ); + out +} diff --git a/crates/windows-platform-probes/src/bin/request_cost.rs b/crates/windows-platform-probes/src/bin/request_cost.rs new file mode 100644 index 000000000..1c65ceb1d --- /dev/null +++ b/crates/windows-platform-probes/src/bin/request_cost.rs @@ -0,0 +1,281 @@ +// Copyright (c) Mike Grier. + +//! Prints what a namespace request costs to build, against the queue that would +//! carry it. +//! +//! **An experiment, not a component.** These probes measure platform behaviour +//! and are not for production use. Do not call them from production code, and +//! do not lift a technique out of here. See this crate's DESIGN-NOTES.md. +//! +//! Read alongside `probe-doorbell-cost`: together they say whether the queue's +//! mechanics or the request's allocation model deserves the attention. + +use std::fmt::Write as _; +use windows_platform_probes::report::{Stdout, emit}; +use windows_platform_probes::request_cost::measure; + +/// Measured by `probe-doorbell-cost` on the development machine, and recorded in +/// [the 2026-08-30 design session]. Restated here only to render a ratio; the +/// authoritative number is whatever that probe prints on the host this runs on. +/// +/// **The build profile behind these is not recorded**, which is why the report +/// below calls the ratios indicative rather than quoting them as results. They +/// are not re-baselined here: the figure is the one that session recorded, and +/// silently replacing it would leave the session describing a number that no +/// longer exists anywhere. CI runs both this probe and `probe-doorbell-cost` +/// under `--release` in the same job, so the like-for-like comparison a reader +/// actually wants is those two outputs, not this constant. +/// +/// [the 2026-08-30 design session]: ../../../../design-sessions/DESIGN-SESSION-2026-08-30-numa-sharded-io-execution-domains.md +const DOORBELL_NS_REFERENCE: f64 = 164.9; +const ATOMIC_NS_REFERENCE: f64 = 7.2; + +fn main() { + // The only place that names the real stream. Everything below composes + // text; nothing below knows where it goes. + emit(&mut Stdout, &render()); +} + +/// The probe's whole report, as text. +fn render() -> String { + let mut out = String::new(); + // 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 + // timing number can be pasted anywhere and compared against anything. + let _ = writeln!( + out, + "{}", + windows_placement_probe::fingerprint::banner_line() + ); + let _ = writeln!(out, "== what does a namespace request cost to build? ==\n"); + + let observation = measure(); + + let _ = writeln!( + out, + "{:<26} {:>10} {:>14} {:>16}", + "operation", "ns/op", "x an atomic", "x a doorbell" + ); + for timing in &observation.timings { + let _ = writeln!( + out, + "{:<26} {:>10.1} {:>14.1} {:>16.2}", + timing.label, + timing.nanos_per_op, + timing.nanos_per_op / ATOMIC_NS_REFERENCE, + timing.nanos_per_op / DOORBELL_NS_REFERENCE, + ); + } + let _ = writeln!( + out, + "\n(ratios use the reference doorbell {DOORBELL_NS_REFERENCE:.1} ns and atomic \ + {ATOMIC_NS_REFERENCE:.1} ns measured\n by probe-doorbell-cost on the development \ + machine; re-read that probe on this host\n before trusting them)" + ); + + let _ = writeln!(out, "\ninterpretation:"); + + let build = observation.get("build_open_request"); + let capture = observation.get("capture_handle"); + + if let Some(build) = build { + // The ratio names its own reference, because the two numbers do not + // come from the same machine. `build` was measured on this host just + // now; the doorbell figure is a constant captured once on the + // development machine. This probe now runs on hosted CI runners, which + // are a heterogeneous fleet, so a ratio printed as though both halves + // were local can be wrong even when the measurement is sound. + let _ = writeln!( + out, + " building a pathed request costs {build:.0} ns, which is {:.1}x one", + build / DOORBELL_NS_REFERENCE + ); + let _ = writeln!( + out, + " doorbell AS MEASURED ON THE DEVELOPMENT MACHINE ({DOORBELL_NS_REFERENCE:.1} ns)," + ); + let _ = writeln!( + out, + " not on this one. Run probe-doorbell-cost here to make the ratio local." + ); + let _ = writeln!(out); + let _ = writeln!( + out, + " SCOPE, because this is easy to over-read: that is a statement about" + ); + let _ = writeln!( + out, + " ONE OPERATION TYPE, not about the queue. A namespace open is the" + ); + let _ = writeln!( + out, + " heaviest payload the queue carries -- it resolves a path through" + ); + let _ = writeln!( + out, + " Win32 and may duplicate a handle -- and it ends in a CreateFileW" + ); + let _ = writeln!( + out, + " costing microseconds regardless. A registered-buffer read, which is" + ); + let _ = writeln!( + out, + " the hot path, carries no path and no handle: its descriptor is a slot" + ); + let _ = writeln!( + out, + " index and an offset, and there the queue's own mechanics are the" + ); + let _ = writeln!(out, " whole cost."); + let _ = writeln!(out); + let _ = writeln!( + out, + " Nor is per-operation overhead the same thing as queue efficiency." + ); + let _ = writeln!( + out, + " Throughput under contention, cache behaviour, batching amortization" + ); + let _ = writeln!( + out, + " and backpressure decide that, and a single uncontended construction" + ); + let _ = writeln!(out, " time measures none of them."); + let _ = writeln!(out); + let _ = writeln!( + out, + " What it does support: for an open-heavy workload, doorbell tuning" + ); + let _ = writeln!( + out, + " would be optimizing the small half. That is a finding about" + ); + let _ = writeln!( + out, + " OPERATION MIX, and it says nothing about the read path." + ); + } + + if let Some(capture) = capture { + let _ = writeln!( + out, + "\n duplicating a handle costs {capture:.0} ns -- a kernel transition, not" + ); + let _ = writeln!( + out, + " a memory copy, and easy to under-count when thinking about what an" + ); + let _ = writeln!(out, " SQE holds."); + // Reported beside it because the duplication figure above excludes it by + // construction, and a reader sizing a request's real cost needs both: + // every captured handle is eventually closed, so the lifecycle is the + // pair. Keeping them separate is what stops either being quoted as the + // other. + if let Some(close) = observation.get("close_handle") { + let _ = writeln!( + out, + " Closing one costs a further {close:.0} ns, measured separately, so a" + ); + let _ = writeln!( + out, + " captured handle's whole lifecycle is {:.0} ns. The duplication figure", + capture + close + ); + let _ = writeln!(out, " above is the duplication alone."); + } + if let Some(build) = build { + if capture > build { + let _ = writeln!( + out, + " It is {:.1}x the cost of building the pathed request itself, so a", + capture / build + ); + let _ = writeln!( + out, + " request carrying a handle is dominated by the duplication, and" + ); + let _ = writeln!( + out, + " any allocation tuning on the path would be optimizing the wrong" + ); + let _ = writeln!(out, " half."); + } else { + let _ = writeln!( + out, + " It is {:.2}x the pathed request, so the two are comparable and", + capture / build + ); + let _ = writeln!(out, " neither dominates."); + } + } + } + + // The split that decides whether an allocator change can help at all. + if let Some(build) = build + && let Some(clone) = observation.get("clone_prepared_units") + && build > clone + { + let _ = writeln!( + out, + "\n WHERE THE TIME ACTUALLY GOES, and it is not the allocator:" + ); + let _ = writeln!( + out, + " `prepare` calls GetFullPathNameW to resolve the path against the" + ); + let _ = writeln!( + out, + " process working directory -- a Win32 call, because the CWD is mutable" + ); + let _ = writeln!( + out, + " by any thread and resolving later would be racy. So most of the cost" + ); + let _ = writeln!( + out, + " above is a syscall that no allocation scheme can remove." + ); + let _ = writeln!( + out, + " Cloning already-prepared units is {clone:.0} ns, which bounds what an" + ); + let _ = writeln!( + out, + " inline-storage or recycling scheme could recover at {:.0} ns per request", + build - clone + ); + let _ = writeln!( + out, + " AT MOST -- and only for a caller that can reuse a resolved path." + ); + let _ = writeln!( + out, + " A caller with a fresh path each time pays the resolution regardless." + ); + } + + let get = |label: &str| { + observation + .get(label) + .map_or("null".to_string(), |n| format!("{n:.1}")) + }; + let _ = writeln!( + out, + concat!( + r#"{{"reason":"x-probe-request-cost","arch":"{}","prepare_short_ns":{},"#, + r#""prepare_long_ns":{},"build_open_request_ns":{},"#, + r#""clone_prepared_units_ns":{},"capture_handle_ns":{},"#, + r#""close_handle_ns":{}}}"# + ), + std::env::consts::ARCH, + get("prepare_short_path"), + get("prepare_long_path"), + get("build_open_request"), + get("clone_prepared_units"), + get("capture_handle"), + get("close_handle"), + ); + out +} diff --git a/crates/windows-platform-probes/src/doorbell_cost.rs b/crates/windows-platform-probes/src/doorbell_cost.rs new file mode 100644 index 000000000..5d0ed95c5 --- /dev/null +++ b/crates/windows-platform-probes/src/doorbell_cost.rs @@ -0,0 +1,287 @@ +// Copyright (c) Mike Grier. + +//! How expensive is a doorbell, relative to the syscall it would guard? +//! +//! **An experiment, not a component.** These probes measure platform behaviour +//! and are not for production use. Do not call them from production code, and +//! do not lift a technique out of here. See this crate's DESIGN-NOTES.md. +//! +//! # The decision this exists to inform +//! +//! The two-layer ring design has a client thread push a descriptor onto a +//! bounded MPSC queue and then, sometimes, signal an event so the domain thread +//! wakes. The design assumes that signal is expensive enough to be worth +//! avoiding, and proposes an eventcount -- publish intent to park, re-check the +//! queue, then wait -- so a producer rings the doorbell only on the +//! empty-to-non-empty edge and only when a consumer is actually parked. +//! +//! That protocol is the highest-risk part of the whole design, because +//! publish-recheck-park is exactly where lost wakeups live. Building it because +//! the cost was *assumed* would be taking on that risk without evidence. So: +//! +//! - if `SetEvent` is a meaningful fraction of `SubmitIoRing`, the skip rules +//! are load-bearing and belong in the design from the start; +//! - if it is noise, a simple always-signal queue is adequate and the +//! optimization can wait for a measurement that justifies it. +//! +//! # What is timed +//! +//! Each is a tight loop over a warm path, reported as nanoseconds per +//! operation. Absolute values are host-specific and uninteresting; the +//! **ratios** are the finding. +//! +//! - `atomic_fetch_add` -- the uncontended atomic that a queue push costs, as a +//! floor for "the cheapest useful thing". +//! - `set_event_already_signalled` -- `SetEvent` on an event that is already +//! set, which is the redundant-signal case the skip rule removes. +//! - `set_reset_event` -- `SetEvent` then `ResetEvent`, the honest cost of one +//! doorbell cycle with nobody waiting. +//! - `wait_zero_signalled` -- `WaitForSingleObject(handle, 0)` on a signalled +//! event: the consumer's cost of observing it. +//! - `submit_io_ring_empty` -- `SubmitIoRing` with nothing queued, which is the +//! syscall the doorbell would be amortised against. Absent when `IoRing` is +//! unavailable. +//! +//! # The empty submit is not a fair denominator, and the first run proved it +//! +//! This probe was written expecting to divide the doorbell cost by +//! `submit_io_ring_empty` and read off "the doorbell is N% of a syscall". **Do +//! not do that.** Measured on the development machine, an empty `SubmitIoRing` +//! came in at ~79 ns -- far too cheap for a kernel transition, so it is almost +//! certainly short-circuiting in user mode when there is nothing queued. The +//! resulting "doorbell is 210% of a syscall" would have been a confident wrong +//! answer built on a denominator that never entered the kernel. +//! +//! The honest denominator is the cost of the real work a submission carries, +//! which this probe deliberately does not measure -- so it reports the absolute +//! costs and the *batching* arithmetic instead, and leaves the ratio alone. +//! [`Observation::doorbell_share_of_submit`] is retained only because the raw +//! fact is worth recording; its own documentation repeats this warning. + +use std::sync::atomic::{AtomicU64, Ordering}; +use std::time::Instant; + +use windows_sys::Win32::Foundation::{CloseHandle, HANDLE, WAIT_OBJECT_0}; +use windows_sys::Win32::System::Threading::{ + CreateEventW, ResetEvent, SetEvent, WaitForSingleObject, +}; + +use crate::ioring; + +/// Nanoseconds per operation for one timed loop. +#[derive(Debug, Clone, Copy, PartialEq)] +pub struct Timing { + /// What was timed. + pub label: &'static str, + /// Iterations executed. + pub iterations: u32, + /// Nanoseconds per iteration. + pub nanos_per_op: f64, +} + +/// Every timing, plus the ratios that actually decide the design question. +#[derive(Debug, Clone)] +pub struct Observation { + /// Each timed loop, in the order run. + pub timings: Vec, + /// `None` when `IoRing` is unavailable on this host. + pub submit_nanos: Option, +} + +impl Observation { + /// Look a timing up by label. + #[must_use] + pub fn get(&self, label: &str) -> Option { + self.timings + .iter() + .find(|t| t.label == label) + .map(|t| t.nanos_per_op) + } + + /// One doorbell cycle as a fraction of one **empty** `SubmitIoRing`. + /// + /// **This is not the number the design turns on, and it should not be read + /// as one.** An empty submit does not appear to enter the kernel (see the + /// module documentation), so this ratio has a denominator that is not a + /// syscall. It is exposed because the raw fact is worth recording across + /// hosts -- a machine where the empty submit is *expensive* would itself be + /// a finding -- not because dividing by it answers anything. + #[must_use] + pub fn doorbell_share_of_submit(&self) -> Option { + let doorbell = self.get("set_reset_event")?; + let submit = self.submit_nanos?; + (submit > 0.0).then_some(doorbell / submit) + } +} + +fn time_loop(label: &'static str, iterations: u32, mut body: impl FnMut()) -> Timing { + // Warm the path first: the first call through a syscall stub pays for + // resolution and page faults that a steady-state cost should not include. + for _ in 0..1024 { + body(); + } + let start = Instant::now(); + for _ in 0..iterations { + body(); + } + let elapsed = start.elapsed(); + Timing { + label, + iterations, + nanos_per_op: elapsed.as_nanos() as f64 / f64::from(iterations), + } +} + +/// Run every timing. +/// +/// # Panics +/// +/// Panics if `CreateEventW` fails, which would mean the host cannot create a +/// manual-reset event and nothing here is measurable. +#[must_use] +pub fn measure() -> Observation { + const ITERATIONS: u32 = 200_000; + + // SAFETY: a manual-reset, initially-unsignalled, unnamed event. + let event: HANDLE = unsafe { CreateEventW(std::ptr::null(), 1, 0, std::ptr::null()) }; + assert!(!event.is_null(), "CreateEventW failed"); + + let counter = AtomicU64::new(0); + let mut timings = Vec::new(); + + timings.push(time_loop("atomic_fetch_add", ITERATIONS, || { + counter.fetch_add(1, Ordering::Relaxed); + })); + + // Leave it signalled, so every call in the next loop is redundant. + unsafe { SetEvent(event) }; + timings.push(time_loop("set_event_already_signalled", ITERATIONS, || { + unsafe { SetEvent(event) }; + })); + + unsafe { ResetEvent(event) }; + timings.push(time_loop("set_reset_event", ITERATIONS, || unsafe { + SetEvent(event); + ResetEvent(event); + })); + + unsafe { SetEvent(event) }; + timings.push(time_loop("wait_zero_signalled", ITERATIONS, || { + unsafe { WaitForSingleObject(event, 0) }; + })); + unsafe { + ResetEvent(event); + CloseHandle(event); + } + + // The syscall the doorbell would be amortised against. Far fewer + // iterations: this one is a real kernel transition. `submit_and_wait(0)` + // asks for no completions, so it returns without blocking and measures the + // transition rather than any I/O. + let submit_nanos = ioring::Ring::new().map(|ring| { + const SUBMIT_ITERATIONS: u32 = 20_000; + let timing = time_loop("submit_io_ring_empty", SUBMIT_ITERATIONS, || { + // Both halves of the answer are checked, inside the timed region. + // Discarding them let a host where `SubmitIoRing` fails produce a + // perfectly plausible timing -- a failing call still costs a + // measurable transition -- which the report then read as the cost of + // a successful empty submission. That is the failure mode this whole + // crate exists to avoid: a number that looks like evidence and is + // not. The `submitted` count is checked too, because a call that + // succeeded while submitting entries did not measure what the label + // says it measured. + // + // The cost is a predictable branch against a syscall, which does not + // perturb the figure; leaving the check outside the loop would let + // the timing be taken before anything established it was valid. + let (hr, submitted) = ring.submit_and_wait(0); + assert!(hr >= 0, "SubmitIoRing(0) failed: {hr:#010x}"); + assert_eq!(submitted, 0, "SubmitIoRing(0) submitted entries"); + }); + timings.push(timing); + timing.nanos_per_op + }); + + Observation { + timings, + submit_nanos, + } +} + +/// Keeps the doorbell's own wake path honest: a consumer that actually parks +/// and is woken measures something the zero-timeout poll above does not. +/// +/// Reported separately because it is a two-thread measurement and therefore +/// noisier than the single-threaded loops. The number is a full **round trip** +/// -- wake the peer, park, be woken -- not a single transition, so it is an +/// upper bound on what one wakeup costs rather than the cost itself. +/// +/// # Why the handshake alternates strictly +/// +/// The obvious version -- one thread calling `SetEvent` in a loop while the +/// other calls `WaitForSingleObject` -- **deadlocks**, and did when this probe +/// was first written. An auto-reset event does not count signals: two arriving +/// before one wait collapse into one, the waiter's count never catches up, and +/// it blocks on `INFINITE` for ever. Two events used as ping and pong force +/// strict alternation, so no signal can be lost. +/// +/// Every wait is nevertheless bounded. A probe that can hang is a probe that +/// can hang a build, and the deadlock above is exactly how that happens; a +/// timeout turns it into a reported anomaly instead. +/// +/// Returns `None` if the handshake ever timed out, because a partial run's +/// average would be meaningless -- and for the same reason if `rounds` is zero, +/// which has no average at all rather than an average of nothing. +#[must_use] +pub fn measure_park_and_wake(rounds: u32) -> Option { + const WAIT_TIMEOUT_MS: u32 = 5_000; + + // An empty sample has no average, and the arithmetic below would not say + // so: no round runs, so the elapsed time is zero, and `0.0 / 0.0` is `NaN` + // wrapped in the `Some` this function documents as a meaningful number. A + // caller comparing that against a threshold gets `false` from every + // comparison and no indication why. + if rounds == 0 { + return None; + } + + // SAFETY: two auto-reset, initially-unsignalled, unnamed events. + let ping: HANDLE = unsafe { CreateEventW(std::ptr::null(), 0, 0, std::ptr::null()) }; + let pong: HANDLE = unsafe { CreateEventW(std::ptr::null(), 0, 0, std::ptr::null()) }; + assert!(!ping.is_null() && !pong.is_null(), "CreateEventW failed"); + + let (ping_addr, pong_addr) = (ping as usize, pong as usize); + let peer = std::thread::spawn(move || { + let (ping, pong) = (ping_addr as HANDLE, pong_addr as HANDLE); + for _ in 0..rounds { + // SAFETY: both handles outlive this thread, which is joined below. + let waited = unsafe { WaitForSingleObject(ping, WAIT_TIMEOUT_MS) }; + if waited != WAIT_OBJECT_0 { + return false; + } + unsafe { SetEvent(pong) }; + } + true + }); + + let mut ok = true; + let start = Instant::now(); + for _ in 0..rounds { + // SAFETY: both handles are live for the whole loop. + unsafe { SetEvent(ping) }; + if unsafe { WaitForSingleObject(pong, WAIT_TIMEOUT_MS) } != WAIT_OBJECT_0 { + ok = false; + break; + } + } + let elapsed = start.elapsed(); + + let peer_ok = peer.join().unwrap_or(false); + // SAFETY: the peer has been joined, so nothing else holds these. + unsafe { + CloseHandle(ping); + CloseHandle(pong); + } + + (ok && peer_ok).then(|| elapsed.as_nanos() as f64 / f64::from(rounds)) +} diff --git a/crates/windows-platform-probes/src/lib.rs b/crates/windows-platform-probes/src/lib.rs index dbc16f560..ed30aebcb 100644 --- a/crates/windows-platform-probes/src/lib.rs +++ b/crates/windows-platform-probes/src/lib.rs @@ -106,7 +106,9 @@ //! | [`cancel_io::cancel_against_busy_thread`] | binary only | it can block indefinitely against a thread re-entering synchronous I/O | //! | [`long_path::measure`] | binary only | whether the `longPathAware` manifest opt-in lifts `MAX_PATH` for a *relative* path -- binary only because the answer is the difference between two differently-manifested executables, which no single in-process test can observe | //! | [`topology::measure`] | asserted | that `windows-topology-sys`' parse of `GetLogicalProcessorInformationEx` agrees with `GetActiveProcessorCount`, `GetActiveProcessorGroupCount` and `GetNumaHighestNodeNumber` read independently -- asserted because the invariants hold on any machine even though every value is host-specific, and the binary prints the shape so CI doubles as a fleet survey | - +//! | [`doorbell_cost::measure`] | binary only | what `SetEvent` costs against the `SubmitIoRing` it would guard, which is what decides whether the two-layer ring needs an eventcount at all | +//! | [`doorbell_cost::measure_park_and_wake`] | asserted | that the park-and-wake handshake completes rather than deadlocking, which its first implementation did | +//! | [`request_cost::measure`] | binary only | what building an owned `OpenFile` costs against the doorbell that would carry it | #![cfg(windows)] #![forbid(unsafe_op_in_unsafe_fn)] #![warn(missing_docs)] @@ -114,6 +116,7 @@ pub mod cancel_io; pub mod completion_port; pub mod device_map; +pub mod doorbell_cost; pub mod error_mode; pub mod handle_state; pub mod ioring; @@ -121,6 +124,7 @@ pub mod long_path; pub mod long_path_report; pub mod pool_growth; pub mod report; +pub mod request_cost; pub mod topology; pub mod topology_report; pub mod worker_context; diff --git a/crates/windows-platform-probes/src/request_cost.rs b/crates/windows-platform-probes/src/request_cost.rs new file mode 100644 index 000000000..9a3a4486d --- /dev/null +++ b/crates/windows-platform-probes/src/request_cost.rs @@ -0,0 +1,250 @@ +// Copyright (c) Mike Grier. + +//! What does it cost to build a namespace request, against the queue that would +//! carry it? +//! +//! **An experiment, not a component.** These probes measure platform behaviour +//! and are not for production use. Do not call them from production code, and +//! do not lift a technique out of here. See this crate's DESIGN-NOTES.md. +//! +//! # The decision this exists to inform +//! +//! The two-layer ring's submission queue was specified to carry **POD +//! descriptors with no allocation on push**. A deferred `CreateFileW` carries a +//! path, and a path is neither fixed-size nor POD, so that requirement and the +//! namespace plane's needs cannot both hold as written. +//! +//! `windows-namespace-request-sys` already solves the hard part: an `OpenFile` +//! is an *owned, `Send`* parameter set, built on one thread and performed +//! faithfully on another. So the queue can carry a request by value and the +//! lifetime hazard disappears. What remains is a cost question about **this +//! operation type**: how does building one compare with the doorbell that would +//! carry it (~165 ns, per `probe-doorbell-cost`)? +//! +//! # What this does not measure, stated because the number invites over-reading +//! +//! **This says nothing about whether the queue is efficient.** It measures the +//! construction cost of the queue's *heaviest* payload. Two distinctions the +//! result must not be stretched across: +//! +//! - **Operation type.** A namespace open resolves a path through Win32 and +//! may duplicate a handle. A registered-buffer read -- the hot path -- does +//! neither: its descriptor is a slot index and an offset, and there the +//! queue's own mechanics are the whole per-operation cost. +//! - **Overhead against efficiency.** Throughput under contention, the ring's +//! cache behaviour, batching amortization, and backpressure under load are +//! what make a queue good or bad. A single uncontended construction time +//! measures none of them. +//! +//! The conclusion it *does* support is about **operation mix**: for an +//! open-heavy workload, effort spent shaving the doorbell would be spent on the +//! small half of the cost. +//! +//! # Handle duplication is the part that is easy to under-count +//! +//! A request that carries a handle -- a template handle for an open, or the +//! subject of a query -- must **duplicate** it, because the submitting thread +//! may close its own copy the moment it returns. `CapturedHandle::capture` does +//! that with `DuplicateHandle`, which is a kernel transition, not a memory +//! copy. So "what does a request cost" is not only an allocation question, and +//! measuring only the path would understate it. +//! +//! # Preparing a path is a Win32 call, not an allocation +//! +//! This probe was written expecting `prepare` to be an allocation and a copy. +//! It is not: it calls **`GetFullPathNameW`** to resolve the path against the +//! process working directory, because [the namespace session] settled that the +//! path is resolved at submission -- the process CWD is mutable by any thread, +//! so even perfect remoting would be racy. +//! +//! That means the measured cost is a *syscall* cost and cannot be tuned away by +//! an allocator. An inline-storage or recycling scheme would only recover the +//! allocation part, which `clone_prepared_units` bounds from below. Knowing +//! which half is which is the point of measuring both. +//! +//! [the namespace session]: ../../../design-sessions/DESIGN-SESSION-2026-08-27-pseudo-async-namespace-operations.md +//! +//! Each timing is reported per operation. Absolute values are host-specific; +//! the **ratios against the doorbell and the atomic** are the finding. + +use std::time::Instant; + +use wtf_string::Wtf16String; + +use windows_namespace_request_sys::{CapturedHandle, OpenFile, prepare}; +use windows_sys::Win32::Foundation::GENERIC_READ; +use windows_sys::Win32::Storage::FileSystem::{FILE_SHARE_READ, OPEN_EXISTING}; +use windows_sys::Win32::System::SystemInformation::GetSystemDirectoryW; + +/// Nanoseconds per operation for one timed loop. +#[derive(Debug, Clone, Copy, PartialEq)] +pub struct Timing { + /// What was timed. + pub label: &'static str, + /// Iterations executed. + pub iterations: u32, + /// Nanoseconds per iteration. + pub nanos_per_op: f64, +} + +/// Every timing taken by [`measure`]. +#[derive(Debug, Clone)] +pub struct Observation { + /// Each timed loop, in the order run. + pub timings: Vec, +} + +impl Observation { + /// Look a timing up by label. + #[must_use] + pub fn get(&self, label: &str) -> Option { + self.timings + .iter() + .find(|t| t.label == label) + .map(|t| t.nanos_per_op) + } +} + +fn time_loop(label: &'static str, iterations: u32, mut body: impl FnMut() -> T) -> Timing { + // Warm the path: the first pass pays for lazily resolved syscall stubs and + // for the allocator's first touch of a fresh size class. + for _ in 0..256 { + std::hint::black_box(body()); + } + let start = Instant::now(); + for _ in 0..iterations { + std::hint::black_box(body()); + } + let elapsed = start.elapsed(); + Timing { + label, + iterations, + nanos_per_op: elapsed.as_nanos() as f64 / f64::from(iterations), + } +} + +/// Time request construction, path preparation, and handle duplication. +/// +/// # Panics +/// +/// Panics if the fixed test paths fail to prepare, which would mean +/// `prepare` rejects an ordinary absolute path and nothing here is meaningful. +#[must_use] +pub fn measure() -> Observation { + const ITERATIONS: u32 = 100_000; + const HANDLE_ITERATIONS: u32 = 50_000; + + // Resolved, not assumed. Windows is not always on `C:` -- a valid + // installation can sit on any volume -- and hard-coding it made this probe + // panic on such a machine rather than measure it. The same path is used for + // the prepared request and the real open below, so the two stay consistent. + let system_dll = system_directory().join("kernel32.dll"); + let short = Wtf16String::from( + system_dll + .to_str() + .expect("the system directory is representable"), + ); + let long_text = format!(r"C:\{}\file.txt", vec!["directory"; 24].join("\\")); + let long = Wtf16String::from(long_text.as_str()); + + let mut timings = Vec::new(); + + // The allocation and normalization a path costs, at two lengths, because + // the common case and the worst case allocate differently. + timings.push(time_loop("prepare_short_path", ITERATIONS, || { + prepare(&short).expect("an absolute path prepares") + })); + timings.push(time_loop("prepare_long_path", ITERATIONS, || { + prepare(&long).expect("an absolute path prepares") + })); + + // A whole request, which is a prepared path plus the builder chain. This is + // what the queue would actually carry. + timings.push(time_loop("build_open_request", ITERATIONS, || { + let path = prepare(&short).expect("an absolute path prepares"); + OpenFile::new(path) + .with_desired_access(GENERIC_READ) + .with_share_mode(FILE_SHARE_READ) + .with_creation_disposition(OPEN_EXISTING) + })); + + // Cloning the prepared path alone, which is what a request-recycling scheme + // would avoid paying. + let prepared_units = prepare(&short) + .expect("an absolute path prepares") + .into_wtf16(); + timings.push(time_loop("clone_prepared_units", ITERATIONS, || { + prepared_units.clone() + })); + + // The kernel transition a captured handle costs. Measured against a handle + // this process already owns, so nothing here depends on the filesystem. + // + // Capture and close are timed SEPARATELY, and that separation is the whole + // point. `time_loop` black-boxes its closure's return value and drops it at + // the end of the statement, so a loop that captures and returns a + // `CapturedHandle` -- which owns an `OwnedHandle` -- also calls + // `CloseHandle` inside the timed region. That is two kernel transitions + // reported as one number, and the report reads that number as the cost of + // duplication alone, so it overstated it by however much a close costs. + // + // Retaining every duplicate in a pre-sized `Vec` keeps the close out of the + // capture loop, and timing the drop of that same `Vec` recovers the close as + // its own figure rather than discarding it. The `push` is a pointer bump + // into reserved capacity, which is not free but is nowhere near a syscall. + let file = std::fs::File::open(&system_dll).expect("kernel32.dll is readable"); + let borrowed = std::os::windows::io::AsHandle::as_handle(&file); + + // Warmed the same way `time_loop` warms, and for the same reason: the first + // pass pays for lazily resolved syscall stubs and the allocator's first + // touch of a fresh size class. + for _ in 0..256 { + let _ = + std::hint::black_box(CapturedHandle::capture(borrowed).expect("duplicating a handle")); + } + + let mut captured = Vec::with_capacity(HANDLE_ITERATIONS as usize); + let start = Instant::now(); + for _ in 0..HANDLE_ITERATIONS { + captured.push(CapturedHandle::capture(borrowed).expect("duplicating an owned handle")); + } + let capture_elapsed = start.elapsed(); + timings.push(Timing { + label: "capture_handle", + iterations: HANDLE_ITERATIONS, + nanos_per_op: capture_elapsed.as_nanos() as f64 / f64::from(HANDLE_ITERATIONS), + }); + + let start = Instant::now(); + drop(captured); + let close_elapsed = start.elapsed(); + timings.push(Timing { + label: "close_handle", + iterations: HANDLE_ITERATIONS, + nanos_per_op: close_elapsed.as_nanos() as f64 / f64::from(HANDLE_ITERATIONS), + }); + + Observation { timings } +} + +/// Where Windows is actually installed, rather than where it usually is. +/// +/// Falls back to the conventional path only when the system will not say, which +/// keeps the probe running on a machine that answers and keeps the failure +/// visible on one that does not. +fn system_directory() -> std::path::PathBuf { + let mut buffer = [0_u16; 260]; + // SAFETY: writes at most `buffer.len()` units into a buffer of that size. + let written = unsafe { GetSystemDirectoryW(buffer.as_mut_ptr(), buffer.len() as u32) }; + let written = written as usize; + // `>=`, not `>`. On success the count excludes the terminator, so it can + // reach at most `buffer.len() - 1`; on failure it is the required size + // *including* the terminator, so it is at least `buffer.len() + 1`. Exactly + // `buffer.len()` is therefore unreachable from either branch -- and treating + // it as a failure costs nothing while removing the need for the next reader + // to redo that analysis before trusting a possibly-unterminated buffer. + if written == 0 || written >= buffer.len() { + return std::path::PathBuf::from(r"C:\Windows\System32"); + } + std::path::PathBuf::from(String::from_utf16_lossy(&buffer[..written])) +} diff --git a/crates/windows-platform-probes/src/tests.rs b/crates/windows-platform-probes/src/tests.rs index b4fb5f734..5ba04c6d8 100644 --- a/crates/windows-platform-probes/src/tests.rs +++ b/crates/windows-platform-probes/src/tests.rs @@ -4296,3 +4296,46 @@ fn a_named_level_with_no_summary_is_not_also_called_missing() { "and still says which absent case it is: {text}" ); } + +// --- the doorbell's park-and-wake handshake --------------------------------- +// +// Its own documentation records that the first implementation DEADLOCKED: one +// thread setting an auto-reset event while the other waited, two signals +// collapsing into one, and the waiter blocking on INFINITE for ever. Nothing +// tested it, so the rewrite that fixed it could have been undone silently. +// +// Both tests are bounded by construction. A test that can hang is worse than +// the defect it guards, because it takes the whole suite with it: the handshake +// itself waits with a 5-second timeout and reports `None` rather than blocking, +// so a reintroduced deadlock surfaces here as a failed assertion within seconds +// rather than as a suite that never finishes. + +#[test] +fn a_zero_round_handshake_has_no_average_rather_than_a_meaningless_one() { + // The deterministic half of the contract, and the one a caller is most + // likely to break by "simplifying". With no rounds the elapsed time is zero + // and the average would be `0.0 / 0.0` -- NaN, wrapped in the `Some` this + // function documents as a meaningful number, against which every comparison + // a caller makes returns false with no indication why. + assert_eq!( + crate::doorbell_cost::measure_park_and_wake(0), + None, + "zero rounds has no average, and must not report one" + ); +} + +#[test] +fn a_small_handshake_completes_and_reports_a_positive_round_trip() { + // The liveness half: the two-event alternation actually runs to completion + // and produces a number. Deliberately few rounds -- this is a real + // cross-thread measurement, and the assertion is that it terminates and is + // sane, not that it is fast. A machine under load may make each round + // arbitrarily slow without making it wrong. + let average = crate::doorbell_cost::measure_park_and_wake(64) + .expect("a bounded handshake of 64 rounds must complete rather than time out"); + + assert!( + average.is_finite() && average > 0.0, + "a completed handshake must report a positive finite round trip, got {average}" + ); +} From 885b0d26244e3fc31b02f3fdba6b1a9c017a6b8a Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 08:35:40 -0400 Subject: [PATCH 02/17] docs(platform-probes): qualify the one doorbell figure that was stated bare `DOORBELL_NS_REFERENCE` is deliberately not re-baselined: it is the figure the 2026-08-30 design session recorded, and silently replacing it would leave that session citing a number that exists nowhere. Its own doc comment says so, and says the like-for-like comparison a reader wants is the two probes' outputs in the same CI job, which run under `--release` together. Three of the four places that mention it carry that qualification. The module doc did not -- it read "the doorbell that would carry it (~165 ns, per `probe-doorbell-cost`)", which states the figure as what that probe measures. It is not: on the x86_64 host in front of me `probe-doorbell-cost` reports 208.9 ns for an already-signalled `SetEvent` and 530.7 ns for a full set/reset cycle, so a reader who took the module doc at face value would find the probe contradicting it in the same log. Now qualified like the other three, and pointing at the local figure rather than implying the constant is one. --- crates/windows-platform-probes/src/request_cost.rs | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/crates/windows-platform-probes/src/request_cost.rs b/crates/windows-platform-probes/src/request_cost.rs index 9a3a4486d..d3ef423b5 100644 --- a/crates/windows-platform-probes/src/request_cost.rs +++ b/crates/windows-platform-probes/src/request_cost.rs @@ -19,7 +19,9 @@ //! faithfully on another. So the queue can carry a request by value and the //! lifetime hazard disappears. What remains is a cost question about **this //! operation type**: how does building one compare with the doorbell that would -//! carry it (~165 ns, per `probe-doorbell-cost`)? +//! carry it (~165 ns as recorded on the development machine -- run +//! `probe-doorbell-cost` on the host in front of you for a local figure, which +//! CI does in the same job)? //! //! # What this does not measure, stated because the number invites over-reading //! From fabda221354ec25636c02f8d3259432af5d28cec Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 08:48:53 -0400 Subject: [PATCH 03/17] fix(platform-probes): stop the cost probes claiming what their runs did not establish Two independent reviews of the peel found six defects, five of them the class this component keeps hitting: a statement that is true of the machine it was written on and printed as fact everywhere else. **The report drew a design conclusion that inverts on this host.** It stated, under "What it does support", that for an open-heavy workload doorbell tuning would be optimizing the small half. That is only true when the doorbell is the smaller of the two, which it was on the development machine (165 ns against a 453 ns build) and is not here: `probe-doorbell-cost` reports a ~531 ns cycle against ~210 ns to build a request, so the doorbell is the LARGE half. Both probes run in the same CI job, so the sentence was contradicted a few lines down the same log. The existing caveats covered the printed ratio and the operation-type scope; neither guarded a sentence phrased as a finding. It now states the comparison, names the figure to read from the sibling probe, and declines the verdict -- which this probe cannot reach, because it measures only one side of it. Swept into the module doc, which carried the same claim. **The machine-readable line handed a consumer the ratio the prose forbids.** The report tells a human an empty `SubmitIoRing` is not a fair denominator and that any figure derived from it is a confident wrong answer -- then emitted `"doorbell_share_of_submit"`, unqualified, under a name meaning exactly that forbidden share. Renamed to `doorbell_over_empty_submit`, so the field states its own denominator and a query looking for a share of a syscall does not find it. The accessor keeps its name and its warning; only the wire field, which no mining pass reads docs for, changes. **The short-circuit diagnosis is now measured rather than asserted.** The caution block claimed unconditionally that the empty submit was "far too cheap for a kernel transition -- almost certainly short-circuiting in user mode", written around a 79 ns development-machine reading. Here it is 216 ns against 206 ns for an already-signalled `SetEvent`, so the claim is not merely unsupported but false. It is now decided against this probe's own measured syscalls; the denominator advice, which holds either way, stays unconditional. **Two optimizations were credited with each other's savings.** The module doc said an inline-storage or recycling scheme recovers the allocation part; the report said the same pair recovers `build - clone`, which is the Win32 resolution the module doc says an allocator cannot touch. They are different schemes: recycling a resolved path pays the clone instead of the build and recovers the difference, inline storage removes the allocation and copy and recovers at most the clone. Both texts now say so. **`time_loop` includes the drop, and now says it does.** `black_box` takes the returned value and it falls at the end of the statement, so the three heap-owning timings are construct-and-destroy cycles reported as construction. Documented rather than restructured: retaining every value -- which the captured-handle loop does, because dropping one calls `CloseHandle` and that is a second kernel transition -- would hold 100_000 live allocations and measure an allocator that never reuses a block. Neither regime is the shipping one, so the honest course is naming which this is. Raised for the engineer rather than settled here. **And the probe-table rows added in the previous commit over-claimed.** They said the doorbell probe establishes cost "against the `SubmitIoRing` it would guard" and the request probe "against the doorbell that would carry it" -- the two denominators these probes specifically decline to stand behind. They now name the absolute costs and the batching arithmetic actually established. --- .../src/bin/doorbell_cost.rs | 64 +++++++++++++++---- .../src/bin/request_cost.rs | 57 +++++++++++++++-- crates/windows-platform-probes/src/lib.rs | 4 +- .../src/request_cost.rs | 46 ++++++++++--- 4 files changed, 142 insertions(+), 29 deletions(-) diff --git a/crates/windows-platform-probes/src/bin/doorbell_cost.rs b/crates/windows-platform-probes/src/bin/doorbell_cost.rs index 80d0c429d..3ed7406cf 100644 --- a/crates/windows-platform-probes/src/bin/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/bin/doorbell_cost.rs @@ -92,31 +92,63 @@ fn render(observation: &Observation, park: Option) -> String { if let Some(submit) = observation.submit_nanos { let _ = writeln!( out, - "\n CAUTION: an empty SubmitIoRing measured {submit:.0} ns, which is far too" + "\n CAUTION: an empty SubmitIoRing measured {submit:.0} ns, and that is" ); let _ = writeln!( out, - " cheap for a kernel transition -- it is almost certainly short-" + " NOT a fair denominator: it carries no work, so any 'doorbell is N%" ); let _ = writeln!( out, - " circuiting in user mode when there is nothing queued. It is" + " of a syscall' figure derived from it would be a confident wrong" ); let _ = writeln!( out, - " therefore NOT a fair denominator, and any 'doorbell is N% of a" + " answer. The honest denominator is the cost of the real work a" ); let _ = writeln!( out, - " syscall' figure derived from it would be a confident wrong answer." + " submission carries, which this probe does not measure." ); - let _ = writeln!( - out, - " The honest denominator is the cost of the real work a submission" - ); - let _ = writeln!(out, " carries, which this probe does not measure."); - } + // Whether it short-circuits is DECIDED HERE, not asserted. This text + // used to state, unconditionally, that the empty submit was "far too + // cheap for a kernel transition -- almost certainly short-circuiting in + // user mode". That was written around a 79 ns reading on the + // development machine and is contradicted by any host where the empty + // submit lands among this probe's own syscalls: measured here at + // 216 ns against 205 ns for an already-signalled `SetEvent` and 280 ns + // for a satisfied wait, the claim is not merely unsupported, it is + // false. The advice above holds either way, which is why it is + // unconditional and this is not. + let syscalls: Vec = ["set_event_already_signalled", "wait_zero_signalled"] + .into_iter() + .filter_map(|label| observation.get(label)) + .collect(); + if let Some(cheapest) = syscalls.iter().copied().reduce(f64::min) { + if submit < cheapest / 2.0 { + let _ = writeln!( + out, + " It is also under half this probe's cheapest measured syscall" + ); + let _ = writeln!( + out, + " ({cheapest:.0} ns), so on this host it is very likely short-circuiting" + ); + let _ = writeln!(out, " in user mode when there is nothing queued."); + } else { + let _ = writeln!( + out, + " On this host it is the same order as this probe's own syscalls" + ); + let _ = writeln!( + out, + " ({cheapest:.0} ns and up), so nothing here says it short-circuits --" + ); + let _ = writeln!(out, " it is simply an empty one."); + } + } + } // What can be said without a denominator: how much batching it takes for // the doorbell to disappear, which is the lever the design actually has. if let Some(doorbell) = observation.get("set_reset_event") @@ -168,13 +200,21 @@ fn render(observation: &Observation, park: Option) -> String { .unwrap_or(f64::NAN); let cycle = observation.get("set_reset_event").unwrap_or(f64::NAN); let wait0 = observation.get("wait_zero_signalled").unwrap_or(f64::NAN); + // `doorbell_over_empty_submit`, not `doorbell_share_of_submit`. The prose + // above tells a human that an empty submit is not a fair denominator and + // that any figure derived from it is a confident wrong answer -- and this + // line then handed a machine exactly that figure under a name meaning "the + // doorbell's share of a submit", with no caveat a mining pass could read. + // The name now states its own denominator, so a query that wants the ratio + // asks for it knowingly, and one that wants a real share of a syscall does + // not find this field by looking for that. let _ = writeln!( out, concat!( r#"{{"reason":"x-probe-doorbell-cost","arch":"{}","atomic_ns":{:.1},"#, r#""set_event_already_signalled_ns":{:.1},"set_reset_event_ns":{:.1},"#, r#""wait_zero_signalled_ns":{:.1},"park_and_wake_round_trip_ns":{},"#, - r#""submit_io_ring_empty_ns":{},"doorbell_share_of_submit":{}}}"# + r#""submit_io_ring_empty_ns":{},"doorbell_over_empty_submit":{}}}"# ), std::env::consts::ARCH, atomic, diff --git a/crates/windows-platform-probes/src/bin/request_cost.rs b/crates/windows-platform-probes/src/bin/request_cost.rs index 1c65ceb1d..b40535fff 100644 --- a/crates/windows-platform-probes/src/bin/request_cost.rs +++ b/crates/windows-platform-probes/src/bin/request_cost.rs @@ -144,18 +144,47 @@ fn render() -> String { ); let _ = writeln!(out, " time measures none of them."); let _ = writeln!(out); + // States the COMPARISON and refuses the verdict, because this probe + // does not measure a doorbell. + // + // This read "What it does support: for an open-heavy workload, doorbell + // tuning would be optimizing the small half" -- a design conclusion + // whose truth depends entirely on which of the two is larger, decided + // against a constant measured on another machine. It INVERTS here: + // `probe-doorbell-cost` reports a ~531 ns cycle on this host against + // ~210 ns to build a request, so the doorbell is the large half and + // tuning it would optimize the large one. Both probes run in the same + // CI job, so the sentence was contradicted a few lines further down the + // same log. + // + // The caveats above cover the printed ratio and the operation-type + // scope; neither guarded this, because it was phrased as what the run + // supports rather than as a ratio. let _ = writeln!( out, - " What it does support: for an open-heavy workload, doorbell tuning" + " WHICH HALF IS LARGER IS NOT ESTABLISHED HERE. Whether doorbell" ); let _ = writeln!( out, - " would be optimizing the small half. That is a finding about" + " tuning would optimize the large or the small half depends on the" ); let _ = writeln!( out, - " OPERATION MIX, and it says nothing about the read path." + " doorbell measured ON THIS HOST, which this probe does not measure:" ); + let _ = writeln!( + out, + " read probe-doorbell-cost's set_reset_event from the same run and" + ); + let _ = writeln!( + out, + " compare it against the {build:.0} ns above. The comparison can invert" + ); + let _ = writeln!( + out, + " between hosts, so a conclusion about OPERATION MIX belongs to a" + ); + let _ = writeln!(out, " reader holding both figures from one machine."); } if let Some(capture) = capture { @@ -239,16 +268,32 @@ fn render() -> String { ); let _ = writeln!( out, - " Cloning already-prepared units is {clone:.0} ns, which bounds what an" + " Two different schemes recover two different things, and this said" ); let _ = writeln!( out, - " inline-storage or recycling scheme could recover at {:.0} ns per request", + " one number for both. RECYCLING a resolved path pays {clone:.0} ns instead" + ); + let _ = writeln!( + out, + " of {build:.0} ns, so it recovers {:.0} ns -- but that saving is the Win32", build - clone ); let _ = writeln!( out, - " AT MOST -- and only for a caller that can reuse a resolved path." + " resolution, not an allocation, and only a caller that can reuse a" + ); + let _ = writeln!( + out, + " resolved path gets it. INLINE STORAGE removes the allocation and" + ); + let _ = writeln!( + out, + " copy instead, which is what the {clone:.0} ns clone measures, so it" + ); + let _ = writeln!( + out, + " recovers at most that and cannot touch the resolution at all." ); let _ = writeln!( out, diff --git a/crates/windows-platform-probes/src/lib.rs b/crates/windows-platform-probes/src/lib.rs index ed30aebcb..12a62bd8b 100644 --- a/crates/windows-platform-probes/src/lib.rs +++ b/crates/windows-platform-probes/src/lib.rs @@ -106,9 +106,9 @@ //! | [`cancel_io::cancel_against_busy_thread`] | binary only | it can block indefinitely against a thread re-entering synchronous I/O | //! | [`long_path::measure`] | binary only | whether the `longPathAware` manifest opt-in lifts `MAX_PATH` for a *relative* path -- binary only because the answer is the difference between two differently-manifested executables, which no single in-process test can observe | //! | [`topology::measure`] | asserted | that `windows-topology-sys`' parse of `GetLogicalProcessorInformationEx` agrees with `GetActiveProcessorCount`, `GetActiveProcessorGroupCount` and `GetNumaHighestNodeNumber` read independently -- asserted because the invariants hold on any machine even though every value is host-specific, and the binary prints the shape so CI doubles as a fleet survey | -//! | [`doorbell_cost::measure`] | binary only | what `SetEvent` costs against the `SubmitIoRing` it would guard, which is what decides whether the two-layer ring needs an eventcount at all | +//! | [`doorbell_cost::measure`] | binary only | the absolute cost of `SetEvent`, a set/reset cycle and a satisfied wait against an uncontended atomic, and how much batching drives the doorbell below the push it accompanies | //! | [`doorbell_cost::measure_park_and_wake`] | asserted | that the park-and-wake handshake completes rather than deadlocking, which its first implementation did | -//! | [`request_cost::measure`] | binary only | what building an owned `OpenFile` costs against the doorbell that would carry it | +//! | [`request_cost::measure`] | binary only | the absolute cost of preparing a path, building an owned `OpenFile`, and duplicating a handle | #![cfg(windows)] #![forbid(unsafe_op_in_unsafe_fn)] #![warn(missing_docs)] diff --git a/crates/windows-platform-probes/src/request_cost.rs b/crates/windows-platform-probes/src/request_cost.rs index d3ef423b5..4bb1d9edb 100644 --- a/crates/windows-platform-probes/src/request_cost.rs +++ b/crates/windows-platform-probes/src/request_cost.rs @@ -38,10 +38,14 @@ //! what make a queue good or bad. A single uncontended construction time //! measures none of them. //! -//! The conclusion it *does* support is about **operation mix**: for an -//! open-heavy workload, effort spent shaving the doorbell would be spent on the -//! small half of the cost. -//! +//! What it supports is a **comparison**, not a verdict: build cost against the +//! doorbell that would carry it. Which of the two is the larger half is a +//! question about one host, and this probe measures only one side of it -- +//! read `probe-doorbell-cost`'s `set_reset_event` from the same run for the +//! other. The comparison inverts between machines: the development machine had +//! the doorbell at roughly a third of a build, and an x86_64 host measured +//! during review had it at roughly two and a half times one. A sentence naming +//! a small half would therefore be wrong on one of them.//! //! # Handle duplication is the part that is easy to under-count //! //! A request that carries a handle -- a template handle for an open, or the @@ -59,11 +63,14 @@ //! path is resolved at submission -- the process CWD is mutable by any thread, //! so even perfect remoting would be racy. //! -//! That means the measured cost is a *syscall* cost and cannot be tuned away by -//! an allocator. An inline-storage or recycling scheme would only recover the -//! allocation part, which `clone_prepared_units` bounds from below. Knowing -//! which half is which is the point of measuring both. -//! +//! That means the measured cost is largely a *syscall* cost, and the two +//! schemes that might reduce it recover different halves. **Inline storage** +//! removes the allocation and copy, which is what `clone_prepared_units` +//! measures, and cannot touch the resolution at all. **Recycling** a resolved +//! path skips the resolution, paying the clone in place of the whole build, so +//! it recovers the difference between them. Naming one figure for both -- as +//! this did -- credits an allocator with the syscall it cannot remove. Knowing +//! which half is which is the point of measuring both.//! //! [the namespace session]: ../../../design-sessions/DESIGN-SESSION-2026-08-27-pseudo-async-namespace-operations.md //! //! Each timing is reported per operation. Absolute values are host-specific; @@ -107,6 +114,27 @@ impl Observation { } } +/// Time `body`, including the drop of whatever it returns. +/// +/// **The drop is inside the timed region, and for the heap-owning values below +/// that is a construct-and-destroy cycle rather than a construction cost.** +/// `black_box` takes the value and it falls at the end of the statement, so +/// `prepare_*`, `build_open_request` and `clone_prepared_units` each include +/// freeing the `Wtf16String` they built. On a clone measured near 50 ns a free +/// is a visible share of the figure. +/// +/// It is reported this way rather than restructured, and the reason is that the +/// obvious alternative is not more truthful. Retaining each value -- what the +/// captured-handle loop below does, for a reason that does not apply here -- +/// would hold 100_000 live allocations, which measures an allocator that never +/// reuses a block instead of one that does. A queue holds a bounded number of +/// requests, so neither regime is the shipping one, and the honest course is to +/// say which one this is. +/// +/// The captured-handle loop is different in kind and is genuinely restructured: +/// dropping a `CapturedHandle` calls `CloseHandle`, so leaving it in the timed +/// region reports two kernel transitions as one number. A free is not a +/// syscall. fn time_loop(label: &'static str, iterations: u32, mut body: impl FnMut() -> T) -> Timing { // Warm the path: the first pass pays for lazily resolved syscall stubs and // for the allocator's first touch of a fresh size class. From ec4e2b537085dd4306cde0b4c5b2fa724e1b3726 Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 10:38:43 -0400 Subject: [PATCH 04/17] fix(platform-probes): correct the doorbell recommendation, which reversed its own arithmetic A second review round found seven defects, and the fixes from the previous round are where several of them were -- which is the pattern this component keeps producing and the reason the round was run before merging rather than after. **The doorbell probe recommended the opposite of what it measured.** Its closing advice was that "the skip-when-busy rule is a refinement, not a prerequisite ... a first implementation can always-signal and stay honest", drawn from a table that divides ONE doorbell across a batch. That is the cost of signalling once per drained batch -- coalescing on the empty-to-non-empty edge. A producer that signals on every push amortizes nothing and pays a redundant `SetEvent` per operation, which this probe measures directly at 208 ns against a 2.1 ns push: 100x, at every batch size. So the arithmetic supports the reverse of the sentence. It now separates the two: coalescing is the prerequisite, the parked-consumer check is the refinement, and the always-signal cost is printed rather than assumed away. This was the probe's headline finding and was quoted as such in the pull request description. **The round trip was called what a wake costs.** `measure_park_and_wake` documents its number as "an upper bound on what one wakeup costs rather than the cost itself" -- it is two handoffs -- while the report said it "is what is paid when the consumer genuinely sleeps". The report now says what the function says. **The short-circuit diagnosis survived in two places the previous fix missed.** That fix made the binary decide per host; the module doc and the accessor doc kept asserting the development machine's reading, and the accessor used it as the *reason* the ratio is meaningless ("a denominator that is not a syscall") -- a reason that is false on a host where the empty submit sits among the real syscalls. Both now rest the argument on *carries no work*, which holds everywhere. **`GetFullPathNameW` was called a syscall.** `windows-namespace-request-sys` documents it as lexical -- resolving `.` and `..` "without touching the filesystem" -- so attributing the measured remainder to a kernel transition contradicts the owning crate and names a mechanism a timing loop cannot establish. The conclusion that mattered survives unchanged: whatever that work is, an allocator cannot remove it. **"Comparable" was concluded from a test for order.** The branch fires whenever capture <= build, which is every ratio from 0.99 to 0.01, and reported all of them as "comparable, and neither dominates". It now prints the ratio and leaves the threshold to a reader who has one. **The construct-and-destroy cycles now say so where a consumer reads them.** The previous round documented in `time_loop` that the drop is inside the timed region, and left the report saying "building ... costs" and the NDJSON emitting `build_open_request_ns`. Documenting a caveat in source a miner never reads is not disclosure: the wire fields are now `*_cycle_ns` and the table says which rows include the drop. And two doc lines carried a stray `//!` glued to the end of a sentence, from splices in the previous commit, which rustdoc rendered as literal text. --- .../src/bin/doorbell_cost.rs | 61 ++++++++++++++++--- .../src/bin/request_cost.rs | 54 +++++++++++++--- .../src/doorbell_cost.rs | 35 ++++++++--- .../src/request_cost.rs | 24 +++++--- 4 files changed, 139 insertions(+), 35 deletions(-) diff --git a/crates/windows-platform-probes/src/bin/doorbell_cost.rs b/crates/windows-platform-probes/src/bin/doorbell_cost.rs index 3ed7406cf..37387ff4d 100644 --- a/crates/windows-platform-probes/src/bin/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/bin/doorbell_cost.rs @@ -77,14 +77,21 @@ fn render(observation: &Observation, park: Option) -> String { if let Some(park) = park { let _ = writeln!( out, - " an actual park-and-wake round trip costs {:.0}x that again ({:.0} ns),", + " a full park-and-wake round trip costs {:.0}x that again ({:.0} ns),", park / doorbell, park ); + // "an upper bound", matching what `measure_park_and_wake` documents. + // This said "which is what is paid when the consumer genuinely + // sleeps", while the function producing the number says it is a + // round trip -- wake the peer, park, be woken -- and therefore an + // upper bound on one wakeup rather than the cost itself. The real + // doorbell path pays one handoff; this measures two. let _ = writeln!( out, - " which is what is paid when the consumer genuinely sleeps." + " which bounds ONE wakeup from above: it is two handoffs, and the" ); + let _ = writeln!(out, " doorbell path pays one."); } } @@ -174,26 +181,64 @@ fn render(observation: &Observation, park: Option) -> String { " so at a batch of about {break_even}, the doorbell costs less per" ); let _ = writeln!(out, " operation than the atomic push it accompanies."); + + // What the arithmetic above does NOT support, spelled out because the + // conclusion drawn from it used to be its opposite. + // + // Every figure above divides ONE doorbell across a batch, which is the + // cost of signalling once per drained batch -- coalescing on the + // empty-to-non-empty edge. A producer that signals on every push pays a + // redundant `SetEvent` each time and amortizes nothing, which is the + // `set_event_already_signalled` row this probe measures precisely + // because that is the always-signal cost. + // + // This block used to end "the skip-when-busy rule is a refinement, not a + // prerequisite ... a first implementation can always-signal and stay + // honest", which reverses its own arithmetic: batching amortizes a + // doorbell only for a producer that does not ring one per push. + if let Some(redundant) = observation.get("set_event_already_signalled") { + let _ = writeln!( + out, + "\n That is the COALESCED cost -- one signal per drained batch. A" + ); + let _ = writeln!( + out, + " producer that signals on every push amortizes nothing and pays a" + ); + let _ = writeln!( + out, + " redundant SetEvent per operation: {redundant:.0} ns, or {:.0}x the push,", + redundant / atomic + ); + let _ = writeln!(out, " at every batch size."); + } } let _ = writeln!( out, - "\n => The skip-when-busy rule is a refinement, not a prerequisite." + "\n => Coalescing is the prerequisite; the parked-consumer check is the" ); let _ = writeln!( out, - " Batching alone drives the doorbell below the cost of the push," + " refinement. Signalling once per empty-to-non-empty edge is what" ); let _ = writeln!( out, - " so a first implementation can always-signal and stay honest." + " drives the doorbell below the push, and it needs no eventcount --" ); let _ = writeln!( out, - " Adopt the eventcount when a measurement against real work" + " only the queue's own emptiness. Tracking whether a consumer is" ); - let _ = writeln!(out, " justifies its lost-wakeup risk -- not before."); - + let _ = writeln!( + out, + " actually parked is a further saving on top of that, and it is the" + ); + let _ = writeln!( + out, + " part carrying the lost-wakeup risk, so it can wait for a" + ); + let _ = writeln!(out, " measurement against real work."); let atomic = observation.get("atomic_fetch_add").unwrap_or(f64::NAN); let already = observation .get("set_event_already_signalled") diff --git a/crates/windows-platform-probes/src/bin/request_cost.rs b/crates/windows-platform-probes/src/bin/request_cost.rs index b40535fff..1db85a23e 100644 --- a/crates/windows-platform-probes/src/bin/request_cost.rs +++ b/crates/windows-platform-probes/src/bin/request_cost.rs @@ -57,6 +57,17 @@ fn render() -> String { "{:<26} {:>10} {:>14} {:>16}", "operation", "ns/op", "x an atomic", "x a doorbell" ); + // Says what the first four rows include, because their names do not. Each + // is a construct-and-DESTROY cycle: `time_loop` drops the value it is + // handed at the end of the timed statement, so the free is inside the + // figure. `capture_handle` and `close_handle` are the exception and are + // timed apart, because dropping a `CapturedHandle` calls `CloseHandle` and + // that is a second kernel transition rather than a free. + let _ = writeln!( + out, + " (the first four are construct-and-drop cycles; capture and close are\n \ + timed separately)" + ); for timing in &observation.timings { let _ = writeln!( out, @@ -231,12 +242,23 @@ fn render() -> String { ); let _ = writeln!(out, " half."); } else { + // The ratio without a verdict. This branch fires on `capture <= + // build`, which is every ratio from 0.99 down to 0.01, and it + // said "the two are comparable and neither dominates" for all + // of them -- a claim about closeness drawn from a test for + // order. Whether two figures are comparable needs a range, and + // this probe was given one only by accident of which arm it + // landed in. let _ = writeln!( out, - " It is {:.2}x the pathed request, so the two are comparable and", + " It is {:.2}x the pathed request. Which of the two dominates, if", capture / build ); - let _ = writeln!(out, " neither dominates."); + let _ = writeln!( + out, + " either does, is for a reader with a threshold in mind; this run" + ); + let _ = writeln!(out, " establishes only the two costs and their ratio."); } } } @@ -250,21 +272,37 @@ fn render() -> String { out, "\n WHERE THE TIME ACTUALLY GOES, and it is not the allocator:" ); + // "lexical path resolution", not "a syscall". `windows-namespace- + // request-sys` documents `GetFullPathNameW` as lexical -- "`.` and `..` + // are resolved without touching the filesystem" -- so it normalizes in + // user mode against the CWD rather than making a kernel transition. + // This said "most of the cost above is a syscall that no allocation + // scheme can remove", which contradicts the owning crate and names a + // mechanism a timing loop cannot establish anyway. The conclusion that + // matters survives: whatever it is, it is not allocation. let _ = writeln!( out, " `prepare` calls GetFullPathNameW to resolve the path against the" ); let _ = writeln!( out, - " process working directory -- a Win32 call, because the CWD is mutable" + " process working directory, because the CWD is mutable by any thread" + ); + let _ = writeln!( + out, + " and resolving later would be racy. That is lexical normalization," + ); + let _ = writeln!( + out, + " not a filesystem touch -- and not an allocation either, so most of" ); let _ = writeln!( out, - " by any thread and resolving later would be racy. So most of the cost" + " the cost above is work no allocation scheme can remove. Whether it" ); let _ = writeln!( out, - " above is a syscall that no allocation scheme can remove." + " enters the kernel is not something this run measured." ); let _ = writeln!( out, @@ -309,9 +347,9 @@ fn render() -> String { let _ = writeln!( out, concat!( - r#"{{"reason":"x-probe-request-cost","arch":"{}","prepare_short_ns":{},"#, - r#""prepare_long_ns":{},"build_open_request_ns":{},"#, - r#""clone_prepared_units_ns":{},"capture_handle_ns":{},"#, + r#"{{"reason":"x-probe-request-cost","arch":"{}","prepare_short_cycle_ns":{},"#, + r#""prepare_long_cycle_ns":{},"build_open_request_cycle_ns":{},"#, + r#""clone_prepared_units_cycle_ns":{},"capture_handle_ns":{},"#, r#""close_handle_ns":{}}}"# ), std::env::consts::ARCH, diff --git a/crates/windows-platform-probes/src/doorbell_cost.rs b/crates/windows-platform-probes/src/doorbell_cost.rs index 5d0ed95c5..a282ca0dd 100644 --- a/crates/windows-platform-probes/src/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/doorbell_cost.rs @@ -46,12 +46,19 @@ //! //! This probe was written expecting to divide the doorbell cost by //! `submit_io_ring_empty` and read off "the doorbell is N% of a syscall". **Do -//! not do that.** Measured on the development machine, an empty `SubmitIoRing` -//! came in at ~79 ns -- far too cheap for a kernel transition, so it is almost -//! certainly short-circuiting in user mode when there is nothing queued. The -//! resulting "doorbell is 210% of a syscall" would have been a confident wrong -//! answer built on a denominator that never entered the kernel. +//! not do that.** An empty submission carries no work, so whatever it costs is +//! not the denominator that question needs, and "the doorbell is 210% of a +//! syscall" would be a confident wrong answer whatever the number turned out +//! to be. //! +//! Whether it even reaches the kernel is host-dependent and the binary decides +//! it per run rather than asserting it. On the development machine it came in +//! at ~79 ns, far below that machine's own syscalls, which reads as +//! short-circuiting in user mode when there is nothing queued; on an x86_64 +//! host measured during review it was 216 ns, sitting among that host's 206 ns +//! `SetEvent` and 280 ns satisfied wait, where nothing supports the claim. The +//! argument above needs neither reading, which is why it is stated over the +//! work carried rather than over the transition. //! The honest denominator is the cost of the real work a submission carries, //! which this probe deliberately does not measure -- so it reports the absolute //! costs and the *batching* arithmetic instead, and leaves the ratio alone. @@ -101,11 +108,19 @@ impl Observation { /// One doorbell cycle as a fraction of one **empty** `SubmitIoRing`. /// /// **This is not the number the design turns on, and it should not be read - /// as one.** An empty submit does not appear to enter the kernel (see the - /// module documentation), so this ratio has a denominator that is not a - /// syscall. It is exposed because the raw fact is worth recording across - /// hosts -- a machine where the empty submit is *expensive* would itself be - /// a finding -- not because dividing by it answers anything. + /// as one.** An empty submit carries no work, so this ratio has a + /// denominator that measures nothing the design cares about. It is exposed + /// because the raw fact is worth recording across hosts -- a machine where + /// the empty submit is *expensive* would itself be a finding -- not because + /// dividing by it answers anything. + /// + /// The argument rests on *carries no work*, which holds everywhere, and no + /// longer on *does not enter the kernel*, which does not. That read "an + /// empty submit does not appear to enter the kernel, so this ratio has a + /// denominator that is not a syscall" -- a development-machine reading + /// (~79 ns) stated as a general fact. The binary decides it per host and + /// on an x86_64 machine measured during review printed the opposite, the + /// empty submit landing at 216 ns among that probe's own 206 ns syscalls. #[must_use] pub fn doorbell_share_of_submit(&self) -> Option { let doorbell = self.get("set_reset_event")?; diff --git a/crates/windows-platform-probes/src/request_cost.rs b/crates/windows-platform-probes/src/request_cost.rs index 4bb1d9edb..aff5334c2 100644 --- a/crates/windows-platform-probes/src/request_cost.rs +++ b/crates/windows-platform-probes/src/request_cost.rs @@ -45,7 +45,7 @@ //! other. The comparison inverts between machines: the development machine had //! the doorbell at roughly a third of a build, and an x86_64 host measured //! during review had it at roughly two and a half times one. A sentence naming -//! a small half would therefore be wrong on one of them.//! +//! a small half would therefore be wrong on one of them. //! # Handle duplication is the part that is easy to under-count //! //! A request that carries a handle -- a template handle for an open, or the @@ -63,14 +63,20 @@ //! path is resolved at submission -- the process CWD is mutable by any thread, //! so even perfect remoting would be racy. //! -//! That means the measured cost is largely a *syscall* cost, and the two -//! schemes that might reduce it recover different halves. **Inline storage** -//! removes the allocation and copy, which is what `clone_prepared_units` -//! measures, and cannot touch the resolution at all. **Recycling** a resolved -//! path skips the resolution, paying the clone in place of the whole build, so -//! it recovers the difference between them. Naming one figure for both -- as -//! this did -- credits an allocator with the syscall it cannot remove. Knowing -//! which half is which is the point of measuring both.//! +//! That work is **lexical**: `windows-namespace-request-sys` documents the call +//! as resolving `.` and `..` "without touching the filesystem". So the measured +//! remainder is path normalization, not allocation -- and calling it a *syscall +//! cost*, as this once did, both contradicts the owning crate and names a +//! mechanism a timing loop cannot establish. What survives is the part that +//! matters: an allocator cannot remove it. +//! +//! The two schemes that might reduce it recover different halves. **Inline +//! storage** removes the allocation and copy, which is what +//! `clone_prepared_units` measures, and cannot touch the resolution at all. +//! **Recycling** a resolved path skips the resolution, paying the clone in +//! place of the whole build, so it recovers the difference between them. Naming +//! one figure for both -- as this did -- credits an allocator with work it +//! cannot remove. Knowing which half is which is the point of measuring both. //! [the namespace session]: ../../../design-sessions/DESIGN-SESSION-2026-08-27-pseudo-async-namespace-operations.md //! //! Each timing is reported per operation. Absolute values are host-specific; From 35c49190a310c2b951a08fdd7b3a74faf4c3fa46 Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 12:13:44 -0400 Subject: [PATCH 05/17] fix(platform-probes): name the platform on every figure, and stop naming a mechanism Two corrections from review, both about claiming more than a run established. Name the platform. The reference constants and every figure derived from them said "the development machine" -- a label only its author can resolve -- and were then read as though they described machines in general. They were measured on a Snapdragon X2 (ARM64). That matters because the two architectures do not merely differ in magnitude, they differ in sign: the doorbell cycle is 164.9 ns on ARM64 against ~531 ns on the x86_64 host measured during review, so the "which half is larger" comparison inverts, and the empty `SubmitIoRing` sits below that machine's syscalls on one and among them on the other. Two observations across two architectures is exactly the sample size from which no universal follows. Both probes already emitted an `arch` field, so only the prose was anonymous. Stop naming a mechanism. A previous commit replaced "a syscall cost" with "lexical" for `GetFullPathNameW`; the replacement is wrong in the same way the original was. `GetFullPathNameW` resolves against the process current directory, and for a drive-relative path against the per-drive current directory in the `=C:` environment variables -- process state, not string work. The reports now state the cost, say it touches no filesystem and is not an allocation, and decline to say whether it enters the kernel, which is the part the timing loop actually established. Queues M2.6 for the layer that owns the answer: `windows-namespace-request-sys`'s own doc carries the same imprecision, and the question of whether a genuinely lexical canonicalizer (`PathCchCanonicalizeEx`) should replace the call belongs there. The expected answer is no -- resolving against the CWD at submission is the property the namespace design buys -- but it should be recorded rather than re-derived. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- crates/windows-platform-probes/CHECKLIST.md | 32 +++++++++ .../src/bin/doorbell_cost.rs | 3 +- .../src/bin/request_cost.rs | 66 ++++++++++++------- .../src/doorbell_cost.rs | 9 +-- .../src/request_cost.rs | 31 +++++---- 5 files changed, 100 insertions(+), 41 deletions(-) diff --git a/crates/windows-platform-probes/CHECKLIST.md b/crates/windows-platform-probes/CHECKLIST.md index 3efef01fd..216014a09 100644 --- a/crates/windows-platform-probes/CHECKLIST.md +++ b/crates/windows-platform-probes/CHECKLIST.md @@ -137,3 +137,35 @@ speculative list to extend by imagination -- a fourth is added when a fourth con than noise: across two rounds one reader raised this twice while two others cleared it, one of them explicitly after being pointed at the question. Nothing in the suite decides it either way, which is itself the argument for the oracle. + +- [ ] **M2.6** -- Say precisely what `GetFullPathNameW` does, in the crate that owns it, and decide + whether it is still the call `prepare` wants. Two successive descriptions in the cost probe were + each wrong in the same direction: *a syscall cost*, which a timing loop cannot establish, and then + *lexical*, which it also is not. The probe now states the cost and declines the mechanism, which is + honest but leaves the question open one layer down. + + [../windows-namespace-request-sys/src/full_path.rs](../windows-namespace-request-sys/src/full_path.rs) + carries the same imprecision, and is the crate that owns the answer: its module doc says "This call + is **lexical**. It resolves relative components and `.`/`..` against the process current + directory". Those two sentences disagree -- consulting the current directory is process state, and + for a drive-relative path (`C:foo`) it also reads the per-drive current directory held in the + `=C:` environment variables. "Touches no filesystem" is the claim that holds; "lexical" is not. + + **The mono-repo rule says fix the layer, so the correction belongs in + `windows-namespace-request-sys`, not in the probe that consumes it.** It is queued rather than + taken because that crate is outside this peel and is release-managed, so a docs change there is its + own commit with its own scope. + + The decision half is the part worth an engineer's attention rather than a sweep. A genuinely + lexical canonicalizer exists -- `PathCchCanonicalizeEx`, or `PathAllocCanonicalize` -- and would be + cheaper, with no process state read at all. **It is very likely the wrong call anyway**, because + resolving against the current directory *at submission* is the property the namespace design is + buying: the CWD is shared mutable state, so a relative path means something different depending on + when it is resolved, and pinning that on the submitting thread is the whole point. Record that + conclusion explicitly, with the alternative named, so the next reader does not re-derive it -- and + if it is wrong, the cheaper call is sitting there. + + Also worth settling while the question is open: whether `GetFullPathNameW` can enter the kernel at + all on any path this crate takes. The probe measured ~212 ns for a build on x86_64 and declines to + say what that is made of; the owning crate could say, and a reader of either would then stop + guessing. diff --git a/crates/windows-platform-probes/src/bin/doorbell_cost.rs b/crates/windows-platform-probes/src/bin/doorbell_cost.rs index 37387ff4d..8b617ceb4 100644 --- a/crates/windows-platform-probes/src/bin/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/bin/doorbell_cost.rs @@ -122,7 +122,8 @@ fn render(observation: &Observation, park: Option) -> String { // used to state, unconditionally, that the empty submit was "far too // cheap for a kernel transition -- almost certainly short-circuiting in // user mode". That was written around a 79 ns reading on the - // development machine and is contradicted by any host where the empty + // Snapdragon X2 (ARM64) development machine and is contradicted by any + // host where the empty // submit lands among this probe's own syscalls: measured here at // 216 ns against 205 ns for an already-signalled `SetEvent` and 280 ns // for a satisfied wait, the claim is not merely unsupported, it is diff --git a/crates/windows-platform-probes/src/bin/request_cost.rs b/crates/windows-platform-probes/src/bin/request_cost.rs index 1db85a23e..d696f1a10 100644 --- a/crates/windows-platform-probes/src/bin/request_cost.rs +++ b/crates/windows-platform-probes/src/bin/request_cost.rs @@ -14,9 +14,20 @@ use std::fmt::Write as _; use windows_platform_probes::report::{Stdout, emit}; use windows_platform_probes::request_cost::measure; -/// Measured by `probe-doorbell-cost` on the development machine, and recorded in -/// [the 2026-08-30 design session]. Restated here only to render a ratio; the -/// authoritative number is whatever that probe prints on the host this runs on. +/// Measured by `probe-doorbell-cost` on a **Snapdragon X2 (ARM64)** machine, +/// and recorded in [the 2026-08-30 design session]. Restated here only to +/// render a ratio; the authoritative number is whatever that probe prints on +/// the host this runs on. +/// +/// **The platform is named because a nanosecond figure without one is not a +/// measurement, it is an anecdote.** These constants said "the development +/// machine", which is a label only its author can resolve, and everything +/// derived from them was then read as though it described machines in general. +/// It does not: an x86_64 host measured during review put the doorbell cycle at +/// ~531 ns against ~208 ns for a redundant `SetEvent`, where the ARM64 figures +/// here are 164.9 and 7.2. Two observations, two architectures, and the +/// conclusions drawn from them differ in sign -- which is the whole argument +/// against generalising from either. /// /// **The build profile behind these is not recorded**, which is why the report /// below calls the ratios indicative rather than quoting them as results. They @@ -94,9 +105,10 @@ fn render() -> String { // The ratio names its own reference, because the two numbers do not // come from the same machine. `build` was measured on this host just // now; the doorbell figure is a constant captured once on the - // development machine. This probe now runs on hosted CI runners, which - // are a heterogeneous fleet, so a ratio printed as though both halves - // were local can be wrong even when the measurement is sound. + // Snapdragon X2 (ARM64) development machine. This probe now runs on + // hosted CI runners, which are a heterogeneous fleet, so a ratio printed + // as though both halves were local can be wrong even when the + // measurement is sound. let _ = writeln!( out, " building a pathed request costs {build:.0} ns, which is {:.1}x one", @@ -104,7 +116,7 @@ fn render() -> String { ); let _ = writeln!( out, - " doorbell AS MEASURED ON THE DEVELOPMENT MACHINE ({DOORBELL_NS_REFERENCE:.1} ns)," + " doorbell AS MEASURED ON THE ARM64 DEVELOPMENT MACHINE ({DOORBELL_NS_REFERENCE:.1} ns)," ); let _ = writeln!( out, @@ -161,10 +173,11 @@ fn render() -> String { // This read "What it does support: for an open-heavy workload, doorbell // tuning would be optimizing the small half" -- a design conclusion // whose truth depends entirely on which of the two is larger, decided - // against a constant measured on another machine. It INVERTS here: - // `probe-doorbell-cost` reports a ~531 ns cycle on this host against - // ~210 ns to build a request, so the doorbell is the large half and - // tuning it would optimize the large one. Both probes run in the same + // against a constant measured on the Snapdragon X2 (ARM64) development + // machine. It INVERTS on the x86_64 host measured during review, where + // `probe-doorbell-cost` reported a ~531 ns cycle against ~210 ns to + // build a request, so the doorbell is the large half there and tuning + // it would optimize the large one. Both probes run in the same // CI job, so the sentence was contradicted a few lines further down the // same log. // @@ -272,14 +285,21 @@ fn render() -> String { out, "\n WHERE THE TIME ACTUALLY GOES, and it is not the allocator:" ); - // "lexical path resolution", not "a syscall". `windows-namespace- - // request-sys` documents `GetFullPathNameW` as lexical -- "`.` and `..` - // are resolved without touching the filesystem" -- so it normalizes in - // user mode against the CWD rather than making a kernel transition. - // This said "most of the cost above is a syscall that no allocation - // scheme can remove", which contradicts the owning crate and names a - // mechanism a timing loop cannot establish anyway. The conclusion that - // matters survives: whatever it is, it is not allocation. + // "resolves against process state" -- not "a syscall", and not + // "lexical" either. + // + // The first was wrong because a timing loop cannot establish a kernel + // transition. The second, which replaced it, is wrong for a symmetric + // reason: `GetFullPathNameW` consults the process current directory, + // and for a drive-relative path the per-drive current directory held in + // the `=C:` environment variables, so it is not pure string work. A + // genuinely lexical canonicalizer is a different call + // (`PathCchCanonicalizeEx`), and it is deliberately NOT the one + // `prepare` wants -- resolving against the CWD at submission is the + // property the namespace design is buying. + // + // What this run established is the cost. The mechanism it did not, and + // two successive attempts to name one were each wrong in the same way. let _ = writeln!( out, " `prepare` calls GetFullPathNameW to resolve the path against the" @@ -290,19 +310,19 @@ fn render() -> String { ); let _ = writeln!( out, - " and resolving later would be racy. That is lexical normalization," + " and resolving later would be racy. That reads process state and" ); let _ = writeln!( out, - " not a filesystem touch -- and not an allocation either, so most of" + " touches no filesystem -- and it is not an allocation, so most of the" ); let _ = writeln!( out, - " the cost above is work no allocation scheme can remove. Whether it" + " cost above is work no allocation scheme can remove. Whether any of" ); let _ = writeln!( out, - " enters the kernel is not something this run measured." + " it enters the kernel is not something this run measured." ); let _ = writeln!( out, diff --git a/crates/windows-platform-probes/src/doorbell_cost.rs b/crates/windows-platform-probes/src/doorbell_cost.rs index a282ca0dd..3abbf74ec 100644 --- a/crates/windows-platform-probes/src/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/doorbell_cost.rs @@ -52,7 +52,7 @@ //! to be. //! //! Whether it even reaches the kernel is host-dependent and the binary decides -//! it per run rather than asserting it. On the development machine it came in +//! it per run rather than asserting it. On the Snapdragon X2 (ARM64) development machine it came in //! at ~79 ns, far below that machine's own syscalls, which reads as //! short-circuiting in user mode when there is nothing queued; on an x86_64 //! host measured during review it was 216 ns, sitting among that host's 206 ns @@ -117,9 +117,10 @@ impl Observation { /// The argument rests on *carries no work*, which holds everywhere, and no /// longer on *does not enter the kernel*, which does not. That read "an /// empty submit does not appear to enter the kernel, so this ratio has a - /// denominator that is not a syscall" -- a development-machine reading - /// (~79 ns) stated as a general fact. The binary decides it per host and - /// on an x86_64 machine measured during review printed the opposite, the + /// denominator that is not a syscall" -- a reading from the Snapdragon X2 + /// (ARM64) development machine (~79 ns) stated as a general fact. The + /// binary decides it per host, and on an x86_64 machine measured during + /// review it printed the opposite, the /// empty submit landing at 216 ns among that probe's own 206 ns syscalls. #[must_use] pub fn doorbell_share_of_submit(&self) -> Option { diff --git a/crates/windows-platform-probes/src/request_cost.rs b/crates/windows-platform-probes/src/request_cost.rs index aff5334c2..4036ea199 100644 --- a/crates/windows-platform-probes/src/request_cost.rs +++ b/crates/windows-platform-probes/src/request_cost.rs @@ -19,9 +19,9 @@ //! faithfully on another. So the queue can carry a request by value and the //! lifetime hazard disappears. What remains is a cost question about **this //! operation type**: how does building one compare with the doorbell that would -//! carry it (~165 ns as recorded on the development machine -- run -//! `probe-doorbell-cost` on the host in front of you for a local figure, which -//! CI does in the same job)? +//! carry it (~165 ns as recorded on the Snapdragon X2 (ARM64) development +//! machine -- run `probe-doorbell-cost` on the host in front of you for a local +//! figure, which CI does in the same job)? //! //! # What this does not measure, stated because the number invites over-reading //! @@ -42,10 +42,10 @@ //! doorbell that would carry it. Which of the two is the larger half is a //! question about one host, and this probe measures only one side of it -- //! read `probe-doorbell-cost`'s `set_reset_event` from the same run for the -//! other. The comparison inverts between machines: the development machine had -//! the doorbell at roughly a third of a build, and an x86_64 host measured -//! during review had it at roughly two and a half times one. A sentence naming -//! a small half would therefore be wrong on one of them. +//! other. The comparison inverts between machines: the Snapdragon X2 (ARM64) +//! development machine had the doorbell at roughly a third of a build, and an +//! x86_64 host measured during review had it at roughly two and a half times +//! one. A sentence naming a small half would therefore be wrong on one of them. //! # Handle duplication is the part that is easy to under-count //! //! A request that carries a handle -- a template handle for an open, or the @@ -63,12 +63,17 @@ //! path is resolved at submission -- the process CWD is mutable by any thread, //! so even perfect remoting would be racy. //! -//! That work is **lexical**: `windows-namespace-request-sys` documents the call -//! as resolving `.` and `..` "without touching the filesystem". So the measured -//! remainder is path normalization, not allocation -- and calling it a *syscall -//! cost*, as this once did, both contradicts the owning crate and names a -//! mechanism a timing loop cannot establish. What survives is the part that -//! matters: an allocator cannot remove it. +//! That work reads **process state**: it resolves against the current +//! directory, and for a drive-relative path against the per-drive current +//! directory held in the `=C:` environment variables. So the measured remainder +//! is path resolution, not allocation -- and naming a *mechanism* for it has +//! now been got wrong twice. Calling it a *syscall cost* claimed a kernel +//! transition a timing loop cannot establish; calling it *lexical*, which +//! replaced it, claimed pure string work it equally is not. A genuinely lexical +//! canonicalizer is a different call (`PathCchCanonicalizeEx`) and is +//! deliberately not the one wanted here, because resolving against the CWD at +//! submission is the property being bought. What survives either way is the +//! part that matters: an allocator cannot remove it. //! //! The two schemes that might reduce it recover different halves. **Inline //! storage** removes the allocation and copy, which is what From f9081f192dbaba7b6f176e849dcee42ac3e9327a Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 12:27:49 -0400 Subject: [PATCH 06/17] fix(platform-probes): finish the doorbell ratio rename, and measure the drive-letter claim Two findings from Copilot review on #83. The review ran against `fabda22`, two commits back, so its third finding (a stray `//!`) was already fixed in `ec4e2b5`; these two are live at HEAD and both land. Finish the rename. `ec4e2b5` renamed the serialized field to `doorbell_over_empty_submit` because "share of a submit" promises a meaningful fraction where the denominator is an empty ring, and left the accessor as `doorbell_share_of_submit`. The comment making that argument sat six lines from the sibling it did not reach, and the reviewer duly read the method as promising a share. A rename for precision is not finished until every name for the quantity moves; the field and the method are one fact with two spellings. Measure the drive-letter claim rather than arguing it. Two review passes read the hard-coded `C:` in the long-path sample as the portability bug that `system_directory()` fixes for the path that is really opened. It is not: `GetFullPathNameW` normalizes a fully-qualified path without consulting a device, so no volume is needed behind the letter -- verified by preparing a 24-component path on a drive letter with nothing mounted, which succeeds. That fact is now a test rather than a comment, and it earns its place twice over. It answers the review permanently, and it is the first thing here to pin "touches no filesystem" -- the claim the probe's whole account of where its nanoseconds go rests on, corrected only one commit ago and until now supported by nothing executable. The sample stays hard-coded, because the two paths have opposite requirements and making them match would hide that. `short` is really opened, so it must exist and is resolved; the long sample is only normalized, so it must not need to exist, and a fixed 24 components keep its length identical across the hosts the report asks a reader to compare. The comment now says so. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../src/bin/doorbell_cost.rs | 15 ++++++--- .../src/doorbell_cost.rs | 7 ++-- .../src/request_cost.rs | 13 ++++++++ crates/windows-platform-probes/src/tests.rs | 32 +++++++++++++++++++ 4 files changed, 60 insertions(+), 7 deletions(-) diff --git a/crates/windows-platform-probes/src/bin/doorbell_cost.rs b/crates/windows-platform-probes/src/bin/doorbell_cost.rs index 8b617ceb4..f8f7813ce 100644 --- a/crates/windows-platform-probes/src/bin/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/bin/doorbell_cost.rs @@ -251,9 +251,16 @@ fn render(observation: &Observation, park: Option) -> String { // that any figure derived from it is a confident wrong answer -- and this // line then handed a machine exactly that figure under a name meaning "the // doorbell's share of a submit", with no caveat a mining pass could read. - // The name now states its own denominator, so a query that wants the ratio - // asks for it knowingly, and one that wants a real share of a syscall does - // not find this field by looking for that. + // The name states its own denominator, so a query that wants the ratio asks + // for it knowingly, and one that wants a real share of a syscall does not + // find this field by looking for that. + // + // The accessor carries the same name, and did not at first. Renaming the + // serialized field while leaving the method as `doorbell_share_of_submit` + // left the argument above sitting a few lines from the sibling it did not + // reach -- and a reviewer duly read the method as promising a meaningful + // share. A rename for precision is not finished until every name for the + // quantity moves; the field and the method are one fact with two spellings. let _ = writeln!( out, concat!( @@ -272,7 +279,7 @@ fn render(observation: &Observation, park: Option) -> String { .submit_nanos .map_or("null".to_string(), |n| format!("{n:.1}")), observation - .doorbell_share_of_submit() + .doorbell_over_empty_submit() .map_or("null".to_string(), |s| format!("{s:.4}")), ); out diff --git a/crates/windows-platform-probes/src/doorbell_cost.rs b/crates/windows-platform-probes/src/doorbell_cost.rs index 3abbf74ec..a96de3328 100644 --- a/crates/windows-platform-probes/src/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/doorbell_cost.rs @@ -62,8 +62,9 @@ //! The honest denominator is the cost of the real work a submission carries, //! which this probe deliberately does not measure -- so it reports the absolute //! costs and the *batching* arithmetic instead, and leaves the ratio alone. -//! [`Observation::doorbell_share_of_submit`] is retained only because the raw -//! fact is worth recording; its own documentation repeats this warning. +//! [`Observation::doorbell_over_empty_submit`] is retained only because the raw +//! fact is worth recording; it is named for its own denominator, and its own +//! documentation repeats this warning. use std::sync::atomic::{AtomicU64, Ordering}; use std::time::Instant; @@ -123,7 +124,7 @@ impl Observation { /// review it printed the opposite, the /// empty submit landing at 216 ns among that probe's own 206 ns syscalls. #[must_use] - pub fn doorbell_share_of_submit(&self) -> Option { + pub fn doorbell_over_empty_submit(&self) -> Option { let doorbell = self.get("set_reset_event")?; let submit = self.submit_nanos?; (submit > 0.0).then_some(doorbell / submit) diff --git a/crates/windows-platform-probes/src/request_cost.rs b/crates/windows-platform-probes/src/request_cost.rs index 4036ea199..1cfcec657 100644 --- a/crates/windows-platform-probes/src/request_cost.rs +++ b/crates/windows-platform-probes/src/request_cost.rs @@ -185,6 +185,19 @@ pub fn measure() -> Observation { .to_str() .expect("the system directory is representable"), ); + // Synthetic, and hard-coded on purpose -- the opposite requirement to the + // path above, which is why the two do not match and must not be made to. + // `short` names a file that is really opened, so it has to exist and is + // resolved. This one is only ever normalized, so it must NOT need to exist: + // a fixed 24-component path keeps the length identical on every host, and a + // length that varied with the local system directory would make the figure + // incomparable between the machines the report asks a reader to compare. + // + // The `C:` is safe for the same reason the probe's own conclusion is: a + // fully-qualified path is normalized without consulting a device, so no + // volume is needed behind the letter. Two review passes read this as the + // portability bug fixed above, so it is now measured rather than argued -- + // see `preparing_a_path_needs_no_volume_behind_its_drive_letter`. let long_text = format!(r"C:\{}\file.txt", vec!["directory"; 24].join("\\")); let long = Wtf16String::from(long_text.as_str()); diff --git a/crates/windows-platform-probes/src/tests.rs b/crates/windows-platform-probes/src/tests.rs index 5ba04c6d8..3ad19e92c 100644 --- a/crates/windows-platform-probes/src/tests.rs +++ b/crates/windows-platform-probes/src/tests.rs @@ -4339,3 +4339,35 @@ fn a_small_handshake_completes_and_reports_a_positive_round_trip() { "a completed handshake must report a positive finite round trip, got {average}" ); } + +// --- what `prepare` needs from a drive letter ------------------------------- +// +// `request_cost::measure` builds its long-path sample on a hard-coded `C:`, and +// two review passes read that as a portability bug: a machine with no `C:` +// volume would panic on the `expect` rather than measure. It would not, and the +// reason is the same fact the probe's own headline conclusion rests on -- that +// `GetFullPathNameW` resolves a fully-qualified path without touching the +// filesystem. A volume that does not exist is therefore not consulted. +// +// That was an argument, and an argument is what a reviewer had to disbelieve. +// This is the measurement. It also pins the "touches no filesystem" claim +// itself, which nothing else here does: if that claim ever stops holding, the +// probe's account of where its nanoseconds go is wrong, and this fails first. + +#[test] +fn preparing_a_path_needs_no_volume_behind_its_drive_letter() { + let absent = ('D'..='Z') + .find(|c| !std::path::Path::new(&format!("{c}:\\")).exists()) + .expect("a test machine has at least one unused drive letter"); + + let text = format!(r"{absent}:\{}\file.txt", vec!["directory"; 24].join("\\")); + let path = wtf_string::Wtf16String::from(text.as_str()); + + assert!( + windows_namespace_request_sys::prepare(&path).is_ok(), + "preparing {text} must succeed with no {absent}: volume mounted -- \ + a fully-qualified path is normalized, not resolved against a device, \ + and `request_cost` depends on that both for its long-path sample and \ + for its claim about where the measured time goes" + ); +} From 22bce4769e9b340e85fd6e6f05268f495d49dc10 Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 12:43:48 -0400 Subject: [PATCH 07/17] fix(platform-probes): check every status the probes discard, and stop guessing a path Six findings from review, all accepted. The rule adopted is flat: every call that returns a status has that status checked, inside the timed region, with no per-call-site argument about whether this one is worth it. The three event loops discarded their `BOOL`s while the `SubmitIoRing` loop twelve lines below them carried a careful note explaining why doing that lets a failing call report a plausible time for an operation that never happened. The argument was right and had been applied only to the call that looked expensive enough to deserve it. That is how the cheap calls get missed: "trivial enough not to check" is a fact about how hard anyone looked, not about the call. Both halves of the case are now measured rather than argued, by running the probe against a deliberately invalid handle so every event call fails. The unchecked version reported 212.7 ns for a redundant `SetEvent` (true 205), 422.9 for the set/reset cycle (true 531), and 231.5 for a satisfied wait (true 280). Not one looks wrong -- the first is within 4% -- so the whole doorbell-versus-build conclusion would have been drawn from a run in which no event operation succeeded. A failing syscall is not cheap enough to be conspicuous, which is the entire hazard. With the checks in place the same host reports 204-206, 528-534 and 280.3-280.7 across three runs: run-to-run spread, not a shift. The figures are recorded at the site so a future tuning decision starts from data. `CloseHandle` is checked as a post-condition, and earns it: in that bad-handle run, with every other check stripped, it was the one that caught it. Also in `request_cost`: - `system_directory` retries at the size the call asks for instead of giving up on a short buffer, and now panics rather than substituting `C:\Windows\ System32` when the system will not answer. The old fallback sat under a doc comment claiming it kept the failure visible while doing the opposite -- substituting a guess for an answer never obtained, which is the same defect as discarding a status. - The path stays wide from the Win32 call to `Wtf16String`. It went out through `from_utf16_lossy` and back in through `to_str().expect(...)`, which could panic on a non-UTF-8 path and silently replaced unpaired surrogates before that. `Wtf16String::from_os_str` exists for exactly this. And the new drive-letter test uses `GetLogicalDrives` instead of probing 23 roots with `Path::exists()`, which touches real devices: an offline mapped network drive would block it until the redirector times out, on exactly the CI machine most likely to have one. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../src/doorbell_cost.rs | 89 ++++++++++++++++--- .../src/request_cost.rs | 75 ++++++++++++---- crates/windows-platform-probes/src/tests.rs | 16 +++- 3 files changed, 149 insertions(+), 31 deletions(-) diff --git a/crates/windows-platform-probes/src/doorbell_cost.rs b/crates/windows-platform-probes/src/doorbell_cost.rs index a96de3328..a139e0c3b 100644 --- a/crates/windows-platform-probes/src/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/doorbell_cost.rs @@ -155,6 +155,13 @@ fn time_loop(label: &'static str, iterations: u32, mut body: impl FnMut()) -> Ti /// /// Panics if `CreateEventW` fails, which would mean the host cannot create a /// manual-reset event and nothing here is measurable. +/// +/// Panics, too, if any timed call fails -- `SetEvent`, `ResetEvent`, a +/// zero-timeout wait that does not observe the event as signalled, or +/// `SubmitIoRing`. This is deliberately loud. Each of those still costs a +/// measurable transition when it fails, so a probe that swallowed the error +/// would report a plausible nanosecond figure for an operation that did not +/// happen, which is worse than reporting nothing. #[must_use] pub fn measure() -> Observation { const ITERATIONS: u32 = 200_000; @@ -170,25 +177,81 @@ pub fn measure() -> Observation { counter.fetch_add(1, Ordering::Relaxed); })); + // THE RULE: every call that returns a status has that status checked, + // inside the timed region. No exceptions, and no per-call-site argument + // about whether this one is worth it. + // + // It is a flat rule on purpose. The previous version checked only + // `SubmitIoRing`, with a well-argued note there explaining why discarding a + // status lets a failing call report a plausible time for an operation that + // never happened -- and left the three event loops above it discarding + // their `BOOL`s. The argument was correct and got applied to the one call + // that looked expensive enough to deserve it. That is how the cheap calls + // get missed: "trivial enough not to check" is not a property of the call, + // it is a property of how hard anyone looked at it. + // + // Both halves of that were measured rather than argued, on the x86_64 + // review host, by running this probe against a deliberately invalid handle + // so that every event call fails. + // + // What the unchecked version reported, in ns/op, against the true figures: + // + // set_event_already_signalled 212.7 (true 205) + // set_reset_event 422.9 (true 531) + // wait_zero_signalled 231.5 (true 280) + // + // Not one of those looks wrong. The redundant-`SetEvent` figure is within + // 4% of the real one, and a reader would have taken the whole set as + // evidence and drawn the doorbell-versus-build conclusion from a run in + // which no event operation ever succeeded. A failing syscall is not cheap + // enough to be conspicuous -- that is the entire hazard. + // + // The checks cost nothing detectable: with them in place the same host + // reports 204-206, 528-534 and 280.3-280.7 across three runs, which is the + // run-to-run spread and not a shift. If a check ever does cost enough to + // distort a figure, that will show up as data and can be tuned then, at + // that site, with the evidence in hand. Until then the rule does not bend + // to an estimate. + // + // `atomic_fetch_add` above is not an exception: `fetch_add` returns no + // status, so there is nothing to check. + // Leave it signalled, so every call in the next loop is redundant. - unsafe { SetEvent(event) }; + assert!(unsafe { SetEvent(event) } != 0, "SetEvent failed"); timings.push(time_loop("set_event_already_signalled", ITERATIONS, || { - unsafe { SetEvent(event) }; + assert!( + unsafe { SetEvent(event) } != 0, + "SetEvent on an already-signalled event failed" + ); })); - unsafe { ResetEvent(event) }; + assert!(unsafe { ResetEvent(event) } != 0, "ResetEvent failed"); timings.push(time_loop("set_reset_event", ITERATIONS, || unsafe { - SetEvent(event); - ResetEvent(event); + assert!(SetEvent(event) != 0, "SetEvent failed mid-cycle"); + assert!(ResetEvent(event) != 0, "ResetEvent failed mid-cycle"); })); - unsafe { SetEvent(event) }; + assert!(unsafe { SetEvent(event) } != 0, "SetEvent failed"); timings.push(time_loop("wait_zero_signalled", ITERATIONS, || { - unsafe { WaitForSingleObject(event, 0) }; + // `assert_eq`, not "did not fail". The label says *satisfied* wait, and + // `WAIT_TIMEOUT` is a successful return that times a different path -- + // an unsatisfied poll, which is the cheaper one and would flatter the + // figure. + assert_eq!( + unsafe { WaitForSingleObject(event, 0) }, + WAIT_OBJECT_0, + "a zero-timeout wait did not observe the event as signalled" + ); })); unsafe { - ResetEvent(event); - CloseHandle(event); + assert!(ResetEvent(event) != 0, "ResetEvent failed"); + // Checked as a post-condition: a close that fails means the handle was + // already invalid, which retroactively discredits every figure above + // it. That is not theoretical -- in the bad-handle run described above, + // with every other check stripped out, this was the one that caught it. + // It is the backstop for a handle that goes bad in a way no individual + // call happens to report. + assert!(CloseHandle(event) != 0, "CloseHandle failed"); } // The syscall the doorbell would be amortised against. Far fewer @@ -208,9 +271,13 @@ pub fn measure() -> Observation { // succeeded while submitting entries did not measure what the label // says it measured. // - // The cost is a predictable branch against a syscall, which does not - // perturb the figure; leaving the check outside the loop would let + // Inside the loop, not outside it: a check after the fact would let // the timing be taken before anything established it was valid. + // + // Every loop above now does the same, under the flat rule stated + // there. This note came first and for a while was the only one, + // which is the whole reason the rule is now flat rather than + // argued per site. let (hr, submitted) = ring.submit_and_wait(0); assert!(hr >= 0, "SubmitIoRing(0) failed: {hr:#010x}"); assert_eq!(submitted, 0, "SubmitIoRing(0) submitted entries"); diff --git a/crates/windows-platform-probes/src/request_cost.rs b/crates/windows-platform-probes/src/request_cost.rs index 1cfcec657..072edd012 100644 --- a/crates/windows-platform-probes/src/request_cost.rs +++ b/crates/windows-platform-probes/src/request_cost.rs @@ -179,12 +179,15 @@ pub fn measure() -> Observation { // installation can sit on any volume -- and hard-coding it made this probe // panic on such a machine rather than measure it. The same path is used for // the prepared request and the real open below, so the two stay consistent. + // Wide the whole way, with no UTF-8 in the middle. `Wtf16String` exists + // precisely to carry what Windows hands back, and routing a Windows path + // through `str` gives up that property twice over: `to_str` panics on a + // path that is not valid UTF-8, and the `from_utf16_lossy` this once used + // inside `system_directory` silently replaced any unpaired surrogate before + // it ever got here. Neither is reachable on a normal install, and neither + // has any business being on the path from a Win32 call to a WTF-16 string. let system_dll = system_directory().join("kernel32.dll"); - let short = Wtf16String::from( - system_dll - .to_str() - .expect("the system directory is representable"), - ); + let short = Wtf16String::from_os_str(system_dll.as_os_str()); // Synthetic, and hard-coded on purpose -- the opposite requirement to the // path above, which is why the two do not match and must not be made to. // `short` names a file that is really opened, so it has to exist and is @@ -283,22 +286,58 @@ pub fn measure() -> Observation { /// Where Windows is actually installed, rather than where it usually is. /// -/// Falls back to the conventional path only when the system will not say, which -/// keeps the probe running on a machine that answers and keeps the failure -/// visible on one that does not. +/// A short buffer is retried at the size the call asks for, so a long system +/// directory is read rather than guessed at. +/// +/// # Panics +/// +/// Panics if `GetSystemDirectoryW` will not report a directory. +/// +/// This used to fall back to `C:\Windows\System32`, under a doc comment +/// claiming the fallback kept the failure visible. It did the opposite: it +/// substituted a guess for an answer the system declined to give, and the probe +/// then measured whatever happened to be at the guessed path -- on a non-`C:` +/// install, something that is not there at all. That is the same defect as +/// discarding a status: a plausible result standing in for one that was never +/// obtained. A probe that cannot locate the file it is timing has nothing to +/// say, and says so here rather than several frames later. fn system_directory() -> std::path::PathBuf { + // The common case, off the stack. let mut buffer = [0_u16; 260]; // SAFETY: writes at most `buffer.len()` units into a buffer of that size. - let written = unsafe { GetSystemDirectoryW(buffer.as_mut_ptr(), buffer.len() as u32) }; - let written = written as usize; + let written = unsafe { GetSystemDirectoryW(buffer.as_mut_ptr(), buffer.len() as u32) } as usize; + + assert!( + written != 0, + "GetSystemDirectoryW failed: {}", + std::io::Error::last_os_error() + ); + // `>=`, not `>`. On success the count excludes the terminator, so it can - // reach at most `buffer.len() - 1`; on failure it is the required size - // *including* the terminator, so it is at least `buffer.len() + 1`. Exactly - // `buffer.len()` is therefore unreachable from either branch -- and treating - // it as a failure costs nothing while removing the need for the next reader - // to redo that analysis before trusting a possibly-unterminated buffer. - if written == 0 || written >= buffer.len() { - return std::path::PathBuf::from(r"C:\Windows\System32"); + // reach at most `buffer.len() - 1`; when the buffer is too small it is the + // required size *including* the terminator, so it is at least + // `buffer.len() + 1`. Exactly `buffer.len()` is therefore unreachable from + // either branch -- and treating it as too-small costs one wasted retry + // while removing the need for the next reader to redo that analysis before + // trusting a possibly-unterminated buffer. + if written >= buffer.len() { + // `written` is the required size including the terminator, so a buffer + // of exactly that length is enough and the retry cannot ask again. + let mut heap = vec![0_u16; written]; + // SAFETY: writes at most `heap.len()` units into a buffer of that size. + let retried = unsafe { GetSystemDirectoryW(heap.as_mut_ptr(), heap.len() as u32) } as usize; + assert!( + retried != 0 && retried < heap.len(), + "GetSystemDirectoryW failed at the size it asked for ({written}): {}", + std::io::Error::last_os_error() + ); + return std::path::PathBuf::from(os_string(&heap[..retried])); } - std::path::PathBuf::from(String::from_utf16_lossy(&buffer[..written])) + + std::path::PathBuf::from(os_string(&buffer[..written])) +} + +/// Losslessly, because a Windows path is UTF-16 and not necessarily Unicode. +fn os_string(units: &[u16]) -> std::ffi::OsString { + std::os::windows::ffi::OsStringExt::from_wide(units) } diff --git a/crates/windows-platform-probes/src/tests.rs b/crates/windows-platform-probes/src/tests.rs index 3ad19e92c..b73a87beb 100644 --- a/crates/windows-platform-probes/src/tests.rs +++ b/crates/windows-platform-probes/src/tests.rs @@ -4356,8 +4356,20 @@ fn a_small_handshake_completes_and_reports_a_positive_round_trip() { #[test] fn preparing_a_path_needs_no_volume_behind_its_drive_letter() { - let absent = ('D'..='Z') - .find(|c| !std::path::Path::new(&format!("{c}:\\")).exists()) + // A bitmask, not 23 `Path::exists()` calls. Probing each root touches real + // devices: an offline mapped network drive makes `exists()` block until the + // redirector times out, so the original form could stall this test for + // minutes on exactly the CI machine most likely to have one. + // `GetLogicalDrives` answers from a snapshot without going near a device, + // and answers the sharper question too -- a letter absent from the mask has + // no volume, where `exists()` also returns false for a drive that is + // present but has no media. + // + // SAFETY: no preconditions. + let used = unsafe { windows_sys::Win32::Storage::FileSystem::GetLogicalDrives() }; + let absent = (b'D'..=b'Z') + .find(|&byte| used & (1 << u32::from(byte - b'A')) == 0) + .map(char::from) .expect("a test machine has at least one unused drive letter"); let text = format!(r"{absent}:\{}\file.txt", vec!["directory"; 24].join("\\")); From cc871534e2ff41ea7d469a97d6b269a18c63648d Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 13:01:07 -0400 Subject: [PATCH 08/17] fix(platform-probes): apply the status rule to the handshake it skipped `measure_park_and_wake` discarded four statuses -- `SetEvent` on both sides of the handshake and both `CloseHandle`s -- in the same file, and the same commit, that declared the rule flat and wrote "no exceptions". Fixing `measure` and leaving its sibling one function below is precisely the failure the flat rule exists to prevent, committed while stating it. Found by `rustc`'s `unused_results` lint rather than by re-reading the file. The regex sweep that sized the workspace backlog had counted these sites; it reported a per-crate total, and a total is not a list, so the four in a file already believed fixed went unlooked-at. The lint names sites. The two `SetEvent`s are reported rather than asserted, because these run either side of a thread boundary. The peer returns `false`, since a panic there would be flattened into the same `false` by `join` with the message lost; the main loop sets `ok = false` and breaks, matching how the existing wait failure is handled. Neither changes the answer -- a failing `SetEvent` was already caught by the peer's wait timing out -- but it changes a five-second timeout per round diagnosed as "the peer never woke" into an immediate failure at the cause. The two `CloseHandle`s assert, matching `measure`. Verified with `RUSTFLAGS=-W unused_results`: the only remaining hits in this PR's two files are `fetch_add` and `black_box`, neither of which is a failable call. 26 unique sites elsewhere in the crate are pre-existing and belong to the workspace audit queued as M22.1. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../src/doorbell_cost.rs | 23 +++++++++++++++---- 1 file changed, 19 insertions(+), 4 deletions(-) diff --git a/crates/windows-platform-probes/src/doorbell_cost.rs b/crates/windows-platform-probes/src/doorbell_cost.rs index a139e0c3b..522ecc62a 100644 --- a/crates/windows-platform-probes/src/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/doorbell_cost.rs @@ -343,7 +343,12 @@ pub fn measure_park_and_wake(rounds: u32) -> Option { if waited != WAIT_OBJECT_0 { return false; } - unsafe { SetEvent(pong) }; + // Reported rather than asserted: a panic here would cross a thread + // boundary into `join`, which turns it into the same `false` with + // the message lost. Failing the handshake is the honest handling. + if unsafe { SetEvent(pong) } == 0 { + return false; + } } true }); @@ -352,7 +357,17 @@ pub fn measure_park_and_wake(rounds: u32) -> Option { let start = Instant::now(); for _ in 0..rounds { // SAFETY: both handles are live for the whole loop. - unsafe { SetEvent(ping) }; + // + // A failing `SetEvent` would eventually be caught by the peer's wait + // timing out, so this is not the difference between a wrong answer and + // a right one -- it is the difference between failing in 5 ms and + // failing after `rounds` timeouts of WAIT_TIMEOUT_MS each, under a + // diagnosis ("the peer never woke") that names the symptom rather than + // the cause. + if unsafe { SetEvent(ping) } == 0 { + ok = false; + break; + } if unsafe { WaitForSingleObject(pong, WAIT_TIMEOUT_MS) } != WAIT_OBJECT_0 { ok = false; break; @@ -363,8 +378,8 @@ pub fn measure_park_and_wake(rounds: u32) -> Option { let peer_ok = peer.join().unwrap_or(false); // SAFETY: the peer has been joined, so nothing else holds these. unsafe { - CloseHandle(ping); - CloseHandle(pong); + assert!(CloseHandle(ping) != 0, "CloseHandle(ping) failed"); + assert!(CloseHandle(pong) != 0, "CloseHandle(pong) failed"); } (ok && peer_ok).then(|| elapsed.as_nanos() as f64 / f64::from(rounds)) From c0a0021e6848244df1aa9d66f08579f2cdaed2aa Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 13:13:28 -0400 Subject: [PATCH 09/17] fix(platform-probes): emit JSON that is actually JSON, and stop the drive test going vacuous Two live findings from Copilot review on #83. Its other two -- the discarded `SetEvent` and `CloseHandle` in `measure_park_and_wake` -- were already fixed in `cc87153`; the review ran against `22bce47`. Independent confirmation of what `unused_results` had found. NaN is not JSON. Four required timings were emitted through `unwrap_or(f64::NAN)` and formatted with `{:.1}`, so a label renamed in one place and not the other would have produced `"atomic_ns":NaN` -- and RFC 8259 has no such literal, so a strict parser rejects the whole line rather than that one field. A defect in this probe would have silently converted every run into unparseable output for exactly the log-mining consumer this format exists for. They are now `expect`, because absent is not a real outcome for them: `measure` always records all four. The three fields that legitimately can be absent keep emitting `null`, which is what that idiom is for -- a parked handshake can time out and an `IoRing` may be unavailable. Worth recording how this survived: every "the NDJSON parses" check in this branch's history used PowerShell's `ConvertFrom-Json`, which ACCEPTS `NaN`. `System.Text.Json`, which follows RFC 8259, rejects it. The verification was weaker than the claim it was making. All three NDJSON-emitting probes are now validated with the strict parser. The drive-letter test could go vacuous. `GetLogicalDrives` returns 0 on failure, which is also a valid mask meaning "no drives at all" -- so an unchecked zero reads as "every letter is free", and the search would pick a letter that may be mounted. The test would then prepare a path on a real volume and pass, proving nothing. That matters here more than most places, because this is the test that pins the claim that no volume is needed. It is also a plain instance of the standard adopted for this workspace, in a call introduced by the previous fix: `Path::exists()` could not fail this way, and its replacement can. The search now covers `A..=Z` rather than `D..=Z`. The mask already excludes anything mounted, so reserving letters by hand only narrowed the search on a machine with many mapped drives -- `C` being in use is precisely what the mask reports. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../src/bin/doorbell_cost.rs | 29 ++++++++++++++++--- crates/windows-platform-probes/src/tests.rs | 26 +++++++++++++++-- 2 files changed, 49 insertions(+), 6 deletions(-) diff --git a/crates/windows-platform-probes/src/bin/doorbell_cost.rs b/crates/windows-platform-probes/src/bin/doorbell_cost.rs index f8f7813ce..b6c0c6c88 100644 --- a/crates/windows-platform-probes/src/bin/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/bin/doorbell_cost.rs @@ -240,12 +240,33 @@ fn render(observation: &Observation, park: Option) -> String { " part carrying the lost-wakeup risk, so it can wait for a" ); let _ = writeln!(out, " measurement against real work."); - let atomic = observation.get("atomic_fetch_add").unwrap_or(f64::NAN); + // `expect`, not `unwrap_or(NAN)`. These four labels are always produced by + // `measure`, so a lookup that misses means a label was renamed in one place + // and not the other -- a defect in this probe, not a condition of the host. + // + // The old default made that defect emit `"atomic_ns":NaN`, and **`NaN` is + // not JSON**: RFC 8259 has no such literal, and a strict parser rejects the + // whole line. So a renamed label would have silently converted every run + // into unparseable output for any consumer doing what this format exists + // for. + // + // Note the contrast with the three fields below, which correctly emit + // `null`. That is right for *them*: a parked handshake can time out and an + // `IoRing` may be unavailable, so absent is a real outcome those fields + // must be able to say. Absent is not a real outcome for these four, and + // giving them a way to say it only hid the bug. + let atomic = observation + .get("atomic_fetch_add") + .expect("measure always records atomic_fetch_add"); let already = observation .get("set_event_already_signalled") - .unwrap_or(f64::NAN); - let cycle = observation.get("set_reset_event").unwrap_or(f64::NAN); - let wait0 = observation.get("wait_zero_signalled").unwrap_or(f64::NAN); + .expect("measure always records set_event_already_signalled"); + let cycle = observation + .get("set_reset_event") + .expect("measure always records set_reset_event"); + let wait0 = observation + .get("wait_zero_signalled") + .expect("measure always records wait_zero_signalled"); // `doorbell_over_empty_submit`, not `doorbell_share_of_submit`. The prose // above tells a human that an empty submit is not a fair denominator and // that any figure derived from it is a confident wrong answer -- and this diff --git a/crates/windows-platform-probes/src/tests.rs b/crates/windows-platform-probes/src/tests.rs index b73a87beb..68799d722 100644 --- a/crates/windows-platform-probes/src/tests.rs +++ b/crates/windows-platform-probes/src/tests.rs @@ -4367,10 +4367,32 @@ fn preparing_a_path_needs_no_volume_behind_its_drive_letter() { // // SAFETY: no preconditions. let used = unsafe { windows_sys::Win32::Storage::FileSystem::GetLogicalDrives() }; - let absent = (b'D'..=b'Z') + + // `GetLogicalDrives` returns 0 on failure, which is also a perfectly valid + // mask meaning "no drives at all" -- so an unchecked zero would be read as + // "every letter is free", and the search would pick a letter that may well + // be mounted. The test would then prepare a path on a REAL volume and pass, + // proving nothing, which is worse than failing. + // + // That this test in particular could go vacuous is the sharp edge: it is + // the one pinning the claim that no volume is needed. It is also a plain + // instance of the workspace standard -- a failable call has its failure + // handled -- introduced by the switch away from `Path::exists()`, which + // could not fail this way. + assert!( + used != 0, + "GetLogicalDrives failed: {}", + std::io::Error::last_os_error() + ); + + // The whole alphabet. The mask already excludes anything mounted, so there + // is no letter worth reserving by hand: starting at `D` only narrowed the + // search on a machine with many mapped drives, for no benefit, since `C` + // being in use is exactly what the mask reports. + let absent = (b'A'..=b'Z') .find(|&byte| used & (1 << u32::from(byte - b'A')) == 0) .map(char::from) - .expect("a test machine has at least one unused drive letter"); + .expect("every drive letter A-Z is in use, so this test cannot run here"); let text = format!(r"{absent}:\{}\file.txt", vec!["directory"; 24].join("\\")); let path = wtf_string::Wtf16String::from(text.as_str()); From bdc45cc543331f82b3220868d0bc87143932d695 Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 13:28:47 -0400 Subject: [PATCH 10/17] fix(platform-probes): route every probe through emit_report, and diagnose loudly Findings from two Copilot reviews on #83. Its `GetLogicalDrives` and `measure_park_and_wake` findings were already fixed in `c0a0021` and `cc87153`; these five are live. Route every probe through `report::emit_report`. `report.rs` states that every probe in this crate routes through it "with no exceptions", and three did not: both new ones here and `topology.rs`, which shipped in #82. All three were mine, so the claim has been false for two PRs. `emit_report` catches a panic during composition, prints what was already established, and resumes -- which is the difference between a CI log showing which probe died and how far it got, and one showing nothing at all. This interacts directly with the rest of this branch. The last several commits deliberately added panics to these probes -- every status now asserted, every required NDJSON label now `expect` -- so the panic surface grew substantially in exactly the two probes sitting outside the mechanism that reports panics. Adding loud failures while bypassing the thing that makes them diagnosable is half a change. `doorbell_cost` also measured in `main`'s argument list, so its measurement ran before the renderer was entered and outside the protection entirely. It now measures inside `render`, after the banner is in the buffer. Verified by sabotage: a panic at the measurement leaves the banner and heading on stdout and still exits 101. Diagnose loudly. Ten assertions said "SetEvent failed" and dropped the Win32 error, which is what a reader has to work from in CI where a rerun under a debugger is not available; the code distinguishes an invalid handle from a resource limit. They now carry `last_os_error()`, evaluated only on failure, so the timed loops are unaffected. `handle_state.rs` already did this -- the idiom existed and had not reached the new code. `request_cost`'s NDJSON emitted `null` for six timings `measure` always records, the same defect as `c0a0021`'s `NaN` and missed in the same sweep. `null` is right for a value that can legitimately be absent, and these cannot be: it would produce a record that parses cleanly and reads, to a mining pass, as a host where the measurement did not apply. Replace the `usize` round-trip carrying handles into the handshake thread with a named `Send` carrier. The review suggested capturing `HANDLE` directly; that does not compile -- `HANDLE` is `*mut c_void` and therefore `!Send` -- but the complaint under it is right, because the cast asserts "safe to move across threads" with no `unsafe` anywhere near the assertion. The carrier puts the `unsafe impl` and its justification where the claim is made. Worth knowing for anyone repeating this: a newtype alone is not enough. Under edition 2021 precise capture, mentioning `carrier.0` inside the closure captures the `!Send` *field* and the wrapper's impl never applies -- the first attempt failed with the identical error it was meant to fix. The carrier exposes a `take(self)` method so the capture is the whole value. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../src/bin/doorbell_cost.rs | 36 ++++-- .../src/bin/request_cost.rs | 26 ++-- .../src/bin/topology.rs | 19 ++- .../src/doorbell_cost.rs | 122 ++++++++++++++++-- 4 files changed, 164 insertions(+), 39 deletions(-) diff --git a/crates/windows-platform-probes/src/bin/doorbell_cost.rs b/crates/windows-platform-probes/src/bin/doorbell_cost.rs index b6c0c6c88..382495ab4 100644 --- a/crates/windows-platform-probes/src/bin/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/bin/doorbell_cost.rs @@ -13,22 +13,19 @@ //! can wait for evidence that it is worth its lost-wakeup risk. use std::fmt::Write as _; -use windows_platform_probes::doorbell_cost::{Observation, measure, measure_park_and_wake}; +use windows_platform_probes::doorbell_cost::{measure, measure_park_and_wake}; -use windows_platform_probes::report::{Stdout, emit}; +use windows_platform_probes::report::emit_report; fn main() { - // The only place that names the real stream. Everything above composes - // text; nothing above knows where it goes. - emit( - &mut Stdout, - &render(&measure(), measure_park_and_wake(20_000)), - ); + // 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(observation: &Observation, park: Option) -> String { - let mut out = String::new(); +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 @@ -43,6 +40,24 @@ fn render(observation: &Observation, park: Option) -> String { "== what does a doorbell cost, against the syscall it guards? ==\n" ); + // Measured HERE, after the banner is already in the buffer, and not in + // `main`'s argument list where it used to sit. + // + // `emit_report` prints whatever was composed before a panic, which is the + // property that makes a probe diagnosable rather than merely correct. A + // measurement called in the argument position runs before the renderer is + // ever entered, so it was outside that protection entirely: a panic left + // the reader with no banner, no heading, and no indication of which probe + // had died. + // + // This matters more than it did. Both measurements below now assert every + // status they take, so the panic surface they present is deliberately much + // larger than when this `main` was written -- adding loud failures to a + // probe while leaving it outside the mechanism that reports them is half a + // change. + let observation = &measure(); + let park = measure_park_and_wake(20_000); + let _ = writeln!(out, "{:<30} {:>12}", "operation", "ns/op"); for timing in &observation.timings { let _ = writeln!(out, "{:<30} {:>12.1}", timing.label, timing.nanos_per_op); @@ -303,5 +318,4 @@ fn render(observation: &Observation, park: Option) -> String { .doorbell_over_empty_submit() .map_or("null".to_string(), |s| format!("{s:.4}")), ); - out } diff --git a/crates/windows-platform-probes/src/bin/request_cost.rs b/crates/windows-platform-probes/src/bin/request_cost.rs index d696f1a10..558fb2a91 100644 --- a/crates/windows-platform-probes/src/bin/request_cost.rs +++ b/crates/windows-platform-probes/src/bin/request_cost.rs @@ -11,7 +11,7 @@ //! mechanics or the request's allocation model deserves the attention. use std::fmt::Write as _; -use windows_platform_probes::report::{Stdout, emit}; +use windows_platform_probes::report::emit_report; use windows_platform_probes::request_cost::measure; /// Measured by `probe-doorbell-cost` on a **Snapdragon X2 (ARM64)** machine, @@ -42,14 +42,14 @@ const DOORBELL_NS_REFERENCE: f64 = 164.9; const ATOMIC_NS_REFERENCE: f64 = 7.2; fn main() { - // The only place that names the real stream. Everything below composes - // text; nothing below knows where it goes. - emit(&mut Stdout, &render()); + // 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() -> String { - let mut out = String::new(); +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 @@ -359,10 +359,19 @@ fn render() -> String { ); } + // `expect`, not `null`. Every label below is recorded unconditionally by + // `measure`, so a lookup that misses means a label was renamed on one side + // and not the other -- a defect in this probe, not a condition of the host. + // + // `null` is the right answer for a value that can legitimately be absent, + // and none of these can be. Letting them say "absent" would have produced a + // partially populated record that parses cleanly and reads, to a mining + // pass, as a host on which the measurement did not apply. let get = |label: &str| { - observation + let ns = observation .get(label) - .map_or("null".to_string(), |n| format!("{n:.1}")) + .unwrap_or_else(|| panic!("measure always records {label}")); + format!("{ns:.1}") }; let _ = writeln!( out, @@ -380,5 +389,4 @@ fn render() -> String { get("capture_handle"), get("close_handle"), ); - out } diff --git a/crates/windows-platform-probes/src/bin/topology.rs b/crates/windows-platform-probes/src/bin/topology.rs index 52e44dd6a..1b1191cac 100644 --- a/crates/windows-platform-probes/src/bin/topology.rs +++ b/crates/windows-platform-probes/src/bin/topology.rs @@ -14,14 +14,23 @@ //! rather than read by eye. use windows_placement_probe::fingerprint::Fingerprint; -use windows_platform_probes::report::{Stdout, emit}; +use windows_platform_probes::report::emit_report; use windows_platform_probes::topology::measure; use windows_platform_probes::topology_report::{attribution, report, report_unmeasured}; fn main() { - // The only place that names the real stream, and the only place that reads - // the host. The text is composed in the library so every branch of it can - // be driven from a test -- see `topology_report`. + // `emit_report`, like every other probe. This used to call `emit` with a + // fully composed `String`, which gave up the one thing `emit_report` is for: + // printing what was already established when a later step panics. The three + // host reads below are exactly the steps that can, so the bypass removed the + // protection at the only place it would have been used. + emit_report(render); +} + +/// The probe's whole report, as text. +fn render(out: &mut String) { + // The only place that reads the host. The text is composed in the library so + // every branch of it can be driven from a test -- see `topology_report`. // // The banner is read FIRST and passed in. It runs a topology discovery of // its own, so leaving it to the renderer made the library half depend on a @@ -46,5 +55,5 @@ fn main() { Ok(observation) => report(&banner, &observation), Err(error) => report_unmeasured(&banner, &error), }; - emit(&mut Stdout, &text); + out.push_str(&text); } diff --git a/crates/windows-platform-probes/src/doorbell_cost.rs b/crates/windows-platform-probes/src/doorbell_cost.rs index 522ecc62a..717520de4 100644 --- a/crates/windows-platform-probes/src/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/doorbell_cost.rs @@ -216,22 +216,50 @@ pub fn measure() -> Observation { // `atomic_fetch_add` above is not an exception: `fetch_add` returns no // status, so there is nothing to check. + // Every message below carries `last_os_error()`. A probe that panics in CI + // is read from a log by someone who cannot rerun it under a debugger, and + // "SetEvent failed" tells them nothing they could not already see; the code + // distinguishes an invalid handle from a resource limit. The format + // arguments are evaluated only when the assertion fires, so this costs + // nothing in the timed loops. + // Leave it signalled, so every call in the next loop is redundant. - assert!(unsafe { SetEvent(event) } != 0, "SetEvent failed"); + assert!( + unsafe { SetEvent(event) } != 0, + "SetEvent failed: {}", + std::io::Error::last_os_error() + ); timings.push(time_loop("set_event_already_signalled", ITERATIONS, || { assert!( unsafe { SetEvent(event) } != 0, - "SetEvent on an already-signalled event failed" + "SetEvent on an already-signalled event failed: {}", + std::io::Error::last_os_error() ); })); - assert!(unsafe { ResetEvent(event) } != 0, "ResetEvent failed"); + assert!( + unsafe { ResetEvent(event) } != 0, + "ResetEvent failed: {}", + std::io::Error::last_os_error() + ); timings.push(time_loop("set_reset_event", ITERATIONS, || unsafe { - assert!(SetEvent(event) != 0, "SetEvent failed mid-cycle"); - assert!(ResetEvent(event) != 0, "ResetEvent failed mid-cycle"); + assert!( + SetEvent(event) != 0, + "SetEvent failed mid-cycle: {}", + std::io::Error::last_os_error() + ); + assert!( + ResetEvent(event) != 0, + "ResetEvent failed mid-cycle: {}", + std::io::Error::last_os_error() + ); })); - assert!(unsafe { SetEvent(event) } != 0, "SetEvent failed"); + assert!( + unsafe { SetEvent(event) } != 0, + "SetEvent failed: {}", + std::io::Error::last_os_error() + ); timings.push(time_loop("wait_zero_signalled", ITERATIONS, || { // `assert_eq`, not "did not fail". The label says *satisfied* wait, and // `WAIT_TIMEOUT` is a successful return that times a different path -- @@ -240,18 +268,27 @@ pub fn measure() -> Observation { assert_eq!( unsafe { WaitForSingleObject(event, 0) }, WAIT_OBJECT_0, - "a zero-timeout wait did not observe the event as signalled" + "a zero-timeout wait did not observe the event as signalled: {}", + std::io::Error::last_os_error() ); })); unsafe { - assert!(ResetEvent(event) != 0, "ResetEvent failed"); + assert!( + ResetEvent(event) != 0, + "ResetEvent failed: {}", + std::io::Error::last_os_error() + ); // Checked as a post-condition: a close that fails means the handle was // already invalid, which retroactively discredits every figure above // it. That is not theoretical -- in the bad-handle run described above, // with every other check stripped out, this was the one that caught it. // It is the backstop for a handle that goes bad in a way no individual // call happens to report. - assert!(CloseHandle(event) != 0, "CloseHandle failed"); + assert!( + CloseHandle(event) != 0, + "CloseHandle failed: {}", + std::io::Error::last_os_error() + ); } // The syscall the doorbell would be amortised against. Far fewer @@ -332,11 +369,60 @@ pub fn measure_park_and_wake(rounds: u32) -> Option { // SAFETY: two auto-reset, initially-unsignalled, unnamed events. let ping: HANDLE = unsafe { CreateEventW(std::ptr::null(), 0, 0, std::ptr::null()) }; let pong: HANDLE = unsafe { CreateEventW(std::ptr::null(), 0, 0, std::ptr::null()) }; - assert!(!ping.is_null() && !pong.is_null(), "CreateEventW failed"); + assert!( + !ping.is_null() && !pong.is_null(), + "CreateEventW failed: {}", + std::io::Error::last_os_error() + ); + + // A named `Send` carrier, where this used to round-trip the handles through + // `usize` and cast them back inside the thread. + // + // `HANDLE` is `*mut c_void`, so it is `!Send` and `thread::spawn` refuses + // it -- capturing the handles directly does not compile. Some carrier is + // therefore required, and the question is only which one says what it is + // doing. The `usize` cast worked but laundered the claim: it asserts "these + // are safe to move across a thread boundary" with no `unsafe` anywhere near + // the assertion, so nothing prompts a reader to check it. Naming the type + // puts the `unsafe impl` and its justification at the point the claim is + // actually made. + // + // SAFETY: a Win32 event `HANDLE` is a process-wide kernel object reference, + // not thread-affine -- `SetEvent`/`WaitForSingleObject` may be called on it + // from any thread. These two are created above, are used by this thread + // only until the join below, and are closed only after that join, so the + // reference stays valid for the whole of the peer's life. + struct SendHandles { + ping: HANDLE, + pong: HANDLE, + } + // SAFETY: as argued directly above. + unsafe impl Send for SendHandles {} + + impl SendHandles { + /// Take both handles, consuming the carrier. + /// + /// This exists to force the closure below to capture the carrier *as a + /// whole*, and it is not decoration. Under edition 2021's precise + /// capture a closure captures the individual **fields** it mentions, so + /// writing `carriers.ping` inside the closure captures a bare `HANDLE` + /// -- which is `!Send` -- and the wrapper's `unsafe impl Send` never + /// enters the picture. The first version of this did exactly that and + /// failed to compile with the same error the `usize` cast was replacing. + /// + /// A method call needs the whole receiver, so the capture is the carrier + /// and the `Send` impl applies. Anyone "simplifying" this back to field + /// access will be told by the compiler, which is the good outcome; this + /// note is here so they know why rather than reaching for the cast. + fn take(self) -> (HANDLE, HANDLE) { + (self.ping, self.pong) + } + } + + let carriers = SendHandles { ping, pong }; - let (ping_addr, pong_addr) = (ping as usize, pong as usize); let peer = std::thread::spawn(move || { - let (ping, pong) = (ping_addr as HANDLE, pong_addr as HANDLE); + let (ping, pong) = carriers.take(); for _ in 0..rounds { // SAFETY: both handles outlive this thread, which is joined below. let waited = unsafe { WaitForSingleObject(ping, WAIT_TIMEOUT_MS) }; @@ -378,8 +464,16 @@ pub fn measure_park_and_wake(rounds: u32) -> Option { let peer_ok = peer.join().unwrap_or(false); // SAFETY: the peer has been joined, so nothing else holds these. unsafe { - assert!(CloseHandle(ping) != 0, "CloseHandle(ping) failed"); - assert!(CloseHandle(pong) != 0, "CloseHandle(pong) failed"); + assert!( + CloseHandle(ping) != 0, + "CloseHandle(ping) failed: {}", + std::io::Error::last_os_error() + ); + assert!( + CloseHandle(pong) != 0, + "CloseHandle(pong) failed: {}", + std::io::Error::last_os_error() + ); } (ok && peer_ok).then(|| elapsed.as_nanos() as f64 / f64::from(rounds)) From 492647c477a77f99ce90666f8ba4b98de3ddb887 Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 14:18:59 -0400 Subject: [PATCH 11/17] docs(platform-probes): attribute disjoint capture to RFC 2229, not to edition 2021 The `SendHandles::take` note explained the closure-capture behaviour as "under edition 2021's precise capture", which reads as though this crate were on that edition. It is not: the workspace declares `edition = "2024"` in `[workspace.package]` and every crate inherits it. The behaviour is RFC 2229 disjoint closure capture, introduced *in* edition 2021 and in force in every edition since, including the 2024 this code compiles under. Naming the RFC rather than an edition says what actually governs, and removes the implication that a reader on 2024 can disregard it -- which would be exactly the wrong conclusion, since it is the reason the carrier needs a method instead of a field access. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- crates/windows-platform-probes/src/doorbell_cost.rs | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/crates/windows-platform-probes/src/doorbell_cost.rs b/crates/windows-platform-probes/src/doorbell_cost.rs index 717520de4..1c4ecc569 100644 --- a/crates/windows-platform-probes/src/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/doorbell_cost.rs @@ -403,12 +403,13 @@ pub fn measure_park_and_wake(rounds: u32) -> Option { /// Take both handles, consuming the carrier. /// /// This exists to force the closure below to capture the carrier *as a - /// whole*, and it is not decoration. Under edition 2021's precise - /// capture a closure captures the individual **fields** it mentions, so - /// writing `carriers.ping` inside the closure captures a bare `HANDLE` - /// -- which is `!Send` -- and the wrapper's `unsafe impl Send` never - /// enters the picture. The first version of this did exactly that and - /// failed to compile with the same error the `usize` cast was replacing. + /// whole*, and it is not decoration. Under disjoint closure capture + /// (RFC 2229, introduced in edition 2021 and in force here in 2024) a + /// closure captures the individual **fields** it mentions, so writing + /// `carriers.ping` inside the closure captures a bare `HANDLE` -- which + /// is `!Send` -- and the wrapper's `unsafe impl Send` never enters the + /// picture. The first version of this did exactly that and failed to + /// compile with the same error the `usize` cast was replacing. /// /// A method call needs the whole receiver, so the capture is the carrier /// and the `Send` impl applies. Anyone "simplifying" this back to field From c6684cff446191760a8a98efa2c86c04d40fc01f Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 14:38:32 -0400 Subject: [PATCH 12/17] fix(platform-probes): check each event creation on its own, and record why the drive test fails loudly Two findings from Copilot review on #83. One is a real leak-and-misreport that the previous commit introduced; the other is declined, with the reasoning recorded at the site so it is not re-raised a fourth time. `measure_park_and_wake` created both events and checked them with a single combined assertion. That leaked: with `ping` created and `pong` failing, it panicked without closing `ping`. It also misreported, and the misreport is the more interesting half -- `last_os_error()` was read after *both* calls, so a failure of the first was overwritten by the success of the second and the message could read "CreateEventW failed: The operation completed successfully". That defect was introduced by `bdc45cc`, which added `last_os_error()` to every assertion in the file precisely to improve diagnosis. Attaching an error code to a condition spanning two calls does not improve a diagnosis, it fabricates one: the code belongs to whichever call ran last, not to whichever failed. The rule this yields is now stated at the site -- an error code is only meaningful read immediately after the single call whose failure is being reported -- and the close in the new failure path reads its own rather than reusing an earlier one. Swept the file for the same shape. One more, milder, in `request_cost`: `GetSystemDirectoryW`'s retry asserted `retried != 0 && retried < heap.len()` with one error code, where only the first half is an OS failure and the second means the directory grew between calls. Split into two assertions so neither carries an error code that would be fiction. Declined: skipping the drive-letter test when no letter is free. libtest has no runtime skip, so a test that skips is a test that PASSES -- and this is the test pinning the claim that `prepare` needs no volume, which makes a pass that established nothing the one outcome worth avoiding. It is the same vacuous-green hazard as the unchecked `GetLogicalDrives` fixed in `c0a0021`. It also matches what this crate already does with the identical condition: two device-map tests `panic!("no free drive letter on this host, so the probe cannot run")` while searching only `H..=Z`, where this searches all 26 and so fails strictly less often. The condition needs `A` and `B` mounted too, which is essentially unreachable. The message now says plainly that it is an environment limitation rather than a failure of the behaviour under test. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../src/doorbell_cost.rs | 37 +++++++++++++++++-- .../src/request_cost.rs | 11 +++++- crates/windows-platform-probes/src/tests.rs | 25 ++++++++++++- 3 files changed, 67 insertions(+), 6 deletions(-) diff --git a/crates/windows-platform-probes/src/doorbell_cost.rs b/crates/windows-platform-probes/src/doorbell_cost.rs index 1c4ecc569..fd173b7e0 100644 --- a/crates/windows-platform-probes/src/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/doorbell_cost.rs @@ -366,15 +366,44 @@ pub fn measure_park_and_wake(rounds: u32) -> Option { return None; } - // SAFETY: two auto-reset, initially-unsignalled, unnamed events. + // Created and checked ONE AT A TIME, which the combined assertion this + // replaces could not do. That assertion leaked: with `ping` created and + // `pong` failing, it panicked without closing `ping`. Worse, it misreported + // -- `last_os_error()` was read after *both* calls, so the failure of the + // first was overwritten by the success of the second, and the message could + // read "CreateEventW failed: The operation completed successfully". + // + // That is a defect introduced by the previous commit, which added + // `last_os_error()` to every assertion in this file for diagnosability. + // Attaching an error code to a condition spanning two calls does not improve + // the diagnosis, it fabricates one: the code belongs to whichever call ran + // last, not to whichever failed. **An error code is only meaningful read + // immediately after the single call whose failure is being reported**, which + // is why the close below reads its own separately rather than reusing this. + + // SAFETY: an auto-reset, initially-unsignalled, unnamed event. let ping: HANDLE = unsafe { CreateEventW(std::ptr::null(), 0, 0, std::ptr::null()) }; - let pong: HANDLE = unsafe { CreateEventW(std::ptr::null(), 0, 0, std::ptr::null()) }; assert!( - !ping.is_null() && !pong.is_null(), - "CreateEventW failed: {}", + !ping.is_null(), + "CreateEventW(ping) failed: {}", std::io::Error::last_os_error() ); + // SAFETY: as above. + let pong: HANDLE = unsafe { CreateEventW(std::ptr::null(), 0, 0, std::ptr::null()) }; + if pong.is_null() { + // Read before the close, which would overwrite it. + let error = std::io::Error::last_os_error(); + // SAFETY: `ping` was created above and nothing else holds it. + let closed = unsafe { CloseHandle(ping) }; + assert!( + closed != 0, + "CreateEventW(pong) failed ({error}), and closing ping then also failed: {}", + std::io::Error::last_os_error() + ); + panic!("CreateEventW(pong) failed: {error}"); + } + // A named `Send` carrier, where this used to round-trip the handles through // `usize` and cast them back inside the thread. // diff --git a/crates/windows-platform-probes/src/request_cost.rs b/crates/windows-platform-probes/src/request_cost.rs index 072edd012..1f7bedf52 100644 --- a/crates/windows-platform-probes/src/request_cost.rs +++ b/crates/windows-platform-probes/src/request_cost.rs @@ -326,11 +326,20 @@ fn system_directory() -> std::path::PathBuf { let mut heap = vec![0_u16; written]; // SAFETY: writes at most `heap.len()` units into a buffer of that size. let retried = unsafe { GetSystemDirectoryW(heap.as_mut_ptr(), heap.len() as u32) } as usize; + + // Two conditions, two assertions, because only one of them is an OS + // failure and an error code attached to the other would be fiction -- + // `GetLastError` is not meaningful for a call that returned a size. assert!( - retried != 0 && retried < heap.len(), + retried != 0, "GetSystemDirectoryW failed at the size it asked for ({written}): {}", std::io::Error::last_os_error() ); + assert!( + retried < heap.len(), + "GetSystemDirectoryW asked for {written} units, then wanted {retried} \ + at that size -- the system directory changed between the two calls" + ); return std::path::PathBuf::from(os_string(&heap[..retried])); } diff --git a/crates/windows-platform-probes/src/tests.rs b/crates/windows-platform-probes/src/tests.rs index 68799d722..737087fea 100644 --- a/crates/windows-platform-probes/src/tests.rs +++ b/crates/windows-platform-probes/src/tests.rs @@ -4389,10 +4389,33 @@ fn preparing_a_path_needs_no_volume_behind_its_drive_letter() { // is no letter worth reserving by hand: starting at `D` only narrowed the // search on a machine with many mapped drives, for no benefit, since `C` // being in use is exactly what the mask reports. + // Fails rather than skips when no letter is free, which is deliberate and + // has been raised in review, so the reasoning is recorded here. + // + // libtest has no runtime skip: a test that "skips" is a test that PASSES. + // This is the test pinning the claim that `prepare` needs no volume, so a + // pass that established nothing is the one outcome worth avoiding -- the + // same vacuous-green hazard as the unchecked `GetLogicalDrives` above, which + // is what made the explicit check necessary in the first place. + // + // It also matches how this crate already handles the identical condition: + // `impersonation_changes_which_device_map_a_drive_letter_resolves_in` and + // its sibling both `panic!("no free drive letter on this host, so the probe + // cannot run")`, and they search only `H..=Z`. This search covers all 26, so + // it fails strictly less often than sites that already chose to fail. + // + // The condition needs every letter mounted including `A` and `B`, which are + // floppy-era and essentially never assigned. A host in that state is worth + // hearing about loudly, and the message says plainly that it is the + // environment rather than the code. let absent = (b'A'..=b'Z') .find(|&byte| used & (1 << u32::from(byte - b'A')) == 0) .map(char::from) - .expect("every drive letter A-Z is in use, so this test cannot run here"); + .expect( + "every drive letter A-Z is mounted on this host, so no unmounted \ + letter exists to test against -- an environment limitation, not a \ + failure of the behaviour under test", + ); let text = format!(r"{absent}:\{}\file.txt", vec!["directory"; 24].join("\\")); let path = wtf_string::Wtf16String::from(text.as_str()); From 4f50485d21f23560c89f8533e7b4524b17626a14 Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 14:46:30 -0400 Subject: [PATCH 13/17] fix(platform-probes): carry the OS error on the last bare assertion, and guard the new CI steps Both findings from Copilot review on #83, and both were siblings walked past rather than new ground. `measure`'s `CreateEventW` assertion was the one site in this file still saying only "CreateEventW failed". `bdc45cc` added `last_os_error()` to every other assertion here and `c6684cf` fixed the creation pair in `measure_park_and_wake`; this one sat between the two sweeps and neither reached it. The CI steps for both new probes lacked `if: '!cancelled()'`, so Actions' default `if: success()` skips them whenever an earlier step in the job fails. The reason that is wrong is already written four lines above them, at the topology step: a probe step exists to emit diagnostics, so skipping it on failure suppresses it in exactly the run that wanted it. The argument was general and had been applied to one step. It matters more for these two than for a pass/fail probe. Both now assert every status they take and panic on a missing NDJSON label, and both route through `emit_report`, which prints what was composed before a panic -- machinery that only reaches a reader if the step runs at all. This branch spent several commits making these probes fail loudly and then left them in the one configuration where the failure is not printed. Two sweeps are queued rather than taken, because both reach beyond this peel: M2.7 -- nine of the twelve probe steps in CI are still unguarded, including the long-path pair, whose own comment says either half alone "says nothing" since the finding is the difference between two executables. Queued rather than changed because `!cancelled()` also runs a step when the *build* failed, turning skipped into failed, which trades quieter broken-build output for better broken-test output. The topology step took that trade; whether all twelve should is an operational judgement about how the log is read. M2.8 -- four assertion messages in probes this peel did not touch still name what was attempted without saying why it failed. The item carries the two rules this peel learned expensively: read the error immediately after the single call whose failure is reported, and attach one only where the condition is genuinely an OS failure. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .github/workflows/ci.yml | 14 +++++++ crates/windows-platform-probes/CHECKLIST.md | 37 +++++++++++++++++++ .../src/doorbell_cost.rs | 6 ++- 3 files changed, 56 insertions(+), 1 deletion(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 907ed1a51..41f6a149a 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -285,11 +285,25 @@ jobs: # first version of it deadlocked, because an auto-reset event does not # count signals and the waiter's count never caught up. A probe that can # hang is a probe that can hang a build. + # + # `if: '!cancelled()'` for the same reason the topology step above carries + # it, and the reason is not specific to topology: a probe step exists to + # produce diagnostic output, so skipping it because an earlier step failed + # suppresses it in precisely the run that wanted it. The test step above + # covers both of these probes, and a host where those tests fail is a host + # whose timings are worth reading. + # + # It matters more for these two than for a pass/fail probe. Both now assert + # every status they take and panic on a missing NDJSON label, and both go + # through `emit_report`, which prints what was already established before a + # panic -- machinery that only reaches a reader if the step runs at all. - name: probe magnitudes (doorbell cost) + if: '!cancelled()' run: cargo run -p windows-platform-probes --bin probe-doorbell-cost --locked --release # Read with the doorbell probe above: together they say whether the # queue's mechanics or the request's own cost deserves the attention. - name: probe magnitudes (request cost) + if: '!cancelled()' run: cargo run -p windows-platform-probes --bin probe-request-cost --locked --release # Both halves of the long-path pair, deliberately. Either alone says # nothing: the finding is the *difference* between two executables that diff --git a/crates/windows-platform-probes/CHECKLIST.md b/crates/windows-platform-probes/CHECKLIST.md index 216014a09..f7b33dbc6 100644 --- a/crates/windows-platform-probes/CHECKLIST.md +++ b/crates/windows-platform-probes/CHECKLIST.md @@ -169,3 +169,40 @@ speculative list to extend by imagination -- a fourth is added when a fourth con all on any path this crate takes. The probe measured ~212 ns for a build on x86_64 and declines to say what that is made of; the owning crate could say, and a reader of either would then stop guessing. + +- [ ] **M2.7** -- Decide whether the other nine probe steps in CI should carry `if: '!cancelled()'`, + and apply or record the decision. + + **Measured 2026-09-09:** twelve probe steps in [ci.yml](../../.github/workflows/ci.yml), of which + three are guarded -- topology, and the doorbell/request pair added with this note. The other nine + (`error mode`, `handle state`, `worker context`, `pool growth`, `device map`, `IoRing`, + `completion port`, and both halves of the long-path pair) are skipped whenever an earlier step in + the job fails, because Actions defaults to `if: success()`. + + The argument for guarding is already written at the topology step and is not specific to it: a + probe step exists to emit diagnostics, so skipping it on failure suppresses it in exactly the run + that wanted it. **The long-path pair is the sharpest case** -- its own comment says either half + alone "says nothing", since the finding is the difference between two executables, so a partial + run of that pair is worse than useless. + + **It is queued rather than done because there is a real tradeoff, and it is an operational call.** + `!cancelled()` also runs the step when the *build* failed, where `cargo run` cannot compile and + the step turns from skipped (grey) into failed (red). That trades quieter broken-build output for + better broken-test output. The topology step already took that trade; whether all twelve should is + a judgement about how the CI log is read, not something to settle by consistency alone. + +- [ ] **M2.8** -- Carry the OS error in the remaining Win32 assertion messages. + + `last_os_error()` (or a raw `GetLastError`) is in the messages in `doorbell_cost`, `request_cost` + and `handle_state`, and missing from four sites in probes this peel did not touch: + `completion_port.rs:224` and `:234` ("create a completion port"), `ioring.rs:320` ("create the + probe pipe"), and `pool_growth.rs:62` ("create the gate event"). Each says what was being attempted + and not why it failed, which is the whole of what a CI log can offer someone who cannot rerun under + a debugger. + + Two rules worth carrying over, both learned the expensive way in this peel. Read the error + **immediately after the single call whose failure is reported** -- a code attached to a condition + spanning two calls belongs to whichever ran last, not whichever failed, and can print "The + operation completed successfully" under a message saying something failed. And attach it only to a + condition that is genuinely an OS failure: a call that returned a size rather than an error should + not carry one, since `GetLastError` says nothing about it. diff --git a/crates/windows-platform-probes/src/doorbell_cost.rs b/crates/windows-platform-probes/src/doorbell_cost.rs index fd173b7e0..a7d32deb6 100644 --- a/crates/windows-platform-probes/src/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/doorbell_cost.rs @@ -168,7 +168,11 @@ pub fn measure() -> Observation { // SAFETY: a manual-reset, initially-unsignalled, unnamed event. let event: HANDLE = unsafe { CreateEventW(std::ptr::null(), 1, 0, std::ptr::null()) }; - assert!(!event.is_null(), "CreateEventW failed"); + assert!( + !event.is_null(), + "CreateEventW failed: {}", + std::io::Error::last_os_error() + ); let counter = AtomicU64::new(0); let mut timings = Vec::new(); From b90d897d1a9d12934972cbda0f990afb768ea2ac Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 15:08:57 -0400 Subject: [PATCH 14/17] docs(platform-probes): state the handshake test's real bound instead of claiming none The liveness test said a loaded machine "may make each round arbitrarily slow without making it wrong". It may not. Each wait inside `measure_park_and_wake` carries a 5-second timeout, and a round that exceeds it makes the handshake return `None` and fails the `expect` on the following line. The claim was contradicted twice within a few lines of being made: the section header directly above states the 5-second bound correctly and gives the reason for it, and the `expect` message on the next line reads "a bounded handshake of 64 rounds must complete rather than time out". Both were right; only this sentence was wrong, which is why nothing caught it -- each statement is locally true and only the pair is contradictory. Reworded to say what the code does, and to keep the reason the bound exists: a test that can hang takes the whole suite with it, which is worse than the defect it guards. The margin is enormous -- a sub-microsecond round trip against a 5-second ceiling -- so a failure means the machine stalled for seconds, which is worth a red test rather than a silently slow pass. Swept the crate for other unbounded-tolerance claims; this was the only one. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- crates/windows-platform-probes/src/tests.rs | 18 ++++++++++++++++-- 1 file changed, 16 insertions(+), 2 deletions(-) diff --git a/crates/windows-platform-probes/src/tests.rs b/crates/windows-platform-probes/src/tests.rs index 737087fea..e95abd376 100644 --- a/crates/windows-platform-probes/src/tests.rs +++ b/crates/windows-platform-probes/src/tests.rs @@ -4329,8 +4329,22 @@ fn a_small_handshake_completes_and_reports_a_positive_round_trip() { // The liveness half: the two-event alternation actually runs to completion // and produces a number. Deliberately few rounds -- this is a real // cross-thread measurement, and the assertion is that it terminates and is - // sane, not that it is fast. A machine under load may make each round - // arbitrarily slow without making it wrong. + // sane, not that it is fast. + // + // The tolerance for a loaded machine is large but **bounded**, and this once + // said "arbitrarily slow without making it wrong", which is not true of the + // code it describes. Each wait inside the handshake carries a 5-second + // timeout; a round that exceeds it makes `measure_park_and_wake` return + // `None` and fails the `expect` below. The section header above states that + // bound correctly and the `expect` message names it outright, so the claim + // was contradicted twice within a few lines of making it. + // + // Bounded is the deliberate choice, for the reason in that header: a test + // that can hang takes the whole suite with it, which is worse than the + // defect it guards against. The margin is enormous -- a round trip is + // sub-microsecond in practice against a 5-second ceiling -- so a failure + // here means the machine stalled for seconds, which is worth a red test + // rather than a silently slow pass. let average = crate::doorbell_cost::measure_park_and_wake(64) .expect("a bounded handshake of 64 rounds must complete rather than time out"); From e03d88b39c2d367de9a6b1222c52e5cdfdaffd14 Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 15:36:28 -0400 Subject: [PATCH 15/17] fix(platform-probes): report a wait result, not a last-error that does not describe it `WaitForSingleObject` is the one call in this file that returns a status code rather than a `BOOL`, and only `WAIT_FAILED` sets the last-error value. `WAIT_TIMEOUT` and `WAIT_ABANDONED` are *successful* returns, so the `last_os_error()` printed beside them belonged to whatever call ran previously and described something else. This is the rule the last two commits arrived at -- attach an error only where the condition is genuinely an OS failure -- broken in the same file that states it. The sweep that added `last_os_error()` to every assertion here treated a status-returning call like the `BOOL`-returning ones around it, which is how a rule about reporting failures became a way to report a failure that did not happen. That is the second time on this branch that a diagnosability sweep introduced a wrong diagnosis, after the combined `CreateEventW` assertion. The wait result now goes through `describe_wait`, which names the code and attaches `last_os_error()` only for `WAIT_FAILED`. Swept the crate: the other two `WaitForSingleObject` calls here compare and return without claiming an error, and `pool_growth`'s discards its result entirely, which belongs to the workspace audit rather than this peel. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../src/doorbell_cost.rs | 54 +++++++++++++++---- 1 file changed, 45 insertions(+), 9 deletions(-) diff --git a/crates/windows-platform-probes/src/doorbell_cost.rs b/crates/windows-platform-probes/src/doorbell_cost.rs index a7d32deb6..00062dddc 100644 --- a/crates/windows-platform-probes/src/doorbell_cost.rs +++ b/crates/windows-platform-probes/src/doorbell_cost.rs @@ -69,7 +69,9 @@ use std::sync::atomic::{AtomicU64, Ordering}; use std::time::Instant; -use windows_sys::Win32::Foundation::{CloseHandle, HANDLE, WAIT_OBJECT_0}; +use windows_sys::Win32::Foundation::{ + CloseHandle, HANDLE, WAIT_ABANDONED, WAIT_EVENT, WAIT_FAILED, WAIT_OBJECT_0, WAIT_TIMEOUT, +}; use windows_sys::Win32::System::Threading::{ CreateEventW, ResetEvent, SetEvent, WaitForSingleObject, }; @@ -149,6 +151,27 @@ fn time_loop(label: &'static str, iterations: u32, mut body: impl FnMut()) -> Ti } } +/// Name a wait result, and attach an OS error only where one exists. +/// +/// `WaitForSingleObject` returns a status code rather than a `BOOL`, and only +/// `WAIT_FAILED` sets the last-error value. `WAIT_TIMEOUT` and `WAIT_ABANDONED` +/// are *successful* returns, so a code printed beside either belongs to +/// whatever call ran previously and describes something else entirely -- which +/// is worse than printing nothing, because it reads as a diagnosis. +fn describe_wait(waited: WAIT_EVENT) -> String { + match waited { + WAIT_OBJECT_0 => "WAIT_OBJECT_0 (signalled)".to_string(), + WAIT_TIMEOUT => { + "WAIT_TIMEOUT -- the event was not signalled; this is not an OS error".to_string() + } + WAIT_ABANDONED => { + "WAIT_ABANDONED -- a mutex owner exited; this is not an OS error".to_string() + } + WAIT_FAILED => format!("WAIT_FAILED: {}", std::io::Error::last_os_error()), + other => format!("unrecognised wait result {other:#010x}"), + } +} + /// Run every timing. /// /// # Panics @@ -265,15 +288,28 @@ pub fn measure() -> Observation { std::io::Error::last_os_error() ); timings.push(time_loop("wait_zero_signalled", ITERATIONS, || { - // `assert_eq`, not "did not fail". The label says *satisfied* wait, and - // `WAIT_TIMEOUT` is a successful return that times a different path -- - // an unsatisfied poll, which is the cheaper one and would flatter the - // figure. - assert_eq!( - unsafe { WaitForSingleObject(event, 0) }, - WAIT_OBJECT_0, + // Checked against `WAIT_OBJECT_0`, not merely "did not fail". The label + // says *satisfied* wait, and `WAIT_TIMEOUT` is a successful return that + // times a different path -- an unsatisfied poll, which is the cheaper + // one and would flatter the figure. + // + // The error code is attached only to `WAIT_FAILED`, because that is the + // only return for which `GetLastError` is defined. `WaitForSingleObject` + // is not a boolean-returning call: `WAIT_TIMEOUT` and `WAIT_ABANDONED` + // are *successful* returns that set no error, so a code printed beside + // them belongs to whatever ran last and is fiction. + // + // This is the rule the previous commits arrived at -- attach an error + // only where the condition is genuinely an OS failure -- applied to the + // one call in this file that returns a status code rather than a + // `BOOL`. The sweep that added `last_os_error()` everywhere treated it + // like the others, which is how a rule about failure reporting became a + // way to report a failure that did not happen. + let waited = unsafe { WaitForSingleObject(event, 0) }; + assert!( + waited == WAIT_OBJECT_0, "a zero-timeout wait did not observe the event as signalled: {}", - std::io::Error::last_os_error() + describe_wait(waited) ); })); unsafe { From dc39ae345edc49576ec3e9cc9803a0365c3ba6d3 Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 15:36:50 -0400 Subject: [PATCH 16/17] docs(namespace-request): record the close-test handle-reuse flake seen in CI A CI run of PR #83 reported 96 failures in this crate. Recorded per the repository's test-tracking rule rather than left in a log, so the next occurrence is recognised instead of re-investigated. The 96 are one defect: `close::tests::a_caller_supplied_routine_is_carried` failed `assertion failed: !was_still_open(raw)` while holding the write guard on `handle_allocation()`, and the other 95 are `PoisonError` collateral from that guard. Established as intermittent rather than assumed: the same commit was re-run unchanged and passed, the crate passes 5/5 locally, and the two commits before it passed the identical job. It is also not attributable to the branch that observed it, which touches only `crates/windows-platform-probes/`, the workflow and `Cargo.lock`, and adds this crate as a dependency without changing its code. The mechanism is measured, not guessed. `was_still_open` probes a raw value by attempting to close it, and its own comment states the precondition -- that these tests hold the allocation lock. **218 tests in this crate, and 11 of them open handles without taking it.** `cargo test` runs tests as threads in one process, so a freed handle value can be reallocated by one of those 11 running concurrently, and the probe then finds it open. The entry also records what is worse than the visible assertion: `was_still_open` CLOSES the handle when the probe succeeds, so in the losing interleaving this test closes a live handle belonging to another test. The failed assertion is the benign outcome; a stranger failure elsewhere is the other one. Three directions are written down, with the observation that taking the lock in those 11 tests stops the bleeding while leaving the invariant resting on every future author remembering -- and that removing the need for the lock, by asking the close routine's own observation static rather than the OS, cannot race at all. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../UNRESOLVED-TEST-FAILURES.md | 78 +++++++++++++++++++ 1 file changed, 78 insertions(+) create mode 100644 crates/windows-namespace-request-sys/UNRESOLVED-TEST-FAILURES.md diff --git a/crates/windows-namespace-request-sys/UNRESOLVED-TEST-FAILURES.md b/crates/windows-namespace-request-sys/UNRESOLVED-TEST-FAILURES.md new file mode 100644 index 000000000..7c0f054b8 --- /dev/null +++ b/crates/windows-namespace-request-sys/UNRESOLVED-TEST-FAILURES.md @@ -0,0 +1,78 @@ +# Unresolved test failures: windows-namespace-request-sys + +Observed failures that are real but not yet diagnosed. Recorded here rather than +left in a CI log, so a later intermittent failure is recognised as a known one +instead of being re-investigated from scratch or dismissed as noise. + +When an entry is resolved, move it to a sibling +[RESOLVED-TEST-FAILURES.md](RESOLVED-TEST-FAILURES.md) under a +`## Resolved -- ` heading in the same +change that removes it from this file. Do not delete entries. + +## Observed 2026-09-09 15:35:14 -04:00 -- `close::tests` handle-value reuse poisons the allocation lock + +**Symptom.** One CI run of `cargo test --workspace` reported **96 failures** in +this crate: `close::tests::a_caller_supplied_routine_is_carried` failed with +`assertion failed: !was_still_open(raw)`, and the other 95 all failed with +`the lock is not poisoned: PoisonError { .. }`. The 95 are collateral -- the +first test panicked while holding the write guard on `handle_allocation()`, +which poisons the lock for every test that takes it afterwards. **The count is +alarming and the defect is singular.** + +**It is intermittent, and that is established rather than assumed.** The same +commit (`b90d897`) was re-run with no change and passed. The crate passes 5/5 +locally. The two commits before it passed the identical job. The commit that +"failed" was comment-only, in a different crate. + +**Mechanism, as far as it is understood.** `was_still_open` probes a raw value +by attempting to close it: + +```rust +fn was_still_open(handle: HANDLE) -> bool { + unsafe { CloseHandle(handle) != FALSE } +} +``` + +Its own comment states the precondition: "A stale value fails with +`ERROR_INVALID_HANDLE` rather than closing something else, **because these tests +hold the allocation lock**." That precondition does not hold for the whole +process. Measured on this revision: **218 tests in the crate, and 11 of them open +handles without taking `handle_allocation()`** -- among them +`open::tests::a_missing_path_reports_the_raw_code_unaltered`, +`open::tests::the_overlapped_flag_is_carried_rather_than_decided`, and +`watch::tests::a_missing_directory_reports_the_raw_code`. + +`cargo test` runs tests as threads in one process (deliberately -- see the root +[DESIGN-NOTES.md](../../DESIGN-NOTES.md)), so a handle value freed by a +lock-holding test can be immediately reallocated by one of those 11 running +concurrently. The probe then finds the value open and the assertion fails. + +**The failing assertion is not the worst of it.** `was_still_open` *closes* the +handle when the probe succeeds. So in the losing interleaving this test does not +merely mis-report -- it closes a live handle belonging to another test, which +can surface later as an unrelated failure somewhere else entirely. The visible +assertion is the benign outcome. + +**Not caused by the change that observed it.** The branch that hit this +(`mikegrier/probes-cost-pair`, PR #83) touches only +`crates/windows-platform-probes/`, `.github/workflows/ci.yml` and `Cargo.lock`; +it adds `windows-namespace-request-sys` as a *dependency* and changes none of its +code. + +**Directions for whoever picks this up**, in rough order of directness: + +1. Take the allocation lock in the 11 tests that open handles without it. This is + the smallest change and closes the measured hole, but it leaves the invariant + resting on every future test author remembering -- the same "a flat rule beats + a rule someone must remember to apply" problem recorded in the root + [DESIGN-NOTES.md](../../DESIGN-NOTES.md) for status checking. +2. Make the lock unnecessary by not probing a raw value at all. `was_still_open` + exists to answer "did the close routine actually run?", and the close routines + already have observation statics for that purpose. A probe that asks the + routine rather than the OS cannot race. +3. Failing both, make the hazard structural: have `Fixture` / `captured_duplicate` + take the read lock themselves, so opening a handle without the lock is not + something a test can do by omission. + +Direction 2 is the most promising and the largest; direction 1 would stop the +bleeding today. From 7c18511ddd29ab94f3ccf155d2c6ad2377cacbd9 Mon Sep 17 00:00:00 2001 From: Mike Grier Date: Wed, 9 Sep 2026 16:13:41 -0400 Subject: [PATCH 17/17] docs(namespace-request): correct two false claims in the flake record The record is meant to save whoever picks this up from re-deriving anything, so a claim in it that does not survive checking is worse than a gap. Two did not. **Which paths the observing branch touches.** It said "touches only `crates/windows-platform-probes/`, `.github/workflows/ci.yml` and `Cargo.lock`", which was untrue the moment it was written, because the file saying it lives under `crates/windows-namespace-request-sys/`. The claim that holds, and the one actually meant, is that the branch makes no *source* change to this crate -- verified against the diff: its only file here is this record. **That the close routines have observation statics.** They do not. That is `windows-threadpool-sys`'s pattern for its wait targets, imported here by mistake. This crate calls the real `CloseHandle` and `FindCloseChangeNotification` directly with no shim, which `src/close.rs` records as deliberate, so there is nothing currently observable to ask and `was_still_open` -- at seven sites in `close/tests.rs` -- is the only mechanism the crate has. That makes the "ask the routine, not the OS" direction substantially larger than the entry implied, since it needs a test-only routine introduced first. The directions are reordered accordingly: make the hazard structural by having the fixture helpers take the lock, so omitting it is not something a test can do, is now second and is the smallest change that stops the flake recurring. Both corrections are recorded in place rather than silently rewritten, since the entry is a diagnostic record and a reader should be able to see what it once claimed. Also adds the `RESOLVED-TEST-FAILURES.md` sibling the record links to, which did not exist -- a link broken on creation, which the repository's own cross-reference rule forbids. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- .../RESOLVED-TEST-FAILURES.md | 8 ++++ .../UNRESOLVED-TEST-FAILURES.md | 48 +++++++++++++------ 2 files changed, 42 insertions(+), 14 deletions(-) create mode 100644 crates/windows-namespace-request-sys/RESOLVED-TEST-FAILURES.md diff --git a/crates/windows-namespace-request-sys/RESOLVED-TEST-FAILURES.md b/crates/windows-namespace-request-sys/RESOLVED-TEST-FAILURES.md new file mode 100644 index 000000000..6de36bdd3 --- /dev/null +++ b/crates/windows-namespace-request-sys/RESOLVED-TEST-FAILURES.md @@ -0,0 +1,8 @@ +# Resolved test failures: windows-namespace-request-sys + +Entries moved here from [UNRESOLVED-TEST-FAILURES.md](UNRESOLVED-TEST-FAILURES.md) +once diagnosed, with what the cause turned out to be. Append-only: entries are +never deleted, so a failure that recurs can be matched against one already +understood. + +*No failures have been resolved yet.* diff --git a/crates/windows-namespace-request-sys/UNRESOLVED-TEST-FAILURES.md b/crates/windows-namespace-request-sys/UNRESOLVED-TEST-FAILURES.md index 7c0f054b8..d540476ba 100644 --- a/crates/windows-namespace-request-sys/UNRESOLVED-TEST-FAILURES.md +++ b/crates/windows-namespace-request-sys/UNRESOLVED-TEST-FAILURES.md @@ -54,10 +54,16 @@ can surface later as an unrelated failure somewhere else entirely. The visible assertion is the benign outcome. **Not caused by the change that observed it.** The branch that hit this -(`mikegrier/probes-cost-pair`, PR #83) touches only -`crates/windows-platform-probes/`, `.github/workflows/ci.yml` and `Cargo.lock`; -it adds `windows-namespace-request-sys` as a *dependency* and changes none of its -code. +(`mikegrier/probes-cost-pair`, PR #83) makes **no source change to this crate**: +its only file here is this record. Everything else it touches is +`crates/windows-platform-probes/`, `.github/workflows/ci.yml` and `Cargo.lock`, +and it takes `windows-namespace-request-sys` as a new *dependency* without +altering it. + +(An earlier revision of this paragraph said the branch touched only those three +paths, which was untrue the moment it was written -- the file stating it lives +under `crates/windows-namespace-request-sys/`. Corrected so a later reader +checking the claim against the diff finds it holds.) **Directions for whoever picks this up**, in rough order of directness: @@ -66,13 +72,27 @@ code. resting on every future test author remembering -- the same "a flat rule beats a rule someone must remember to apply" problem recorded in the root [DESIGN-NOTES.md](../../DESIGN-NOTES.md) for status checking. -2. Make the lock unnecessary by not probing a raw value at all. `was_still_open` - exists to answer "did the close routine actually run?", and the close routines - already have observation statics for that purpose. A probe that asks the - routine rather than the OS cannot race. -3. Failing both, make the hazard structural: have `Fixture` / `captured_duplicate` - take the read lock themselves, so opening a handle without the lock is not - something a test can do by omission. - -Direction 2 is the most promising and the largest; direction 1 would stop the -bleeding today. +2. Make the hazard structural rather than remembered: have `Fixture` / + `captured_duplicate` take the lock themselves, so opening a handle *without* + it is not something a test can do by omission. This is the same move as + preferring a type that discharges a rule over a rule each author must apply. +3. Make the lock unnecessary by not probing a raw value at all. `was_still_open` + exists to answer "did the close routine actually run?", and asking the routine + rather than the OS cannot race. **Note this is a bigger change than it sounds** + -- the two routines here are the real `CloseHandle` and + `FindCloseChangeNotification`, called directly with no shim (a deliberate + property, recorded in [src/close.rs](src/close.rs)), so there is nothing + currently observable to ask. It would mean introducing a test-only routine + that records into a static, which is the pattern `windows-threadpool-sys` + already uses for its wait targets -- see the root + [DESIGN-NOTES.md](../../DESIGN-NOTES.md) -> "Testing it needs per-test statics, + not one global counter", which also documents why those statics must be + per-test rather than at module scope, for exactly this concurrency reason. + +Direction 1 stops the bleeding today; direction 2 is the smallest change that +stops it recurring. Direction 3 is the most thorough and touches the most. + +(An earlier revision of this list claimed the close routines "already have +observation statics". They do not -- that is `windows-threadpool-sys`'s pattern, +imported here by mistake. `was_still_open`, used at seven sites in +`close/tests.rs`, is the only mechanism this crate has for the question.)