From 443ea81cc158b25538b09d628ae72ced0697a282 Mon Sep 17 00:00:00 2001 From: DonislawDev Date: Fri, 16 Oct 2026 23:41:34 +0200 Subject: [PATCH 1/2] test(mutation): what the first full run found - nineteen entries it did not catch, each caught now by a stronger guard or a re-anchored entry The first run of every entry in CI (745 entries, sixteen parts) came back 693 caught, 17 MISSED, 1 BROKEN, 1 BASELINE RED and 33 NOT HERE. Each of the nineteen had a cause, and each entry is caught now, measured locally with -Only. - Shim, eleven entries: the Node scenarios did not check what the old harness outside the repository did. New checks: a date built from a date's own constructor, Date() in the engine's words when the page replaced the prototype's toString, Intl formatToParts for now, Date() counted, the zone read through the engine's Date when the page replaced Date, a second install carrying a change still to come, a foreign __chronomock left as the page made it, performance.now or a timer as the first clock read past a scheduled change, the duration axis not stepping back when a correction of the wall carries it past the instant, and a page let go judged against no zone. The harness gets drift(). - The hook's first look (session_identity): the probe reached a detour before the end. Measured with a stack taken in the hook: opening a file arms a thread-pool timer inside Windows, through the timer detour, which starts the watcher while the session runs, so with the first look taken out the late read was real all the same. The probe now waits on a named mutex the test holds until the core has gone (a wait on an object is only counted), reads the clock first and writes its lines after. - The release order (cdp_attach): the fake browser answered the busy page's count the moment its release arrived, so an attacher that gave the zone back right after sending the release went through. fake_browser_paced answers a held reply once the client has gone quiet. - The window background: the cards and the base cover 46.8% and 45.5% of the window, so with the base gone the grounds still came to 50.8% and the share above half passed. No single colour outside the grounds may now cover a tenth of the window, where the largest measured is 0.5%. - wire_keys: the both-ends check of UNREACHED runs over a list that is empty today, so its two entries had nothing to judge. The check is a function with a test on a planted list, and the entries mutate the function. - The layout complaint: the known-defect list it was judged by is empty. The spill rule's test now asks for the words in the complaint, and the entry is judged by that test. - N36 (BROKEN): the decision moved to reading_shows_time, where the civil time is not in scope. The entry makes the same mistake in reading_text. - BASELINE RED: the session close test reads the sample target, which the runner did not build. A part with a C# entry now builds the whole solution, as CI does before its C# tests (with that reverted on a copy of the runner and the target taken away, the entry was BASELINE RED again). The entry asks for the release cores, and the test itself now fails when the core is missing instead of passing because nothing could start - measured, with the core taken away it passed before and fails now. Co-Authored-By: Claude Opus 5.5 --- crates/cli/src/cdp/mod.rs | 2 +- crates/cli/src/cdp/shim_exec.rs | 114 ++++++++++++++++-- crates/cli/src/cdp/shim_harness.js | 4 + crates/cli/src/cdp/ws.rs | 21 +++- crates/cli/src/cdp_attach.rs | 38 +++--- crates/cli/tests/session_identity.rs | 89 +++++++++++--- crates/cli/tests/wire_keys.rs | 33 ++++- .../BackgroundGuardTests.cs | 22 +++- gui/ChronoMock.App.Tests/LayoutGuardTests.cs | 7 +- gui/ChronoMock.App.Tests/SessionCloseTests.cs | 5 + tests/mutation/entries.json | 24 ++-- tests/mutation/mutate.ps1 | 16 ++- 12 files changed, 303 insertions(+), 72 deletions(-) diff --git a/crates/cli/src/cdp/mod.rs b/crates/cli/src/cdp/mod.rs index fb4fcf20..2b9619aa 100644 --- a/crates/cli/src/cdp/mod.rs +++ b/crates/cli/src/cdp/mod.rs @@ -27,7 +27,7 @@ pub use session::{ pub use ws::WsClient; /// The scripted browser the transport's own tests talk to, for the attacher's tests outside this module. #[cfg(test)] -pub(crate) use ws::tests::fake_browser_holding; +pub(crate) use ws::tests::{fake_browser_holding, fake_browser_paced}; /// One decoded CDP message: either a reply to a command we sent, or an event the browser pushed. pub enum Msg { diff --git a/crates/cli/src/cdp/shim_exec.rs b/crates/cli/src/cdp/shim_exec.rs index a46258e6..a36dd130 100644 --- a/crates/cli/src/cdp/shim_exec.rs +++ b/crates/cli/src/cdp/shim_exec.rs @@ -93,10 +93,11 @@ fn numbers() -> Vec<(&'static str, String)> { } /// The clocks a page reads after the shim: the wall at the session rate from the session's start, -/// `Date`, `new Date()`, `Date()` and a subclass of `Date` alike, a date given as one value or several -/// left alone (R5-WY3 builds the one-value date directly), "now" formatted by `Intl` the session's, -/// `performance.now` at the duration rate from where it stood (R4-S16), and a timer's delay divided by -/// it. +/// `Date`, `new Date()`, `Date()` and a subclass of `Date` alike, a date built from a date's own +/// constructor too (R4-W6), a date given as one value or several left alone (R5-WY3 builds the one-value +/// date directly), `Date()` in the engine's own words even when the page replaced the prototype's +/// `toString`, "now" formatted by `Intl` the session's, whole or in parts, `performance.now` at the +/// duration rate from where it stood (R4-S16), and a timer's delay divided by it. #[test] fn the_page_reads_the_session_clock_through_every_form_of_date() { let mut vars = numbers(); @@ -114,6 +115,14 @@ fn the_page_reads_the_session_clock_through_every_form_of_date() { check('a real second is a minute at x60', Date.now() === FAKE0 + 60000, Date.now() - FAKE0); check('new Date() reads it', new Date().getTime() === Date.now()); check('Date() reads it', Date() === new EngineDate(Date.now()).toString()); + check('a date names the session Date as its constructor', new Date().constructor === Date); + check('and a date built from that constructor reads it', new (new Date().constructor)().getTime() === Date.now()); + // A native Date() never calls the prototype's toString, so a page's own does not reach it. + const engineText = Date.prototype.toString; + Date.prototype.toString = function() { return 'the page own text'; }; + const said = Date(); + Date.prototype.toString = engineText; + check('Date() is the engine text, not one the page put on the prototype', said === new EngineDate(Date.now()).toString(), said); class Sub extends Date {} check('a subclass of Date stays itself', new Sub() instanceof Sub && new Sub().getTime() === Date.now()); check('a subclass given a value stays itself', new Sub(5) instanceof Sub && new Sub(5).getTime() === 5); @@ -124,6 +133,8 @@ fn the_page_reads_the_session_clock_through_every_form_of_date() { check('Date.name and Date.length are the native ones', Date.name === 'Date' && Date.length === 7); const year = new Intl.DateTimeFormat('en-US', { timeZone: 'UTC', year: 'numeric' }).format(); check('Intl formats the session clock for now', year === '2038', year); + const parts = new Intl.DateTimeFormat('en-US', { timeZone: 'UTC', year: 'numeric' }).formatToParts(); + check('and in parts', parts.some((p) => p.type === 'year' && p.value === '2038'), parts); check('performance.now runs at the duration rate', near(performance.now() - p0, 60000, 0.001), performance.now() - p0); const id = setTimeout(() => {}, 6000); check('a timer waits its delay divided by the rate', env.timers.find((t) => t.id === id).delay === 100); @@ -175,7 +186,8 @@ fn a_timer_keeps_its_delay_when_only_the_wall_runs_fast() { /// What the session sends moves the clock as the session means it: a jump moves the wall and leaves /// `performance.now` continuous, a release puts the wall back on the real clock and starts the audit -/// over, the counts come back as numbers, and the zone read answers two offsets. +/// over, the counts come back as numbers - `Date()` counted with `new Date()` (R4-S19) - and the zone +/// read answers two offsets through the engine's own `Date`, whatever the page put in its place (ADR-21). #[test] fn the_session_moves_counts_and_lets_go_of_the_page() { let fake1 = FAKE0 + 86_400_000; @@ -191,9 +203,9 @@ fn the_session_moves_counts_and_lets_go_of_the_page() { &vars, r" run(SHIM); - Date.now(); Date.now(); new Date(); performance.now(); + Date.now(); Date.now(); new Date(); Date(); performance.now(); const counts = run(COUNTS); - check('the counts come back', counts.now === 2 && counts.date === 1 && counts.perf === 1, counts); + check('the counts come back', counts.now === 2 && counts.date === 2 && counts.perf === 1, counts); check('a page with no frames reached none', counts.frames === 0 && counts.capped === 0, counts); const p0 = performance.now(); check('a jump answers ok', run(JUMP) === 'ok'); @@ -213,6 +225,11 @@ fn the_session_moves_counts_and_lets_go_of_the_page() { const zone = run(ZONE_READ); check('the zone read answers two offsets', Array.isArray(zone) && zone.length === 2 && zone.every(Number.isFinite), zone); check('through the engine own Date', zone[0] === new EngineDate(WALL0).getTimezoneOffset(), zone); + const sessionDate = globalThis.Date; + globalThis.Date = function PageDate() { return { getTimezoneOffset() { return 7777; } }; }; + const replaced = run(ZONE_READ); + globalThis.Date = sessionDate; + check('a page that replaced Date does not answer for the engine', replaced[0] === zone[0] && replaced[1] === zone[1], replaced); ", ); } @@ -220,7 +237,9 @@ fn the_session_moves_counts_and_lets_go_of_the_page() { /// A rate change scheduled for an instant takes effect at that instant, with the wall continuous across /// it (R4-S17), the duration axis re-anchored at the rate it ran at and never back below a reading /// already handed out (untouchable rule 3), and one received after its instant takes effect at once and -/// says `late`. +/// says `late`. It takes effect whichever clock is read first past the instant - `performance.now` and a +/// timer's delay as much as the wall - and the duration axis does not step back when a correction of the +/// system clock carries the wall past the instant while `performance.now` has not got there. #[test] fn a_scheduled_rate_change_takes_effect_at_its_instant() { let on_time = cdp_schedule_expr(ScheduledRate { at_ms: WALL0 + 500, mult: 1, dur: 1 }); @@ -249,12 +268,59 @@ fn a_scheduled_rate_change_takes_effect_at_its_instant() { check('and never steps the duration axis back', performance.now() >= p700, performance.now() - p700); ", ); + let mut first_perf = numbers(); + first_perf.push(("SHIM", shim(60, 60))); + first_perf.push(("ON_TIME", js_text(&on_time))); + run_scenario( + "schedulefirstperf", + &first_perf, + r" + run(SHIM); + const p0 = performance.now(); + run(ON_TIME); + // Nothing reads the wall: performance.now is the first clock read past the instant. + advance(700); + const p = performance.now() - p0; + check('performance.now read first is at the new rate from the instant', near(p, 500 * 60 + 200, 0.001), p); + ", + ); + let mut first_timer = numbers(); + first_timer.push(("SHIM", shim(60, 60))); + first_timer.push(("ON_TIME", js_text(&on_time))); + run_scenario( + "schedulefirsttimer", + &first_timer, + r" + run(SHIM); + run(ON_TIME); + advance(700); + const id = setTimeout(() => {}, 6000); + check('a timer armed first past the instant waits at the new rate', env.timers.find((t) => t.id === id).delay === 6000); + ", + ); + let mut drifting = numbers(); + drifting.push(("SHIM", shim(60, 60))); + drifting.push(("ON_TIME", js_text(&on_time))); + run_scenario( + "scheduledrift", + &drifting, + r" + run(SHIM); + run(ON_TIME); + advance(499); + const before = performance.now(); + // The wall is corrected 20 ms on, past the instant, while performance.now moves 5. + drift(20, 5); + const after = performance.now(); + check('performance.now does not step back when the wall runs ahead of it', after >= before, after - before); + ", + ); } -/// A second install in the same document only sets the clock it carries, the last instant and the zone -/// included (R4-W5), a `__chronomock` that is not this shim makes the install fail rather than report a -/// covered context (rule 4), and a page whose own scripts are in it before the shim answers `running` -/// (R5-P7). +/// A second install in the same document only sets the clock it carries, the last instant, the zone and +/// a change still to come included (R4-W5), a `__chronomock` that is not this shim makes the install +/// fail rather than report a covered context (rule 4) and is left as the page made it, and a page whose +/// own scripts are in it before the shim answers `running` (R5-P7). #[test] fn a_second_install_a_foreign_marker_and_a_running_page_are_told_apart() { let wall_max2 = FAKE0 + 5_000; @@ -276,6 +342,20 @@ fn a_second_install_a_foreign_marker_and_a_running_page_are_told_apart() { check('and the zone it carried is the one judged', run(COUNTS).zone === (offset === -60 ? 0 : 1), offset); ", ); + let carried = build_shim(FAKE0, WALL0, 60, 60, Some(ScheduledRate { at_ms: WALL0 + 2_000, mult: 1, dur: 1 }), WALL_MAX, None); + let mut change = numbers(); + change.push(("SHIM", shim(60, 60))); + change.push(("CARRIED", js_text(&carried))); + run_scenario( + "secondchange", + &change, + r" + run(SHIM); + check('a second install answers already', run(CARRIED) === 'already'); + advance(3000); + check('and the change it carried takes effect at its instant', Date.now() === FAKE0 + 2000 * 60 + 1000, Date.now() - FAKE0); + ", + ); let mut foreign = numbers(); foreign.push(("SHIM", shim(60, 60))); run_scenario( @@ -287,6 +367,8 @@ fn a_second_install_a_foreign_marker_and_a_running_page_are_told_apart() { try { run(SHIM); } catch (e) { threw = true; } check('a foreign marker makes the install fail', threw); check('and nothing is replaced', Date === EngineDate); + const left = Object.keys(globalThis.__chronomock); + check('and the object under the name is left as the page made it', left.join() === 'counts', left); ", ); let mut page = numbers(); @@ -604,7 +686,8 @@ fn the_moves_the_audit_and_the_release_reach_the_frames_of_the_page() { /// A page hidden while its timers run faster is noted - on install, when its visibility changes, and on /// every audit - and not at the rate 1 (R4-N28). The zone a context reads is judged against the session's -/// at install and at every audit, and a session with no zone judges none. +/// at install and at every audit, a session with no zone judges none, and a page let go is judged no +/// more: what it reads after the release is no evidence about the session's zone (CodeRabbit on #89). #[test] fn the_audit_notes_a_hidden_page_and_a_zone_it_did_not_read() { let mut vars = numbers(); @@ -640,6 +723,7 @@ fn the_audit_notes_a_hidden_page_and_a_zone_it_did_not_read() { let mut zones = numbers(); zones.push(("FLOW", js_text(&build_shim(FAKE0, WALL0, 1, 1, None, WALL_MAX, None)))); zones.push(("COUNTS", js_text(COUNTS_EXPR))); + zones.push(("RELEASE", js_text(&release_expr()))); run_scenario( "zones", &zones, @@ -651,6 +735,10 @@ fn the_audit_notes_a_hidden_page_and_a_zone_it_did_not_read() { check('a context that reads the session zone is not noted', run(COUNTS).zone === 0, here); globalThis.__chronomock.set(FAKE0, WALL0, 1, 1, null, undefined, here + 60); check('one that reads another zone is', run(COUNTS).zone === 1, here); + // An offset no engine shows, so the page on the real clock can never read it by chance. + globalThis.__chronomock.set(FAKE0, WALL0, 1, 1, null, undefined, 9999); + run(RELEASE); + check('a page let go is judged against no zone', run(COUNTS).zone === 0); ", ); } diff --git a/crates/cli/src/cdp/shim_harness.js b/crates/cli/src/cdp/shim_harness.js index 1423e132..bae55352 100644 --- a/crates/cli/src/cdp/shim_harness.js +++ b/crates/cli/src/cdp/shim_harness.js @@ -48,6 +48,10 @@ globalThis.clearInterval = clearTimer; /** Move both clocks by `ms` without running anything, as a page busy with its own work. */ function stall(ms) { env.wall += ms; env.perf += ms; } +/** Move the wall by `wall` and performance by `perf` without running anything: a correction of the + * system clock moves the wall alone, and the two clocks run apart. */ +function drift(wall, perf) { env.wall += wall; env.perf += perf; } + /** Move both clocks by `ms` and run every timer that comes due, earliest first. A timer already * overdue runs now, late, as an engine runs it once its thread is free, and an engine's own repeating * timer is armed again from then. */ diff --git a/crates/cli/src/cdp/ws.rs b/crates/cli/src/cdp/ws.rs index 4ac8f410..db5c8f4e 100644 --- a/crates/cli/src/cdp/ws.rs +++ b/crates/cli/src/cdp/ws.rs @@ -542,10 +542,21 @@ pub(crate) mod tests { /// entry whose id is `null` is an event: its "result" is written as the whole message. pub(crate) fn fake_browser_holding( mut answer: impl FnMut(&serde_json::Value) -> Vec<(serde_json::Value, serde_json::Value)> + Send + 'static, + ) -> (u16, std::thread::JoinHandle>) { + fake_browser_paced(None, move |request| request.map(&mut answer).unwrap_or_default()) + } + + /// The same, and once the client has sent nothing for `quiet`, `answer` is asked again with no + /// request: a renderer busy with its own work comes free when it does, not when the next command + /// arrives, so a reply held back can come after the client went on without it. + pub(crate) fn fake_browser_paced( + quiet: Option, + mut answer: impl FnMut(Option<&serde_json::Value>) -> Vec<(serde_json::Value, serde_json::Value)> + Send + 'static, ) -> (u16, std::thread::JoinHandle>) { let (tx, rx) = std::sync::mpsc::channel(); let (port, server) = server(move |mut s| { s.write_all(UPGRADED).unwrap(); + s.set_read_timeout(quiet).unwrap(); let mut log = Vec::new(); let mut buf = Vec::new(); let mut b = [0u8; 8192]; @@ -557,14 +568,20 @@ pub(crate) mod tests { let Ok(request) = serde_json::from_slice::(&payload) else { continue; }; - for (id, result) in answer(&request) { + for (id, result) in answer(Some(&request)) { s.write_all(&server_frame(scripted_message(id, result).as_bytes(), true)).unwrap(); } log.push(request); } match s.read(&mut b) { - Ok(0) | Err(_) => break, + Ok(0) => break, Ok(n) => buf.extend_from_slice(&b[..n]), + Err(e) if quiet.is_some() && matches!(e.kind(), io::ErrorKind::WouldBlock | io::ErrorKind::TimedOut) => { + for (id, result) in answer(None) { + s.write_all(&server_frame(scripted_message(id, result).as_bytes(), true)).unwrap(); + } + } + Err(_) => break, } } let _ = tx.send(log); diff --git a/crates/cli/src/cdp_attach.rs b/crates/cli/src/cdp_attach.rs index f9ca34d3..86f5a17a 100644 --- a/crates/cli/src/cdp_attach.rs +++ b/crates/cli/src/cdp_attach.rs @@ -1289,19 +1289,32 @@ mod tests { } /// CodeRabbit on #89: two pages share one renderer and its zone override, and the protocol does not - /// order commands across sessions. Here the second page's renderer is busy and runs its last count - /// only when its release arrives, reading another zone if the session's was replaced before. The - /// release replaces the zone after the answers, so the count reads the session's zone, and both - /// pages are then put on the machine's zone by its name (ADR-21). + /// order commands across sessions. Here the second page's renderer is busy: its last count and its + /// release wait until it comes free, which is once the attacher has gone quiet after sending the + /// release, and the count reads another zone if the session's was replaced before then. The release + /// replaces the zone only after the answers, so the count reads the session's zone, and both pages + /// are then put on the machine's zone by its name (ADR-21). A renderer that answered the count the + /// moment the release arrived let an attacher through that replaced the zone right after sending the + /// release, without waiting for the answers (the registry's entry went through). #[test] fn the_release_takes_the_zone_away_only_after_the_last_counts() { let mut reset = false; let mut held: Option = None; - let (port, browser) = crate::cdp::fake_browser_holding(move |request| { + let mut release: Option = None; + let count = |reset: bool| json!({ "result": { "value": { "now": 1, "zone": u8::from(reset) } } }); + let (port, browser) = crate::cdp::fake_browser_paced(Some(Duration::from_millis(200)), move |request| { + let Some(request) = request else { + // Free again: the count it was busy with, then the release behind it. + let Some(release_id) = release.take() else { + return Vec::new(); + }; + let mut out: Vec<_> = held.take().map(|count_id| (count_id, count(reset))).into_iter().collect(); + out.push((release_id, json!({ "result": { "value": "ok" } }))); + return out; + }; let id = request["id"].clone(); let session = request["sessionId"].as_str().unwrap_or(""); let expr = request["params"]["expression"].as_str().unwrap_or(""); - let count = |reset: bool| json!({ "result": { "value": { "now": 1, "zone": u8::from(reset) } } }); match request["method"].as_str().unwrap_or("") { "Target.getTargets" => vec![( id, @@ -1326,16 +1339,11 @@ mod tests { let shown = if reset { json!([-60, -120]) } else { json!([-330, -330]) }; vec![(id, json!({ "result": { "value": shown } }))] } - "Runtime.evaluate" if expr == cdp::release_expr() => { - let mut out = Vec::new(); - if session == "S2" - && let Some(count_id) = held.take() - { - out.push((count_id, count(reset))); - } - out.push((id, json!({ "result": { "value": "ok" } }))); - out + "Runtime.evaluate" if expr == cdp::release_expr() && session == "S2" => { + release = Some(id); + Vec::new() } + "Runtime.evaluate" if expr == cdp::release_expr() => vec![(id, json!({ "result": { "value": "ok" } }))], "Runtime.evaluate" => vec![(id, json!({ "result": {} }))], _ => vec![(id, json!({}))], } diff --git a/crates/cli/tests/session_identity.rs b/crates/cli/tests/session_identity.rs index 34a04f1b..f30fecf1 100644 --- a/crates/cli/tests/session_identity.rs +++ b/crates/cli/tests/session_identity.rs @@ -20,6 +20,7 @@ //! it for the first time after the end. Its hook starts watching the core from the first detour, not //! when it joins, so that first read used to come back on the session's clock. +use std::io::Read; use std::path::{Path, PathBuf}; use std::process::{Command, Stdio}; use std::sync::Mutex; @@ -37,9 +38,9 @@ const PROBE_CHILD_AFTER: &str = "CHRONO_SESSION_IDENTITY_PROBE_CHILD_AFTER_MS"; /// Set, the probe only writes one line and waits this many milliseconds - the second session's target. const PROBE_IDLE: &str = "CHRONO_SESSION_IDENTITY_PROBE_IDLE_MS"; -/// Set, the probe reads no clock until this many milliseconds have passed, then reads it once - the -/// target of the third test. -const PROBE_LATE_READ: &str = "CHRONO_SESSION_IDENTITY_PROBE_LATE_READ_MS"; +/// Set, the probe reaches no detour until it can take the named mutex this names, which the test holds +/// until the core has gone, then reads the clock once - the target of the third test. +const PROBE_LATE_GATE: &str = "CHRONO_SESSION_IDENTITY_PROBE_LATE_GATE"; /// The probe's own name, which is how the binary is asked to run it and nothing else. const PROBE: &str = "probe_starts_a_child_after_its_session_ends"; @@ -67,8 +68,18 @@ static ONE_SESSION: Mutex<()> = Mutex::new(()); #[cfg_attr(not(target_arch = "x86"), link(name = "kernel32", kind = "raw-dylib"))] unsafe extern "system" { fn GetModuleHandleA(name: *const core::ffi::c_char) -> *mut core::ffi::c_void; + fn CreateMutexA(attributes: *const core::ffi::c_void, owned: i32, name: *const core::ffi::c_char) -> *mut core::ffi::c_void; + fn OpenMutexA(access: u32, inherit: i32, name: *const core::ffi::c_char) -> *mut core::ffi::c_void; + fn ReleaseMutex(mutex: *mut core::ffi::c_void) -> i32; + fn WaitForSingleObject(handle: *mut core::ffi::c_void, ms: u32) -> u32; + fn CloseHandle(handle: *mut core::ffi::c_void) -> i32; } +/// The right to wait on an object, and the wait with no end and its failure, as Windows numbers them. +const SYNCHRONIZE: u32 = 0x0010_0000; +const INFINITE: u32 = u32::MAX; +const WAIT_FAILED: u32 = u32::MAX; + /// The wall clock as this process reads it, in whole seconds since the Unix epoch. fn wall_seconds() -> u64 { SystemTime::now().duration_since(UNIX_EPOCH).map(|d| d.as_secs()).unwrap_or(0) @@ -99,8 +110,8 @@ fn millis(name: &str) -> Option { /// Writes `parent-start`, waits past the session, starts itself as the child, which writes `child`, /// then writes `parent-after`. Each line holds the wall seconds read, 1 when the hook is loaded, and the -/// pid. With `PROBE_IDLE` set it writes `idle` and only waits. With `PROBE_LATE_READ` set it writes -/// `late-start` without reading the clock, waits, and writes `late-read` with the clock read once. +/// pid. With `PROBE_IDLE` set it writes `idle` and only waits. With `PROBE_LATE_GATE` set it waits for +/// the gate, reads the clock once, and only then writes `late-start` and `late-read`. #[test] #[ignore = "the target of the two session tests in this file, not a test on its own"] fn probe_starts_a_child_after_its_session_ends() { @@ -108,12 +119,26 @@ fn probe_starts_a_child_after_its_session_ends() { return; }; let out = PathBuf::from(out); - if let Some(late) = millis(PROBE_LATE_READ) { - // Nothing here reads a clock the hook watches until the wait is over: the line carries 0 for - // its seconds, and a plain sleep is not hooked in a session that does not scale durations. + if let Ok(gate) = std::env::var(PROBE_LATE_GATE) { + // Nothing here reaches a detour that starts the hook's watcher until the clock is read: a wait on + // an object is only counted. Measured: opening a file arms a thread-pool timer inside Windows, + // through the timer detour, so the probe that wrote a line and slept had its watcher running while + // the session ran, and with the first look taken out of the hook it still read the real clock - + // the test proved nothing about a first read after the end. So the clock is read first, and the + // lines are written after it. + let name = std::ffi::CString::new(gate).expect("a gate name without NUL"); + // SAFETY: a lookup and a wait on a handle this block opened and closes, with a NUL-terminated name. + let opened = unsafe { + let mutex = OpenMutexA(SYNCHRONIZE, 0, name.as_ptr()); + let waited = !mutex.is_null() && WaitForSingleObject(mutex, INFINITE) != WAIT_FAILED; + if !mutex.is_null() { + CloseHandle(mutex); + } + waited + }; + let seconds = wall_seconds(); append_seconds(&out, "late-start", 0); - std::thread::sleep(Duration::from_millis(late)); - append(&out, "late-read"); + append_seconds(&out, if opened { "late-read" } else { "late-gate-failed" }, seconds); return; } if let Some(idle) = millis(PROBE_IDLE) { @@ -156,6 +181,18 @@ fn line(text: &str, role: &str) -> Option { Some(Reading { seconds: parts.next()?.parse().ok()?, hooked: parts.next()? == "1", pid: parts.next()?.parse().ok()? }) } +/// A child's stream read to its end on a thread of its own, so that neither stream fills while the test +/// waits on the process. +fn drain(stream: Option) -> std::thread::JoinHandle { + std::thread::spawn(move || { + let mut bytes = Vec::new(); + if let Some(mut stream) = stream { + let _ = stream.read_to_end(&mut bytes); + } + String::from_utf8_lossy(&bytes).into_owned() + }) +} + /// The library is built and the scratch directory `name` is empty, before a session starts. fn prepare(name: &str) -> PathBuf { let library = injected_library(); @@ -327,16 +364,36 @@ fn a_process_that_read_no_clock_in_its_session_reads_the_real_clock_after_it() { let dir = prepare("session-late-read"); let file = dir.join("probe.txt"); - // As in the first test, `output()` returns once the probe is done, which is what the file needs. - let out = session(SESSION_AT, "2") + // The probe waits on this mutex until the core has gone, so its one read comes after the end however + // slow the machine is. Should this test stop before it lets go, the mutex is abandoned with it, and + // the probe's wait ends all the same. + let gate_name = format!("Local\\chrono-session-identity-gate-{}", std::process::id()); + let gate_c = std::ffi::CString::new(gate_name.as_str()).expect("a gate name without NUL"); + // SAFETY: a named object created with a NUL-terminated name, owned by this thread from the start. + let gate = unsafe { CreateMutexA(std::ptr::null(), 1, gate_c.as_ptr()) }; + assert!(!gate.is_null(), "the gate could not be made"); + let mut run = session(SESSION_AT, "2") .env(PROBE_OUT, &file) - .env(PROBE_LATE_READ, CHILD_AFTER_MS.to_string()) - .output() + .env(PROBE_LATE_GATE, &gate_name) + .stdout(Stdio::piped()) + .stderr(Stdio::piped()) + .spawn() .expect("the tool must run"); + let stdout = drain(run.stdout.take()); + let stderr = drain(run.stderr.take()); + // The core's own exit, not the end of its streams: the probe holds the error stream until it is done, + // and it is not done until the gate opens. + let _ = run.wait(); + // SAFETY: the mutex this thread created and owns. + unsafe { + ReleaseMutex(gate); + CloseHandle(gate); + } + let stdout = stdout.join().unwrap_or_default(); + let stderr = stderr.join().unwrap_or_default(); let real_now = wall_seconds(); - let stdout = String::from_utf8_lossy(&out.stdout); let text = std::fs::read_to_string(&file).unwrap_or_default(); - let context = || format!("probe: {text:?} stdout: {stdout} stderr: {}", String::from_utf8_lossy(&out.stderr)); + let context = || format!("probe: {text:?} stdout: {stdout} stderr: {stderr}"); // The application joined the session, or the read below says nothing about a session. let Some(start) = line(&text, "late-start") else { diff --git a/crates/cli/tests/wire_keys.rs b/crates/cli/tests/wire_keys.rs index 2d8dd485..b6db8a80 100644 --- a/crates/cli/tests/wire_keys.rs +++ b/crates/cli/tests/wire_keys.rs @@ -768,10 +768,37 @@ fn every_translation_is_reached_by_the_window_or_the_core() { from a word, name that rule in BUILT." ); - for (key, reason) in UNREACHED { - assert!(en.contains(key), "UNREACHED names `{key}`, which is no longer in the files - take it out ({reason})"); - assert!(!reached.contains(key), "UNREACHED names `{key}`, which is reached again - take it out ({reason})"); + let problems = unreached_problems(&UNREACHED, &en, &reached); + assert!(problems.is_empty(), "{}", problems.join("\n")); +} + +/// What is wrong with the texts `UNREACHED` excuses, read from both ends: one no longer in the files and +/// one reached again each have to come out. A function of its own so that the check is tested on a list +/// of its own - the list is empty today, and a check over an empty list passes whatever it does. +fn unreached_problems(excused: &[(&str, &str)], in_files: &BTreeSet, reached: &BTreeSet) -> Vec { + let mut problems = Vec::new(); + for (key, reason) in excused { + if !in_files.contains(*key) { + problems.push(format!("UNREACHED names `{key}`, which is no longer in the files - take it out ({reason})")); + } + if reached.contains(*key) { + problems.push(format!("UNREACHED names `{key}`, which is reached again - take it out ({reason})")); + } } + problems +} + +/// The list of unreached texts is checked from both ends: an entry whose text left the files and one whose +/// text is reached again are each named, and an entry that is neither passes. +#[test] +fn the_unreached_list_is_checked_from_both_ends() { + let in_files: BTreeSet = ["kept.text", "back.text"].map(String::from).into(); + let reached: BTreeSet = ["back.text"].map(String::from).into(); + let excused = [("kept.text", "a reason"), ("gone.text", "a reason"), ("back.text", "a reason")]; + let problems = unreached_problems(&excused, &in_files, &reached); + assert_eq!(problems.len(), 2, "{problems:?}"); + assert!(problems[0].contains("`gone.text`") && problems[0].contains("no longer in the files"), "{problems:?}"); + assert!(problems[1].contains("`back.text`") && problems[1].contains("reached again"), "{problems:?}"); } /// The markup scan takes a key from either resource extension and nothing that is not a key. diff --git a/gui/ChronoMock.App.Tests/BackgroundGuardTests.cs b/gui/ChronoMock.App.Tests/BackgroundGuardTests.cs index f928df73..3e00edd8 100644 --- a/gui/ChronoMock.App.Tests/BackgroundGuardTests.cs +++ b/gui/ChronoMock.App.Tests/BackgroundGuardTests.cs @@ -45,9 +45,8 @@ public void The_window_paints_our_palette_over_most_of_its_surface() // 🔴 OUR GROUNDS, not the dependency's default. The trap this guards paints the wpfui #202020 on // every pixel, because a ui:FluentWindow ignores its own Background - our palette never contains that // colour. Which of our grounds dominates is the design's affair - the setup phase covers most of the - // window in cards (BrushBgSurface) over the base (BrushBgBase) - so the measure is how much of the - // surface OUR grounds cover together. That stays above half whether the base or a card wins, and - // collapses the moment #202020 comes back, which is the failure this exists to catch. + // window in cards (BrushBgSurface) over the base (BrushBgBase) - so the first measure is how much of + // the surface OUR grounds cover together, which stays above half whether the base or a card wins. var grounds = WpfTestHost.InvokeSettled(() => new[] { "BrushBgBase", "BrushBgSurface", "BrushBgSurfaceAlt" } .Select(key => Application.Current.TryFindResource(key) as SolidColorBrush) @@ -64,8 +63,25 @@ public void The_window_paints_our_palette_over_most_of_its_surface() covered > 0.5, $"our palette grounds cover only {covered:P1} of the window - something else is painting it, or " + "the content root lost its Background to the FluentWindow trap"); + + // That share alone does not catch the trap. Measured 2026-10-16: the cards cover 46.8% and the base + // 45.5%, so with the base gone the cards and the alternate ground still come to 50.8% (the registry's + // entry painting the base another colour went through). The trap shows as ONE colour that is not ours + // over the base's whole area, while the text, icons and accents spread over many colours of a few + // tenths of a percent each (the largest 0.5%). + var (foreign, share) = counts.Where(pair => !groundKeys.Contains(pair.Key)) + .Select(pair => (pair.Key, Share: pair.Value / (double)sampled)) + .MaxBy(pair => pair.Share); + Assert.True( + share < ForeignCeiling, + $"one colour that is not our ground, #{foreign:X8}, covers {share:P1} of the window - something " + + "else paints a whole area of it, or the content root lost its Background to the FluentWindow trap"); } + // No single colour outside our grounds may cover this share of the window: twenty times the largest one + // measured, and well under the base's area that the trap takes. + private const double ForeignCeiling = 0.10; + [Fact] public void No_view_writes_a_background_onto_a_FluentWindow() { diff --git a/gui/ChronoMock.App.Tests/LayoutGuardTests.cs b/gui/ChronoMock.App.Tests/LayoutGuardTests.cs index 7e83dfbb..41bfd2d7 100644 --- a/gui/ChronoMock.App.Tests/LayoutGuardTests.cs +++ b/gui/ChronoMock.App.Tests/LayoutGuardTests.cs @@ -202,7 +202,8 @@ public void The_spill_rule_fires_on_text_wider_than_the_box_it_was_put_in() { // The exact shape measured while the truncation probe refused to fire: a Grid declared 60 wide // came back holding a TextBlock 285 wide. WPF let it overflow rather than squeezing it, which - // is how text ends up painted over its neighbour. + // is how text ends up painted over its neighbour. The complaint names the words the block shows: + // an unnamed TextBlock is found by them, not by where it sits. var complaints = WpfTestHost.InvokeSettled(() => { var narrow = new Grid { Width = 60 }; @@ -217,7 +218,9 @@ public void The_spill_rule_fires_on_text_wider_than_the_box_it_was_put_in() return LayoutRules.SpillsOutOfItsParent(LayoutProbe.Walk(host)); }); - Assert.NotEmpty(complaints); + Assert.Contains( + complaints, + c => c.StartsWith("TextBlock \"a sentence far longer than sixty pixels of room\" at [", StringComparison.Ordinal)); } [Fact] diff --git a/gui/ChronoMock.App.Tests/SessionCloseTests.cs b/gui/ChronoMock.App.Tests/SessionCloseTests.cs index 429cecae..8229c65e 100644 --- a/gui/ChronoMock.App.Tests/SessionCloseTests.cs +++ b/gui/ChronoMock.App.Tests/SessionCloseTests.cs @@ -49,6 +49,11 @@ public async Task A_close_while_the_start_is_still_preparing_launches_nothing() { var target = SessionPlan.DefaultTargetPath(); Assert.True(target is not null, "the sample target is not built - build the solution first"); + // Without its core the start fails on its own and launches nothing, and this test would pass for + // that reason whatever the close did - measured, with the core taken away. + Assert.True( + File.Exists(AppPaths.SubstitutionCores.CoreForTarget(target)), + "the core for the sample target is not built - build the release cores first"); var store = new InMemorySessionHistoryStore(); var vm = new SessionViewModel(store); vm.SetTarget(target); diff --git a/tests/mutation/entries.json b/tests/mutation/entries.json index c31bd77c..2a7509df 100644 --- a/tests/mutation/entries.json +++ b/tests/mutation/entries.json @@ -453,9 +453,9 @@ "name": "pr-a exception no longer in the files", "edits": [ { - "file": "gui/ChronoMock.App/Localization/Strings.en.json", - "from": " \"target.missing\": \"(missing)\",\n", - "to": "" + "file": "crates/cli/tests/wire_keys.rs", + "from": " if !in_files.contains(*key) {\n", + "to": " if false {\n" } ], "runner": "rust", @@ -464,7 +464,7 @@ "--test", "wire_keys" ], - "test": "every_translation_is_reached_by_the_window_or_the_core", + "test": "the_unreached_list_is_checked_from_both_ends", "match": "exact", "build": "", "notHere": "" @@ -473,9 +473,9 @@ "name": "pr-a exception reached again", "edits": [ { - "file": "gui/ChronoMock.App/Views/SetupPhaseView.xaml", - "from": "ToolTip=\"{DynamicResource setup.tip_recent}\"", - "to": "ToolTip=\"{DynamicResource setup.tip_recent}\" Tag=\"{DynamicResource target.missing}\"" + "file": "crates/cli/tests/wire_keys.rs", + "from": " if reached.contains(*key) {\n", + "to": " if false {\n" } ], "runner": "rust", @@ -484,7 +484,7 @@ "--test", "wire_keys" ], - "test": "every_translation_is_reached_by_the_window_or_the_core", + "test": "the_unreached_list_is_checked_from_both_ends", "match": "exact", "build": "", "notHere": "" @@ -879,7 +879,7 @@ "runner": "cs", "package": "gui/ChronoMock.App.Tests", "target": [], - "test": "ChronoMock.App.Tests.ParameterRowLayoutTests.The_general_layout_rules_find_nothing_in_any_scenarios_parameters_at_the_calculators_narrowest", + "test": "ChronoMock.App.Tests.LayoutGuardTests.The_spill_rule_fires_on_text_wider_than_the_box_it_was_put_in", "match": "method", "build": "", "notHere": "" @@ -1834,7 +1834,7 @@ "target": [], "test": "ChronoMock.App.Tests.SessionCloseTests.A_close_while_the_start_is_still_preparing_launches_nothing", "match": "method", - "build": "", + "build": "release", "notHere": "" }, { @@ -8930,8 +8930,8 @@ "edits": [ { "file": "crates/cli/src/calc.rs", - "from": "chrono_core::calc::DateReading::Iso => time_written,", - "to": "chrono_core::calc::DateReading::Iso => (civil.hour, civil.minute, civil.second) != (0, 0, 0)," + "from": " if reading_shows_time(reading, time_written) {\n", + "to": " if reading_shows_time(reading, time_written && (civil.hour, civil.minute, civil.second) != (0, 0, 0)) {\n" } ], "runner": "rust", diff --git a/tests/mutation/mutate.ps1 b/tests/mutation/mutate.ps1 index dfdac0af..01ce4c47 100644 --- a/tests/mutation/mutate.ps1 +++ b/tests/mutation/mutate.ps1 @@ -123,6 +123,9 @@ $env:CARGO_TERM_COLOR = 'never' # the judge is a change to every judgement. $runnerFiles = @('tests/mutation/mutate.ps1', 'tests/mutation/json.ps1', 'tests/mutation/report.ps1', '.github/workflows/mutation.yml') +# The C# side as one build, the solution CI builds before its C# tests. +$csSolution = 'gui/ChronoMock.slnx' + # --------------------------------------------------------------------------------------------------- # The registry # --------------------------------------------------------------------------------------------------- @@ -1275,8 +1278,11 @@ $csProjects = @($judged | Where-Object { $_.runner -eq 'cs' } | ForEach-Object { $hasRelease = @($judged | Where-Object { $_.build -eq 'release' }).Count -gt 0 # The clean tree first: the debug workspace for the tests that drive a session (cargo test never builds -# chrono_hook.dll), both release cores when an entry's test reads them, and every C# test project of the -# part. A tree that does not build here cannot make a test red because of a mutation. +# chrono_hook.dll), both release cores when an entry's test reads them, and the whole C# solution when the +# part has a C# entry - as CI builds it before its C# tests, not each test project alone, because a test +# reads what another project of the solution builds (the sample target a session test launches). A part +# that built the test projects alone found that test red before any mutation, on its first run in CI. A +# tree that does not build here cannot make a test red because of a mutation. $cleanBuilds = @() if ($hasRust) { $cleanBuilds += 'debug' } if ($hasRelease) { $cleanBuilds += 'release' } @@ -1287,11 +1293,11 @@ foreach ($kind in $cleanBuilds) { Stop-Part @("THE UNMUTATED TREE DOES NOT BUILD ($kind), so no test here can be red because of a mutation. Stopping.") $artifacts.Run } } -foreach ($project in $csProjects) { - $build = Invoke-CsBuild $project +if ($csProjects.Count -gt 0) { + $build = Invoke-CsBuild $csSolution if ($build.Code -ne 0) { $partState.built = $false - Stop-Part @("THE UNMUTATED TREE DOES NOT BUILD ($project), so no test here can be red because of a mutation. Stopping.") $build + Stop-Part @("THE UNMUTATED TREE DOES NOT BUILD ($csSolution), so no test here can be red because of a mutation. Stopping.") $build } } From 65a75eb2ace128ececf123f1ede5435a919cba68 Mon Sep 17 00:00:00 2001 From: DonislawDev Date: Sat, 17 Oct 2026 00:00:10 +0200 Subject: [PATCH 2/2] test(mutation): review round on #113 - the drift scenario asks for the new rate, the paced fake browser never reads a timed-out socket, and the late-read test waits for the core with a deadline - The drift scenario only asked that performance.now did not step back after a correction of the wall carried it past a scheduled change. It now also advances and asks for the new rate. Measured with the rate change taken out of settle: the old check still passed and the new one fails (60000 where 1000 is due). (Review finding.) - fake_browser_paced read the same socket again after a receive had timed out, which Winsock documents as leaving the connection in an indeterminate state that should be closed. A thread of its own now reads with plain blocking reads, the quiet is a timed wait on what that thread hands over, and the socket is shut down at the end so the thread cannot be left in its read. All 188 CDP tests pass on it. (Review finding.) - The late-read test waited for the core without a bound. A core that came to wait for its target would wait on the probe, the probe on the gate and the test on the core. It now polls the core with a deadline of 60 s, opens the gate either way, kills the core on the deadline and fails with what the core said, and a failed wait is an error rather than ignored. Measured with the deadline set to 300 ms: the test failed in 0.3 s and left no process behind. (Review finding.) Co-Authored-By: Claude Opus 5.5 --- crates/cli/src/cdp/shim_exec.rs | 6 ++++- crates/cli/src/cdp/ws.rs | 33 ++++++++++++++++++++++------ crates/cli/tests/session_identity.rs | 25 +++++++++++++++++++-- 3 files changed, 54 insertions(+), 10 deletions(-) diff --git a/crates/cli/src/cdp/shim_exec.rs b/crates/cli/src/cdp/shim_exec.rs index a36dd130..3c4b085f 100644 --- a/crates/cli/src/cdp/shim_exec.rs +++ b/crates/cli/src/cdp/shim_exec.rs @@ -239,7 +239,8 @@ fn the_session_moves_counts_and_lets_go_of_the_page() { /// already handed out (untouchable rule 3), and one received after its instant takes effect at once and /// says `late`. It takes effect whichever clock is read first past the instant - `performance.now` and a /// timer's delay as much as the wall - and the duration axis does not step back when a correction of the -/// system clock carries the wall past the instant while `performance.now` has not got there. +/// system clock carries the wall past the instant while `performance.now` has not got there, and runs at +/// the new rate from there. #[test] fn a_scheduled_rate_change_takes_effect_at_its_instant() { let on_time = cdp_schedule_expr(ScheduledRate { at_ms: WALL0 + 500, mult: 1, dur: 1 }); @@ -313,6 +314,9 @@ fn a_scheduled_rate_change_takes_effect_at_its_instant() { drift(20, 5); const after = performance.now(); check('performance.now does not step back when the wall runs ahead of it', after >= before, after - before); + advance(1000); + const step = performance.now() - after; + check('and runs at the new rate from there', near(step, 1000, 0.001), step); ", ); } diff --git a/crates/cli/src/cdp/ws.rs b/crates/cli/src/cdp/ws.rs index db5c8f4e..a538fd5b 100644 --- a/crates/cli/src/cdp/ws.rs +++ b/crates/cli/src/cdp/ws.rs @@ -549,6 +549,10 @@ pub(crate) mod tests { /// The same, and once the client has sent nothing for `quiet`, `answer` is asked again with no /// request: a renderer busy with its own work comes free when it does, not when the next command /// arrives, so a reply held back can come after the client went on without it. + /// + /// The socket is read by a thread of its own with plain blocking reads, and the quiet is the wait on + /// what that thread hands over: a receive that timed out leaves a Windows socket in an indeterminate + /// state that should not be read again (Winsock, `SO_RCVTIMEO`), so no read here ever times out. pub(crate) fn fake_browser_paced( quiet: Option, mut answer: impl FnMut(Option<&serde_json::Value>) -> Vec<(serde_json::Value, serde_json::Value)> + Send + 'static, @@ -556,10 +560,18 @@ pub(crate) mod tests { let (tx, rx) = std::sync::mpsc::channel(); let (port, server) = server(move |mut s| { s.write_all(UPGRADED).unwrap(); - s.set_read_timeout(quiet).unwrap(); + let (bytes_tx, bytes_rx) = std::sync::mpsc::channel::>(); + let mut reader = s.try_clone().unwrap(); + let reading = std::thread::spawn(move || { + let mut b = [0u8; 8192]; + while let Ok(n) = reader.read(&mut b) { + if n == 0 || bytes_tx.send(b[..n].to_vec()).is_err() { + break; + } + } + }); let mut log = Vec::new(); let mut buf = Vec::new(); - let mut b = [0u8; 8192]; 'read: loop { while let Ok(Some((_, opcode, payload))) = take_frame(&mut buf) { if opcode == 0x8 { @@ -573,17 +585,24 @@ pub(crate) mod tests { } log.push(request); } - match s.read(&mut b) { - Ok(0) => break, - Ok(n) => buf.extend_from_slice(&b[..n]), - Err(e) if quiet.is_some() && matches!(e.kind(), io::ErrorKind::WouldBlock | io::ErrorKind::TimedOut) => { + let next = match quiet { + Some(quiet) => bytes_rx.recv_timeout(quiet), + None => bytes_rx.recv().map_err(|_| RecvTimeoutError::Disconnected), + }; + match next { + Ok(bytes) => buf.extend_from_slice(&bytes), + Err(RecvTimeoutError::Timeout) => { for (id, result) in answer(None) { s.write_all(&server_frame(scripted_message(id, result).as_bytes(), true)).unwrap(); } } - Err(_) => break, + Err(RecvTimeoutError::Disconnected) => break, } } + // A client that sent its close frame and kept the connection open would hold the reading + // thread in its read for good. + let _ = s.shutdown(Shutdown::Both); + let _ = reading.join(); let _ = tx.send(log); }); let log = std::thread::spawn(move || { diff --git a/crates/cli/tests/session_identity.rs b/crates/cli/tests/session_identity.rs index f30fecf1..2baf03c2 100644 --- a/crates/cli/tests/session_identity.rs +++ b/crates/cli/tests/session_identity.rs @@ -50,6 +50,10 @@ const PROBE: &str = "probe_starts_a_child_after_its_session_ends"; /// session does not scale durations, so it is not shortened. const CHILD_AFTER_MS: u64 = 5_000; +/// How long a session of two heartbeats may take to end in the third test, far past the few seconds it +/// takes on a slow runner, before the test calls it stuck rather than waiting on it for good. +const CORE_ENDS_WITHIN: Duration = Duration::from_secs(60); + /// The session's moment, far enough ahead that no real clock reading can be mistaken for it. const SESSION_AT: &str = "2077-01-01T00:00:00"; @@ -382,15 +386,32 @@ fn a_process_that_read_no_clock_in_its_session_reads_the_real_clock_after_it() { let stdout = drain(run.stdout.take()); let stderr = drain(run.stderr.take()); // The core's own exit, not the end of its streams: the probe holds the error stream until it is done, - // and it is not done until the gate opens. - let _ = run.wait(); + // and it is not done until the gate opens. Bounded, because a core that came to wait for its target + // would wait on the probe, the probe on the gate and this test on the core. + let deadline = Instant::now() + CORE_ENDS_WITHIN; + let ended = loop { + match run.try_wait().expect("the core can be waited on") { + Some(_) => break true, + None if Instant::now() < deadline => std::thread::sleep(Duration::from_millis(50)), + None => break false, + } + }; // SAFETY: the mutex this thread created and owns. unsafe { ReleaseMutex(gate); CloseHandle(gate); } + if !ended { + let _ = run.kill(); + let _ = run.wait(); + } let stdout = stdout.join().unwrap_or_default(); let stderr = stderr.join().unwrap_or_default(); + assert!( + ended, + "the core did not end within {CORE_ENDS_WITHIN:?} of a session of two heartbeats - it waited for its \ + target, which waited for this test. stdout: {stdout} stderr: {stderr}" + ); let real_now = wall_seconds(); let text = std::fs::read_to_string(&file).unwrap_or_default(); let context = || format!("probe: {text:?} stdout: {stdout} stderr: {stderr}");