From 1109773efa7da7c0cf46654ea2ac64f50df677fe Mon Sep 17 00:00:00 2001 From: DonislawDev Date: Fri, 25 Sep 2026 11:22:14 +0200 Subject: [PATCH 1/3] fix(mech): say what to do with an argument a batch script cannot take The refusal of an argument holding a line break or a zero character said why the launch would fail but not what to change, while the refusal of a line that is too long did. It now says to remove that character. Co-Authored-By: Claude Opus 5.5 --- crates/mech/src/batch.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/crates/mech/src/batch.rs b/crates/mech/src/batch.rs index feaf7618..3ae31eea 100644 --- a/crates/mech/src/batch.rs +++ b/crates/mech/src/batch.rs @@ -63,7 +63,7 @@ fn batch_line(script: &str, args: &[String]) -> Result { if let Some(broken) = args.iter().find(|a| a.contains(['\r', '\n', '\0'])) { return Err(format!( "the argument {broken:?} holds a line break or a zero character, which would cut the \ - command line of a batch script short" + command line of a batch script short - remove that character from the argument" )); } let script = user_path(script)?.replace('%', "%%cd:~,%"); From eaabedc5d1ea281a3c33173ac19fe213b4e3dc31 Mon Sep 17 00:00:00 2001 From: DonislawDev Date: Fri, 25 Sep 2026 11:22:15 +0200 Subject: [PATCH 2/3] fix: let the session last for the processes on its clock, not the first one A launcher, a restart after an update, or a batch script that runs `start app.exe` ends the program the session launched on purpose and leaves the application running with the hook in it. The session ended at that moment and put the application back on the real clock. Measured with a probe that records the hooked wall clock next to a reference the hook cannot touch, on x64 and x86: - a starter that ended inside the opening guard window was reported as a single-instance application (exit 12), and the application it started saw the session date for 1 sample of 80 - a starter that ended later was reported as working (exit 0) over an application that saw the real date for 79 samples of 80 - `cmd.exe` given as the program behaved the same, so this was every launcher, not scripts alone The session now lasts while any process on its clock runs: the one it launched, or any process the hook followed into (ADR-16). A member is watched through a handle opened when its sign-in slot is first seen, and a process whose parent is outside the family is not taken for a member whose pid it recycled. The guard window treats a target that left such a process running as a launcher. A vanish that left only a process the hook could not enter running is named `target.handed_off_uncovered` instead of a single-instance suspicion. The report says so: `session.followed_family`, and an additive `session_verdict.followed` list printed under `exited:` as `followed:`. The GUI shows the warning, and its vanish detail no longer calls every vanish a single-instance application. After the change every starter variant keeps the application on the session clock for 80 samples of 80 with exit 0, on both bitnesses. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 12 + README.md | 3 +- crates/cli/src/cdp_session.rs | 4 +- crates/cli/src/core.rs | 85 ++++++- crates/cli/src/report.rs | 79 ++++++- crates/cli/src/run/collect.rs | 8 + crates/cli/tests/batch_script.rs | 45 +++- crates/cli/tests/network.rs | 6 +- crates/mech/src/family.rs | 211 ++++++++++++++++++ crates/mech/src/lib.rs | 30 +++ crates/mech/src/tree.rs | 36 ++- crates/proto/src/lib.rs | 31 ++- gui/ChronoMock.App.Tests/LocalizationTests.cs | 9 +- gui/ChronoMock.App.Tests/PhaseStates.cs | 35 ++- gui/ChronoMock.App.Tests/StateSheetTests.cs | 2 + .../Localization/Strings.en.json | 8 +- .../Localization/Strings.pl.json | 6 +- site/pages/cli-reference/en.html | 2 +- site/pages/cli-reference/pl.html | 2 +- 19 files changed, 572 insertions(+), 42 deletions(-) create mode 100644 crates/mech/src/family.rs diff --git a/CHANGELOG.md b/CHANGELOG.md index 813eea6d..ebff38db 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -56,6 +56,18 @@ Notable changes to Chrono Mock, newest first. The format follows script is started any other way. An argument holding a line break, and a command line longer than the interpreter's 8191 characters, are refused before anything starts, with exit 2, and `--dry-run` refuses them too. +- **A launcher, or a script that starts a program and ends, took the session down with it.** The + session lasted only as long as the program it launched. A script that runs `start app.exe`, a + launcher, or an application that restarts itself ends that program on purpose and leaves the real + application running, and the session ended at that moment and put the application back on the + real clock within a second. Ending at once, it was reported as a single-instance application that + did not take effect. Ending a moment later, it was reported as working, over an application that + saw the real date almost the whole time. The session now lasts until the last program on the + session clock closes, and the report names the programs it went on for (`followed:` in the report, + `followed` in `session_verdict` under `--json`). A helper that keeps running after the application + closes keeps the session open too, and is named the same way. A target that hands off to a program + the session could not enter, usually one of the other bitness, is no longer called a + single-instance application. - **`--dry-run` approved sessions the real run refuses.** An impossible `--at` (month 13, 30 February, 25:61) was printed as the plan and exited 0, while the real run was refused by the core with exit 1. A file Windows will not start (a text file, an empty `.exe`, one cut short inside its diff --git a/README.md b/README.md index 50f3ddd8..be3f4eef 100644 --- a/README.md +++ b/README.md @@ -28,7 +28,8 @@ it exists. resyncing with a time server, which breaks anything measuring elapsed time without a guard. - **Its own time zone** - a fixed offset for that process only, while the system zone stays put. - **Child processes come along** - installers and launchers spawn children, and without that the test - covers only half of what ran. + covers only half of what ran. A launcher or a script that starts the application and ends does not + end the session: it lasts until the last program on the session clock closes. - **Tells you if it worked** - a verdict, the channels covered with call counts, the channels missed, and warnings with consequences. [See below](#how-do-you-know-it-worked---the-time-source-audit) - this is the part no other tool does. diff --git a/crates/cli/src/cdp_session.rs b/crates/cli/src/cdp_session.rs index 7d385197..a3b51a0c 100644 --- a/crates/cli/src/cdp_session.rs +++ b/crates/cli/src/cdp_session.rs @@ -268,7 +268,8 @@ pub(crate) fn cdp_session(target: TargetSpec, time: TimeSpec, reader: BufReader< /// contexts, not injected processes, so its per-context warnings already travel on the coverage /// events, and it spawns nothing the hook could fail to follow - the two child fields stay empty. /// `process_count` has carried the context count since this session existed and keeps doing so for -/// the clients that read it there. `context_count` says the same number under its own name. +/// the clients that read it there. `context_count` says the same number under its own name. The +/// session ends with the browser it launched, so it never goes on for anything (`followed`). fn emit_cdp_session_verdict(token: &str, reason: &str, contexts: u32) { emit(&Event::SessionVerdict { v: PROTOCOL_VERSION, @@ -280,6 +281,7 @@ fn emit_cdp_session_verdict(token: &str, reason: &str, contexts: u32) { uncovered_children_total: 0, context_count: contexts, engines: Vec::new(), + followed: Vec::new(), }); } diff --git a/crates/cli/src/core.rs b/crates/cli/src/core.rs index 204e3ae9..10e6ad4c 100644 --- a/crates/cli/src/core.rs +++ b/crates/cli/src/core.rs @@ -16,9 +16,9 @@ use std::time::{Duration, Instant}; use chrono_core::{ filetime_utc_to_wall, verdict_from_coverage, Coverage, Moment, SessionSpec, TimeMode, Verdict, }; -use chrono_mech::UncoveredChild; +use chrono_mech::{FamilyMember, UncoveredChild}; use chrono_proto::{ - parse_command, Command, Event, MomentSpec, TargetSpec, TimeSpec, PROTOCOL_VERSION, + parse_command, Command, Event, FollowedProcess, MomentSpec, TargetSpec, TimeSpec, PROTOCOL_VERSION, UNCOVERED_CHILDREN_WIRE_MAX, }; @@ -139,7 +139,7 @@ pub(crate) fn core_mode() -> i32 { } match chrono_mech::prepare(&spec, &m_target, &hook) { - Ok(prepared) => { + Ok(mut prepared) => { // Surface an orphan reclaim so it is not silent (a prior core had died and left its // control block behind). Human diagnostic on stderr, never on the protocol stdout. if prepared.orphan_reclaimed { @@ -152,12 +152,17 @@ pub(crate) fn core_mode() -> i32 { // Single-instance vanish (ADR-4): the target exited within the guard // window right after injection. Report it honestly with exit 12 rather - // than trusting the install bits into a false verdict. - if let Some(lived_ms) = prepared.vanished_lived_ms { + // than trusting the install bits into a false verdict. A target that exited leaving a + // process on the session clock running is a launcher, not a vanish: the session goes on + // for that process (ADR-16). + if let Some(lived_ms) = prepared.vanished_lived_ms + && !prepared.session.family_alive() + { + let reason_key = vanish_reason_key(&mut prepared.session); emit(&Event::Vanished { v: PROTOCOL_VERSION, pid: prepared.session.pid, - reason_key: "target.single_instance_suspected".into(), + reason_key: reason_key.into(), lived_ms, }); prepared.session.end(); @@ -302,6 +307,9 @@ pub(crate) struct SessionLedger { /// Sticky for the same reason as the wall flag: readings taken while the duration axis stood /// there were held, and a later re-anchor does not make them untrue. duration_clamped: bool, + /// The processes the session went on for once the target had closed (ADR-16), noted the first + /// time the target is seen gone. `None` while it runs, empty when nothing outlived it. + followed: Option>, } impl SessionLedger { @@ -313,13 +321,19 @@ impl SessionLedger { uncovered_children: Vec::new(), clock_clamped: false, duration_clamped: false, + followed: None, } } - /// Poll for children that joined and for children the hook could not follow into. + /// Poll for children that joined and for children the hook could not follow into, and keep + /// the watch on the processes the session lasts for current. pub(crate) fn poll(&mut self, session: &mut chrono_mech::Session) { fold_children(session, &mut self.family, &mut self.family_pids); self.uncovered_children.extend(session.poll_uncovered_children()); + session.refresh_family(); + if self.followed.is_none() && !session.is_alive() { + self.followed = Some(session.living_family()); + } } /// Note whether either clock stands at the end of its range in this sample. @@ -405,7 +419,10 @@ pub(crate) fn run_session( let st = session.state(); ledger.sample(&st); emit(&state_event_from(&st)); - if !session.is_alive() { + // The session lasts for the family on its clock, not for the process it launched: a + // launcher ends on purpose and leaves the application running (ADR-16). The exit code + // is the launched process's, the one the tester named. + if !session.family_alive() { target_exit = session.exit_code(); break; } @@ -583,6 +600,33 @@ pub(crate) fn native_session_warnings( /// timers and elapsed-time counters carry on at normal speed from where the session left them. const KEY_LEFT_RUNNING: &str = "session.left_running"; +/// The target closed while processes it had started were still running on the session clock, and +/// the session went on for them (ADR-16). Said because a session that outlives the program the +/// tester named is a surprise unless it is explained, and a helper that never ends keeps it open. +const KEY_FOLLOWED_FAMILY: &str = "session.followed_family"; + +/// The target vanished inside the guard window after starting a process the hook could not enter, +/// usually one of the other bitness, which runs on the real clock (ADR-16). +const KEY_HANDED_OFF_UNCOVERED: &str = "target.handed_off_uncovered"; + +/// Why a target vanished inside the guard window with nothing on the session clock left running. +/// Asked only after the family was found gone, so a process it started is either one the hook never +/// entered or none at all. +fn vanish_reason_key(session: &mut chrono_mech::Session) -> &'static str { + let children = session.poll_uncovered_children(); + vanish_reason(session.pid, &children, chrono_mech::process_is_alive) +} + +/// The reason for a vanish, from the children the hook could not enter: a hand-off when one the +/// target started is still running, otherwise the single-instance suspicion ADR-4 was written for. +fn vanish_reason(root: u32, children: &[UncoveredChild], alive: impl Fn(u32) -> bool) -> &'static str { + if children.iter().any(|c| c.parent_pid == root && alive(c.pid)) { + KEY_HANDED_OFF_UNCOVERED + } else { + "target.single_instance_suspected" + } +} + /// Whether any process of the family the hook reached is still running as the session ends - the /// application the tester is left with. A recycled pid reads as alive, which errs toward saying so /// once too often, never toward keeping quiet about a process left behind. @@ -600,8 +644,9 @@ pub(crate) fn close_session( ) -> i32 { // Final fold so a child that joined since the last heartbeat still counts in the family. ledger.poll(&mut session); - let SessionLedger { mut family, family_pids, uncovered_children, clock_clamped, duration_clamped } = + let SessionLedger { mut family, family_pids, uncovered_children, clock_clamped, duration_clamped, followed } = ledger; + let followed = followed.unwrap_or_default(); // The application may outlive the session - a `--ticks` cutoff, a Stop in the panel - and the // session does not stop it (docs/01 section 8.4). It lets it go instead, and the pages have to be // let go while their connections are still open, so this comes before `finish`. @@ -670,6 +715,9 @@ pub(crate) fn close_session( reconcile_engine_warnings(&mut children_warnings, pages.pages_reached()); session_warnings.extend(children_warnings); session_warnings.extend(pages.session_warnings(zone_differs)); + if !followed.is_empty() { + session_warnings.push(KEY_FOLLOWED_FAMILY.to_string()); + } if left_running { session_warnings.push(KEY_LEFT_RUNNING.to_string()); } @@ -696,6 +744,12 @@ pub(crate) fn close_session( uncovered_children_total, context_count: pages.seen.len() as u32, engines: pages.engines, + // The image name comes from the process list, text from the target's world like the + // uncovered children's, and passes the same sieve. + followed: followed + .iter() + .map(|m| FollowedProcess { pid: m.pid, image: m.image.as_deref().map(crate::cdp::sanitise_target_text) }) + .collect(), }); emit(&Event::Ended { v: PROTOCOL_VERSION, @@ -1282,4 +1336,17 @@ mod tests { assert_eq!(Verdict::Works.combine(Verdict::Fails), Verdict::Partial); assert_eq!(Verdict::Undetermined.combine(Verdict::Fails), Verdict::Fails); } + + /// A target that vanished leaving a program it started running, one the hook could not enter, + /// handed off to it - measured with a 64-bit launcher starting a 32-bit program, which the report + /// called a single-instance application (ADR-16). Anything else is still the ADR-4 suspicion. + #[test] + fn a_vanish_that_left_an_uncovered_program_running_is_a_hand_off() { + let child = |pid, parent_pid| UncoveredChild { pid, parent_pid, image: None, command_line: None }; + assert_eq!(vanish_reason(10, &[child(11, 10)], |_| true), KEY_HANDED_OFF_UNCOVERED); + // Ended already, started by another process of the family, or nothing started at all. + assert_eq!(vanish_reason(10, &[child(11, 10)], |_| false), "target.single_instance_suspected"); + assert_eq!(vanish_reason(10, &[child(12, 11)], |_| true), "target.single_instance_suspected"); + assert_eq!(vanish_reason(10, &[], |_| true), "target.single_instance_suspected"); + } } diff --git a/crates/cli/src/report.rs b/crates/cli/src/report.rs index 92e4f561..13894ec9 100644 --- a/crates/cli/src/report.rs +++ b/crates/cli/src/report.rs @@ -108,6 +108,9 @@ pub(crate) struct SessionReport { pub(crate) context_count: u32, /// The DevTools endpoints the session reached inside the application, one per engine. pub(crate) engines: Vec, + /// The processes the session went on for after the target closed, from `session_verdict.followed` + /// (ADR-16). Empty when nothing outlived the target. + pub(crate) followed: Vec, /// Session duration as the core states it in `ended`: (fake wall reached, real ms elapsed, /// fake ms elapsed), or None when `ended` carried no end wall (a session that never started). /// Authoritative, not sampled from the heartbeats - one source of truth (3d35a79). @@ -311,6 +314,11 @@ pub(crate) fn describe_warning(key: &str) -> String { "session.left_running" => { "the application was still running when the session ended, so it is back on the real date and time now - its tick counts and elapsed-time counters carry on at normal speed from where the session left them instead of jumping back, a repeating timer it set while its timers were sped up keeps the shorter interval it was given, and a restart gives it a clean run on the real clock" } + // A session that outlives the program the tester named is a surprise unless it is explained - + // a launcher is the case it exists for, a helper that never ends is the case it warns about. + "session.followed_family" => { + "the target closed while programs it had started were still running on the session clock, so the session went on until the last of them closed - the programs listed under 'followed' are the ones it went on for, and one that keeps running after the application closes keeps the session open too" + } "embedded.pages_not_released" => { "a page inside the application did not confirm it was handed back to the real clock when the session ended, so it may keep the session date until it is reloaded or closed" } @@ -581,6 +589,34 @@ fn render_cut_short(stopped_early: Option<&'static str>) -> String { ) } +/// What a vanish is suspected to be, by its reason key. A target that started a program the hook +/// could not enter and closed is a hand-off, not a single-instance application (ADR-16), and the +/// line that used to say "single-instance" for every vanish said it of that one too. +fn vanish_cause(reason_key: &str) -> &'static str { + match reason_key { + "target.handed_off_uncovered" => { + "it started a program the session could not enter, usually one of the other bitness, which runs on the real clock" + } + _ => "suspected single-instance app", + } +} + +/// The processes the session went on for after the target closed (ADR-16), or nothing. Under the +/// line that says the target closed, because that line alone reads as the end of the session. +fn render_followed(followed: &[chrono_proto::FollowedProcess]) -> String { + if followed.is_empty() { + return String::new(); + } + let mut out = String::from(" followed: the target had started these, and the session went on until they closed:\n"); + for p in followed { + match &p.image { + Some(image) => out.push_str(&format!(" - {image} (pid {})\n", p.pid)), + None => out.push_str(&format!(" - pid {}\n", p.pid)), + } + } + out +} + /// One heading plus its pid-tagged channel names, or nothing when the list is empty. Shared by the /// two name-only buckets so `render_report` stays under its pinned complexity ceiling - the ceiling /// asked for this, and lifting a repeated shape out is the cheaper of its two answers. @@ -670,9 +706,7 @@ pub(crate) fn render_report(r: &SessionReport) -> String { // parent verdict as a fallback for an older core, then nothing. if let Some((reason_key, lived_ms)) = &r.vanished { out.push_str(" verdict: DID NOT TAKE EFFECT - the target vanished right after injection\n"); - out.push_str(&format!( - " (suspected single-instance app: {reason_key}; lived {lived_ms} ms)\n" - )); + out.push_str(&format!(" ({}: {reason_key}; lived {lived_ms} ms)\n", vanish_cause(reason_key))); } else if let Some((verdict, reason_key, count)) = &r.session_verdict { out.push_str(&format!( " verdict: {} ({units}: {count}{}{})\n", @@ -743,6 +777,7 @@ pub(crate) fn render_report(r: &SessionReport) -> String { exit_code_label(code) )); } + out.push_str(&render_followed(&r.followed)); if !r.covered.is_empty() { // The total belongs in the heading, not under the rows. There are up to forty-one of these @@ -883,6 +918,7 @@ mod tests { warnings: vec![], context_count: 0, engines: vec![], + followed: vec![], uncovered: vec![], unobserved: vec![], installed_late: vec![], @@ -1020,6 +1056,43 @@ mod tests { let out = render_report(&r); assert!(out.contains("DID NOT TAKE EFFECT"), "got:\n{out}"); assert!(out.contains("vanished"), "got:\n{out}"); + assert!(out.contains("suspected single-instance app"), "got:\n{out}"); + } + + /// A target that started a program the hook could not enter and closed is a hand-off. The line + /// said "suspected single-instance app" for every vanish, this one included (ADR-16). + #[test] + fn a_hand_off_to_an_uncovered_program_is_not_called_single_instance() { + let r = SessionReport { + vanished: Some(("target.handed_off_uncovered".into(), 15)), + ..empty_report() + }; + let out = render_report(&r); + assert!(out.contains("DID NOT TAKE EFFECT"), "got:\n{out}"); + assert!(out.contains("could not enter"), "got:\n{out}"); + assert!(!out.contains("single-instance"), "got:\n{out}"); + } + + /// The processes the session went on for stand under the line that says the target closed, named + /// when the process list had a name and by pid when it did not (ADR-16). + #[test] + fn the_processes_a_session_went_on_for_are_listed_under_the_exit() { + let r = SessionReport { + target_exit: Some(0), + followed: vec![ + chrono_proto::FollowedProcess { pid: 5150, image: Some("app.exe".into()) }, + chrono_proto::FollowedProcess { pid: 5151, image: None }, + ], + ..empty_report() + }; + let out = render_report(&r); + let exited = out.find("exited:").expect("the exit line"); + let followed = out.find("followed:").expect("the followed line"); + assert!(exited < followed, "got:\n{out}"); + assert!(out.contains("- app.exe (pid 5150)"), "got:\n{out}"); + assert!(out.contains("- pid 5151\n"), "got:\n{out}"); + // Nothing followed, no line. + assert!(!render_report(&empty_report()).contains("followed:")); } #[test] diff --git a/crates/cli/src/run/collect.rs b/crates/cli/src/run/collect.rs index 9a9fc07d..5c3afa9e 100644 --- a/crates/cli/src/run/collect.rs +++ b/crates/cli/src/run/collect.rs @@ -34,6 +34,8 @@ pub(super) struct Collector { // from `session_verdict` (docs/09). context_count: u32, engines: Vec, + // The processes the session went on for after the target closed, from `session_verdict` (ADR-16). + followed: Vec, timing: Option<(String, i64, i64)>, // (fake wall reached, real ms, fake ms) from `ended` // The target's own exit code and whatever teardown could not remove, both from `ended`. The wire // has carried them since the session report grew a duration, and the GUI panel has shown them @@ -63,6 +65,7 @@ impl Collector { uncovered_children_total, context_count, engines, + followed, .. } => { self.session_line = Some((verdict, reason_key, process_count)); @@ -71,6 +74,7 @@ impl Collector { self.uncovered_children_total = uncovered_children_total; self.context_count = context_count; self.engines = engines; + self.followed = followed; } Event::Vanished { reason_key, lived_ms, .. } => { self.vanished = Some((reason_key, lived_ms)); @@ -193,6 +197,7 @@ impl Collector { uncovered_children_total: self.uncovered_children_total, context_count: self.context_count, engines: self.engines, + followed: self.followed, cdp, stopped_early, } @@ -266,10 +271,13 @@ mod tests { uncovered_children_total: 0, context_count: 0, engines: Vec::new(), + followed: vec![chrono_proto::FollowedProcess { pid: 200, image: Some("app.exe".into()) }], }); let report = c.into_report("app.exe".into(), false, None); assert_eq!(report.warnings, vec!["runtime.qpc_elapsed", "session.pid_registry_full"]); + // The processes the session went on for reach the report as the core named them (ADR-16). + assert_eq!(report.followed, vec![chrono_proto::FollowedProcess { pid: 200, image: Some("app.exe".into()) }]); } /// Only `ended` ends the read, and it is the one event carrying the target's own exit code and diff --git a/crates/cli/tests/batch_script.rs b/crates/cli/tests/batch_script.rs index cdb67c43..73514ae4 100644 --- a/crates/cli/tests/batch_script.rs +++ b/crates/cli/tests/batch_script.rs @@ -9,7 +9,9 @@ //! command. The launch now starts the interpreter itself (`chrono_mech`, `batch.rs`, ADR-15). //! //! The evidence is the file the script writes, not the exit code: a script that ends at once can -//! end inside the opening guard window, which is its own verdict (ADR-4). +//! end inside the opening guard window, which is its own verdict (ADR-4). A script that starts a +//! program and ends is the other thing a batch target is for, and the session goes on for the +//! program it started (ADR-16). use std::path::PathBuf; use std::process::Command; @@ -110,3 +112,44 @@ fn a_launch_the_interpreter_would_not_run_is_refused_before_anything_starts() { } let _ = std::fs::remove_dir_all(&dir); } + +/// A script that starts a program and ends, the most common starter there is. The session used to end +/// with the script: one that ended at once, inside the opening guard window, was reported as a +/// single-instance application, and one that ended later as a session that worked - and either way the +/// program it started was back on the real clock within a second (measured, both ways). The session +/// now goes on for the program (ADR-16). The evidence is the date the program writes down two seconds +/// after the script is gone, not the exit code. +#[test] +fn a_script_that_starts_a_program_and_ends_leaves_the_session_to_that_program() { + require_injected_library(); + let _session = one_real_session_at_a_time(); + // Ending at once takes the guard-window path, ending after a second the heartbeat's. + for (name, before) in [("at-once", ""), ("after-a-second", "ping -n 2 127.0.0.1 >nul")] { + let dir = std::env::temp_dir().join(format!("chrono-starter-{name}-{}", std::process::id())); + let _ = std::fs::remove_dir_all(&dir); + std::fs::create_dir_all(&dir).expect("a scratch directory"); + let script = dir.join("starter.bat"); + // `start /b` returns at once and opens no window. The program waits two seconds on the + // loopback address and writes the date it sees, by which time the script has long ended. + let body = [ + "@echo off", + "cd /d \"%~dp0\"", + before, + "start \"\" /b cmd /c \"ping -n 3 127.0.0.1 >nul & date /t >seen.txt\"", + "", + ] + .join("\r\n"); + std::fs::write(&script, body).expect("the script"); + let out = Command::new(env!("CARGO_BIN_EXE_chrono")) + .args(["run", &script.display().to_string(), "--at", "2030-06-15T12:00:00"]) + .output() + .expect("the tool must run"); + let said = format!("stdout: {} stderr: {}", String::from_utf8_lossy(&out.stdout), String::from_utf8_lossy(&out.stderr)); + let seen = std::fs::read_to_string(dir.join("seen.txt")) + .unwrap_or_else(|e| panic!("{name}: the program never wrote its date ({e}). {said}")); + assert!(seen.contains("2030"), "{name}: the program saw {seen:?} after the script ended, not the session's date. {said}"); + assert_eq!(out.status.code(), Some(0), "{name}: {said}"); + assert!(said.contains("followed:"), "{name}: the report must name what the session went on for. {said}"); + let _ = std::fs::remove_dir_all(&dir); + } +} diff --git a/crates/cli/tests/network.rs b/crates/cli/tests/network.rs index 77f004bb..38f9ce4d 100644 --- a/crates/cli/tests/network.rs +++ b/crates/cli/tests/network.rs @@ -167,8 +167,10 @@ const ALLOWED: &[(&str, &str, &str)] = &[ "crates/cli/tests/batch_script.rs", "spawn", "runs the built binary on a batch script in a scratch folder, to see the arguments reach the \ - script as they were given and a launch the interpreter would not run refused before anything \ - starts. The script only writes a file beside itself, and nothing reaches past this machine", + script as they were given, a launch the interpreter would not run refused before anything \ + starts, and a script that starts a program and ends leave the session to that program. The \ + scripts only write files beside themselves and wait by pinging the loopback address, and \ + nothing reaches past this machine", ), ( "crates/cli/tests/usage.rs", diff --git a/crates/mech/src/family.rs b/crates/mech/src/family.rs new file mode 100644 index 00000000..befb4081 --- /dev/null +++ b/crates/mech/src/family.rs @@ -0,0 +1,211 @@ +//! The processes a session lasts for. +//! +//! A session used to end with the process it launched. A launcher, a restart after an update and a +//! batch script that runs `start app.exe` all end that process on purpose and leave the application +//! running, with the hook in it (ADR-3). Ending the session there let the application go back to the +//! real clock seconds after it started, and a launcher that ended inside the opening guard window +//! was even reported as a single-instance application (measured, tools/probes/starter). The session +//! now lasts for as long as any process on its clock is running: the one it launched, or any process +//! the hook followed into (ADR-16). +//! +//! A member is watched through a handle opened the first time its sign-in slot is seen, so a pid the +//! system recycles later cannot keep the session alive. The one gap left is a member that ended and +//! had its pid recycled before that first look - a child poll is 100 ms apart - and it is closed by +//! asking the process snapshot who started the process behind the handle: a recycled pid belongs to a +//! process started by somebody outside the family. + +use std::collections::HashSet; + +use windows::Win32::Foundation::{CloseHandle, HANDLE, WAIT_TIMEOUT}; +use windows::Win32::System::Threading::{ + OpenProcess, WaitForSingleObject, PROCESS_QUERY_LIMITED_INFORMATION, PROCESS_SYNCHRONIZE, +}; + +use crate::tree::{process_entries, ProcessEntry}; + +/// A process of the family that was still running when the session last looked, named by the file +/// of its executable when the snapshot had it. +#[derive(Debug, Clone, PartialEq, Eq)] +pub struct FamilyMember { + pub pid: u32, + pub image: Option, +} + +/// What the session knows about one sign-in slot. +enum Watch { + /// Not looked at yet. + Unseen, + /// Running when last asked, through a handle this session owns. + Living { pid: u32, handle: HANDLE, image: Option }, + /// Ended, or never watchable: it could not be opened, or the snapshot said it is not ours. + Done, +} + +/// Every process of the family besides the one the session launched, which the session watches +/// through its own handle. +pub(crate) struct Family { + watch: Vec, + /// The launched process's own slot, left to the session's handle on it. + root_slot: Option, +} + +impl Family { + pub(crate) fn new(slots: usize, root_slot: Option) -> Self { + Family { watch: (0..slots).map(|_| Watch::Unseen).collect(), root_slot } + } + + /// Start watching every process that signed in since the last call, and stop watching the ones + /// that ended. `published` is every `(slot, pid)` signed in so far, the launched one included. + pub(crate) fn refresh(&mut self, root_pid: u32, published: &[(usize, u32)]) { + let mut opened: Vec<(usize, u32, HANDLE)> = Vec::new(); + for &(slot, pid) in published { + let Some(Watch::Unseen) = self.watch.get(slot) else { + continue; + }; + if Some(slot) == self.root_slot { + continue; + } + // SAFETY: a plain open by pid. The handle is closed below once the process ends, or in `Drop`. + match unsafe { OpenProcess(PROCESS_SYNCHRONIZE | PROCESS_QUERY_LIMITED_INFORMATION, false, pid) } { + Ok(handle) => opened.push((slot, pid, handle)), + Err(_) => self.watch[slot] = Watch::Done, + } + } + if !opened.is_empty() { + let known: HashSet = std::iter::once(root_pid).chain(published.iter().map(|&(_, pid)| pid)).collect(); + let entries = process_entries().ok(); + for (slot, pid, handle) in opened { + self.watch[slot] = match member_of_family(pid, &known, entries.as_deref()) { + Some(image) => Watch::Living { pid, handle, image }, + None => { + // SAFETY: opened above and owned by nobody else. + unsafe { + let _ = CloseHandle(handle); + } + Watch::Done + } + }; + } + } + for watch in &mut self.watch { + if let Watch::Living { handle, .. } = watch { + // SAFETY: the handle is ours until it is closed right here or in `Drop`. + let running = unsafe { WaitForSingleObject(*handle, 0) } == WAIT_TIMEOUT; + if !running { + unsafe { + let _ = CloseHandle(*handle); + } + *watch = Watch::Done; + } + } + } + } + + /// The members still running when `refresh` last looked. + pub(crate) fn living(&self) -> Vec { + self.watch + .iter() + .filter_map(|w| match w { + Watch::Living { pid, image, .. } => Some(FamilyMember { pid: *pid, image: image.clone() }), + _ => None, + }) + .collect() + } +} + +impl Drop for Family { + fn drop(&mut self) { + for watch in &self.watch { + if let Watch::Living { handle, .. } = watch { + // SAFETY: each living handle is ours and closed exactly once, here. + unsafe { + let _ = CloseHandle(*handle); + } + } + } + } +} + +/// Whether the process behind a freshly opened handle is the one that signed in, and its image name +/// when it is: `None` when the snapshot no longer lists it (it ended) or lists it with a parent +/// outside the family (its pid was recycled before the first look). A member's parent signed in +/// before starting it, so a parent missing from `known` is somebody else's. +/// +/// A snapshot that could not be read (`entries` is `None`) answers yes, without a name. The handle +/// opened at first sight is the guard that matters, and ending a session under a running application +/// because a list was unreadable would be the failure this module exists to fix. +fn member_of_family(pid: u32, known: &HashSet, entries: Option<&[ProcessEntry]>) -> Option> { + match entries { + None => Some(None), + Some(list) => list + .iter() + .find(|e| e.pid == pid) + .filter(|e| known.contains(&e.parent)) + .map(|e| Some(e.image.clone())), + } +} + +#[cfg(test)] +mod tests { + use super::*; + + fn entry(pid: u32, parent: u32, image: &str) -> ProcessEntry { + ProcessEntry { pid, parent, image: image.to_string() } + } + + #[test] + fn a_process_started_by_the_family_is_a_member_and_is_named() { + let known = HashSet::from([10, 20]); + let list = [entry(30, 20, "app.exe"), entry(40, 99, "other.exe")]; + assert_eq!(member_of_family(30, &known, Some(&list)), Some(Some("app.exe".to_string()))); + } + + #[test] + fn a_recycled_pid_or_an_ended_process_is_not_a_member() { + let known = HashSet::from([10, 20]); + let list = [entry(40, 99, "other.exe")]; + // Pid 40 now belongs to a process started outside the family: its slot's process is gone. + assert_eq!(member_of_family(40, &known, Some(&list)), None); + // Not listed at all: it ended between the open and the snapshot. + assert_eq!(member_of_family(50, &known, Some(&list)), None); + } + + #[test] + fn an_unreadable_snapshot_keeps_the_member_without_a_name() { + let known = HashSet::from([10]); + assert_eq!(member_of_family(30, &known, None), Some(None)); + } + + #[test] + fn the_launched_process_and_a_slot_seen_before_are_left_alone() { + // The launched process is the session's own to watch, and a slot is looked at once: neither + // is opened here, so a pid of this test process in them proves nothing is kept. + let me = std::process::id(); + let mut family = Family::new(4, Some(0)); + family.watch[1] = Watch::Done; + family.refresh(me, &[(0, me), (1, me)]); + assert!(family.living().is_empty()); + assert!(matches!(family.watch[0], Watch::Unseen)); + assert!(matches!(family.watch[1], Watch::Done)); + } + + #[test] + fn a_running_member_is_watched_and_a_stranger_is_not() { + // This test process stands in for a member: started by the process that runs the tests, which + // is listed as signed in, so the snapshot vouches for it. + let me = std::process::id(); + let entries = process_entries().expect("the snapshot is readable"); + let parent = entries.iter().find(|e| e.pid == me).expect("this process is listed").parent; + let mut family = Family::new(4, Some(0)); + family.refresh(parent, &[(0, parent), (2, me)]); + let living = family.living(); + assert_eq!(living.len(), 1, "{living:?}"); + assert_eq!(living[0].pid, me); + assert!(living[0].image.as_deref().is_some_and(|i| !i.is_empty()), "{living:?}"); + // Signed in by a parent outside the family: not a member, and no handle kept. + let mut stranger = Family::new(4, Some(0)); + stranger.refresh(u32::MAX - 1, &[(0, u32::MAX - 1), (2, me)]); + assert!(stranger.living().is_empty()); + assert!(matches!(stranger.watch[2], Watch::Done)); + } +} diff --git a/crates/mech/src/lib.rs b/crates/mech/src/lib.rs index acf314aa..9b6915a2 100644 --- a/crates/mech/src/lib.rs +++ b/crates/mech/src/lib.rs @@ -13,12 +13,14 @@ mod batch; mod environment; +mod family; mod listeners; mod policy; mod tree; pub use batch::{batch_launch_problem, is_batch_script}; pub use environment::{current_environment, encode_block, environment_block, merge_entries}; +pub use family::FamilyMember; pub use listeners::{listening_sockets, Listener, IPV4_ANY_ADDR, IPV4_LOOPBACK_ADDR}; pub use policy::webview2_arguments_policy_present; pub use tree::family_of; @@ -149,6 +151,9 @@ pub struct Session { /// and for the same reason. An entry claimed but not yet written (pid 0) stops the walk for that /// slot until the next poll - the writer fills it within a few instructions of claiming it. consumed_children: Vec, + /// The other processes on the session clock, watched so the session lasts as long as any of them + /// runs and not only as long as the one it launched (ADR-16). + family: family::Family, /// The session lock, held for as long as the session lives. Dropped last, so a second core /// cannot start until this one has released the control block it was using. _lock: SessionLock, @@ -351,6 +356,30 @@ impl Session { unsafe { WaitForSingleObject(self.hprocess, 0) == WAIT_TIMEOUT } } + /// Start watching the processes that joined the session since the last call, and stop watching + /// the ones that ended. Cheap enough for the child poll: a new member costs one open and one + /// process snapshot, a known one a zero-length wait. + pub fn refresh_family(&mut self) { + let published: Vec<(usize, u32)> = (0..MAX_COV_PIDS) + .map(|slot| (slot, unsafe { read_pid(self.ctl(), slot) })) + .filter(|&(_, pid)| pid != 0) + .collect(); + self.family.refresh(self.pid, &published); + } + + /// Whether any process on the session clock is still running: the launched one, or any the hook + /// followed into. A launcher that started the application and ended leaves the session running + /// for the application (ADR-16). + pub fn family_alive(&mut self) -> bool { + self.refresh_family(); + self.is_alive() || !self.family.living().is_empty() + } + + /// The processes besides the launched one that were running when the family was last refreshed. + pub fn living_family(&self) -> Vec { + self.family.living() + } + /// The target's exit code, once it has exited. pub fn exit_code(&self) -> Option { let mut code: u32 = 0; @@ -1317,6 +1346,7 @@ pub fn prepare(spec: &SessionSpec, target: &Target, hook_dll: &Path) -> Result

Result, String> { - let edges = parent_edges()?; + let edges: Vec<(u32, u32)> = process_entries()?.iter().map(|e| (e.pid, e.parent)).collect(); Ok(descendants(root, &edges)) } -/// Every `(pid, parent pid)` pair the snapshot holds. The walk ends only on the one error that means -/// "no more entries" - any other failure is reported, because a list cut short would be handed on -/// as a family with members missing, and a family missing the process that holds the port is a -/// search that quietly finds nothing. -fn parent_edges() -> Result, String> { +/// One process as the snapshot lists it: its pid, the pid of the process that started it, and the +/// file name of its executable. +pub(crate) struct ProcessEntry { + pub(crate) pid: u32, + pub(crate) parent: u32, + pub(crate) image: String, +} + +/// Every process the snapshot holds. The walk ends only on the one error that means "no more +/// entries" - any other failure is reported, because a list cut short would be handed on as a +/// family with members missing, and a family missing the process that holds the port is a search +/// that quietly finds nothing. +pub(crate) fn process_entries() -> Result, String> { // SAFETY: the snapshot handle is closed on every path out, and the entry structure carries its // own size as the API requires. The last error is read right after the failing call, before // anything else can overwrite it. @@ -40,7 +48,7 @@ fn parent_edges() -> Result, String> { dwSize: std::mem::size_of::() as u32, ..Default::default() }; - let mut edges = Vec::new(); + let mut entries = Vec::new(); let mut step = Process32FirstW(snapshot, &mut entry); let outcome = loop { if step.is_err() { @@ -51,14 +59,24 @@ fn parent_edges() -> Result, String> { Err(format!("the process snapshot ended with error {}", error.0)) }; } - edges.push((entry.th32ProcessID, entry.th32ParentProcessID)); + entries.push(ProcessEntry { + pid: entry.th32ProcessID, + parent: entry.th32ParentProcessID, + image: text_up_to_nul(&entry.szExeFile), + }); step = Process32NextW(snapshot, &mut entry); }; let _ = CloseHandle(snapshot); - outcome.map(|()| edges) + outcome.map(|()| entries) } } +/// A fixed-size UTF-16 buffer as the text before its first zero. +fn text_up_to_nul(units: &[u16]) -> String { + let end = units.iter().position(|&u| u == 0).unwrap_or(units.len()); + String::from_utf16_lossy(&units[..end]) +} + /// The root and everything under it, each pid once. Pure over the edge list, so the walk is tested /// on a made-up tree. The edges are indexed by parent first, so a snapshot of a few hundred /// processes read once a second costs one pass over it, not one pass per family member. A parent diff --git a/crates/proto/src/lib.rs b/crates/proto/src/lib.rs index a8346f09..d093a3ac 100644 --- a/crates/proto/src/lib.rs +++ b/crates/proto/src/lib.rs @@ -113,6 +113,15 @@ pub struct UncoveredChild { pub role: Option, } +/// A process on the session clock that was still running when the target closed, so the session +/// went on for it (ADR-16). `image` is the executable's file name when the process list had it. +#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)] +pub struct FollowedProcess { + pub pid: u32, + #[serde(default, skip_serializing_if = "Option::is_none")] + pub image: Option, +} + /// The most uncovered children one `session_verdict` names. A parent's ring holds 32 and the /// registry has 256 slots, so the unbounded list could be thousands of entries in one NDJSON line /// for a family that fans out - the total still travels, the names past this point do not. @@ -275,6 +284,11 @@ pub enum Event { /// Empty for a session that found none, and for a Chromium session, which opened its own. #[serde(default)] engines: Vec, + /// The processes the session went on for after the target closed (ADR-16) - a launcher's + /// application, or a helper that kept the session open. Empty when nothing outlived the + /// target, and for a session that ended while the target ran. Additive. + #[serde(default)] + followed: Vec, }, Ended { v: u32, @@ -492,11 +506,17 @@ mod tests { uncovered_children_total: 3, context_count: 2, engines: vec![ReachedEngine { pid: 8072, port: 51234, browser: "Engine/1.0".into() }], + followed: vec![ + FollowedProcess { pid: 5150, image: Some("app.exe".into()) }, + FollowedProcess { pid: 5151, image: None }, + ], }; let line = ev.to_ndjson(); assert!(line.starts_with(r#"{"type":"session_verdict""#), "got {line}"); assert!(line.contains(r#""context_count":2"#), "got {line}"); assert!(line.contains(r#""engines":[{"pid":8072,"port":51234,"browser":"Engine/1.0"}]"#), "got {line}"); + // A process the list did not name carries no `image` key, as an unnamed child does. + assert!(line.contains(r#""followed":[{"pid":5150,"image":"app.exe"},{"pid":5151}]"#), "got {line}"); // An unnamed child carries no `image` key at all, rather than a null the panel would render. assert!(line.contains(r#"{"pid":4243,"parent_pid":100}"#), "got {line}"); match parse_event(&line).unwrap() { @@ -521,9 +541,12 @@ mod tests { _ => panic!("wrong event variant"), } match parse_event(&line).unwrap() { - Event::SessionVerdict { context_count, engines, .. } => { + Event::SessionVerdict { context_count, engines, followed, .. } => { assert_eq!(context_count, 2); assert_eq!(engines, vec![ReachedEngine { pid: 8072, port: 51234, browser: "Engine/1.0".into() }]); + assert_eq!(followed.len(), 2); + assert_eq!(followed[0], FollowedProcess { pid: 5150, image: Some("app.exe".into()) }); + assert_eq!(followed[1].image, None); } _ => panic!("wrong event variant"), } @@ -546,11 +569,13 @@ mod tests { } _ => panic!("wrong event variant"), } - // And for the two the embedded-engine channel added (docs/09 section 12.4). + // And for the two the embedded-engine channel added (docs/09 section 12.4), and the list of + // processes a session went on for (ADR-16). match parse_event(line).unwrap() { - Event::SessionVerdict { context_count, engines, .. } => { + Event::SessionVerdict { context_count, engines, followed, .. } => { assert_eq!(context_count, 0); assert!(engines.is_empty()); + assert!(followed.is_empty()); } _ => panic!("wrong event variant"), } diff --git a/gui/ChronoMock.App.Tests/LocalizationTests.cs b/gui/ChronoMock.App.Tests/LocalizationTests.cs index dbcd499e..93b2947b 100644 --- a/gui/ChronoMock.App.Tests/LocalizationTests.cs +++ b/gui/ChronoMock.App.Tests/LocalizationTests.cs @@ -58,8 +58,9 @@ public void Available_cultures_are_discovered_by_scanning_the_folder() "embedded.discovery_unavailable", "embedded.qt_port_taken", "embedded.zone_is_host", "embedded.registry_arguments_hidden", "embedded.pages_not_released", "time.fake_clock_clamped", "time.duration_axis_clamped", - // The application outlived the session and was let go (docs/01 section 8.4). - "session.left_running", + // The application outlived the session and was let go (docs/01 section 8.4), and the session + // outlived the program it launched and went on for what that program started (ADR-16). + "session.left_running", "session.followed_family", "chromium.launched_with_debug_port", "chromium.app_closed_before_audit", "chromium.rate_change_affects_running_timers", "chromium.context_ceiling_reached", // Runtime detection warnings the driver appends to coverage (B1): a Python/.NET/Java target whose @@ -75,8 +76,8 @@ public void Available_cultures_are_discovered_by_scanning_the_folder() "runtime.unity_delta_time_capped", // Cleanup residue (EndedEvent residue_keys) - a teardown that could not finish (CDP temp profile). "cleanup.chromium_profile_left", - // Vanish reason (VanishedEvent reason_key, shown inside report.vanish_detail). - "target.single_instance_suspected", + // Vanish reasons (VanishedEvent reason_key, shown inside report.vanish_detail). + "target.single_instance_suspected", "target.handed_off_uncovered", // Start/fatal error keys, surfaced as the status headline (RELEASE-001). "core.hook_dll_missing", "time.bad_mode", "time.bad_multiplier", "moment.invalid", // In-flight jump rejections (Event::Error answering a jump command). Both were missing from diff --git a/gui/ChronoMock.App.Tests/PhaseStates.cs b/gui/ChronoMock.App.Tests/PhaseStates.cs index 8fc2398b..499f476c 100644 --- a/gui/ChronoMock.App.Tests/PhaseStates.cs +++ b/gui/ChronoMock.App.Tests/PhaseStates.cs @@ -111,6 +111,26 @@ public static SessionViewModel ResultWorks() return model; } + ///

+ /// A session that outlived the program it launched: a launcher, or a script running start app.exe, + /// ended and left the application running, and the session went on for it (ADR-16). The warning is what + /// tells the tester why the session lasted longer than the program they chose. + /// + public static SessionViewModel ResultWorksAfterHandOff() + { + var model = ResultRunning(); + model.Apply(new SessionVerdictEvent + { + V = ProtocolJson.ProtocolVersion, + Verdict = "works", + ReasonKey = "session.family_covered", + ProcessCount = 2, + WarningKeys = ["session.followed_family"], + }); + model.Apply(Ended()); + return model; + } + /// A session that only partly worked: the reason and the meaning both have to show under the word. public static SessionViewModel ResultPartial() { @@ -311,7 +331,16 @@ public static SessionViewModel ResultRefused() /// model ignores - rather than on the panel's fixture, which puts a heartbeat first. A heartbeat cannot /// precede a vanish (the session is never entered), and with one the first render of this state showed /// an hour of fake time passing on an application that lived 180 ms. - public static SessionViewModel ResultVanished() + public static SessionViewModel ResultVanished() => Vanished("target.single_instance_suspected", 180); + + /// + /// The target gone after starting a program the hook could not enter, usually one of the other bitness, + /// which runs on the real clock - a hand-off, not a single-instance application (ADR-16). Lived 14 ms, as + /// measured on a 64-bit launcher starting a 32-bit program. + /// + public static SessionViewModel ResultVanishedHandedOff() => Vanished("target.handed_off_uncovered", 14); + + private static SessionViewModel Vanished(string reasonKey, long livedMs) { var model = WithTarget(new SessionViewModel(SeededHistory())); model.Apply(new CoverageEvent @@ -328,8 +357,8 @@ public static SessionViewModel ResultVanished() { V = ProtocolJson.ProtocolVersion, Pid = 4242, - ReasonKey = "target.single_instance_suspected", - LivedMs = 180, + ReasonKey = reasonKey, + LivedMs = livedMs, }); model.Apply(new EndedEvent { V = ProtocolJson.ProtocolVersion, Clean = true }); return model; diff --git a/gui/ChronoMock.App.Tests/StateSheetTests.cs b/gui/ChronoMock.App.Tests/StateSheetTests.cs index f14b9522..a1b3a7d7 100644 --- a/gui/ChronoMock.App.Tests/StateSheetTests.cs +++ b/gui/ChronoMock.App.Tests/StateSheetTests.cs @@ -202,6 +202,8 @@ public void The_result_phase_renders_in_the_outcomes_a_session_can_end_in() total += RenderResult("result-embedded", PhaseStates.ResultPartialWithEmbeddedPages(), "AuditSection").Count; total += RenderResult("result-refused", PhaseStates.ResultRefused()).Count; total += RenderResult("result-vanished", PhaseStates.ResultVanished()).Count; + total += RenderResult("result-vanished-handoff", PhaseStates.ResultVanishedHandedOff()).Count; + total += RenderResult("result-followed", PhaseStates.ResultWorksAfterHandOff(), "AuditSection").Count; total += RenderResult("result-not-started", PhaseStates.ResultNotStarted()).Count; total += RenderResult("result-history", PhaseStates.ResultWithHistoryChosen(), "HistorySection").Count; diff --git a/gui/ChronoMock.App/Localization/Strings.en.json b/gui/ChronoMock.App/Localization/Strings.en.json index 6d62d450..d4cbf527 100644 --- a/gui/ChronoMock.App/Localization/Strings.en.json +++ b/gui/ChronoMock.App/Localization/Strings.en.json @@ -461,7 +461,11 @@ "time.duration_axis_clamped": "The monotonic counters (tick count, unbiased interrupt time, and QPC when scaled) reached the end of their range and stood there, so elapsed time inside the application stopped advancing even though the session went on. A lower speed or a shorter session avoids it.", // The session does not stop the application, so it says which way each clock went once it lets go: "back to real time" alone reads as "the counters went back too", which is what letting go used to do. "session.left_running": "The application was still running when the session ended. It is back on the real date and time now, and its tick counts and elapsed-time counters carry on at normal speed from where the session left them instead of jumping back. A repeating timer it set while its timers were sped up keeps the shorter interval it was given. Restart it for a clean run on the real clock.", - "target.single_instance_suspected": "exited right after it started, before the substitution could be confirmed", + // A launcher, a restart after an update, a script that runs "start app.exe": the program the tester chose ends on purpose and the session goes on for what it started (ADR-16). Says why the session outlived it, and the one way that can surprise. + "session.followed_family": "The program you started closed while programs it had started were still running on the fake clock, so the session went on until the last of them closed. A program that keeps running after the application closes keeps the session open too - stop the session when you are done.", + // The vanish reasons complete the sentence under "The application ran for N ms and then vanished", and each carries its own suspicion, because report.vanish_detail no longer names one for all of them. + "target.single_instance_suspected": "exited right after it started, before the substitution could be confirmed - usually a single-instance application handing over to a copy that is already running", + "target.handed_off_uncovered": "closed right after starting another program that could not be given the fake clock - usually one of a different bitness - so that program runs on the real one", // Runtime detected statically from the target's files (B1): its monotonic/elapsed clocks stand on QueryPerformanceCounter, which stays real (ADR-2), so a timer built on them does not scale even though the wall clock does. Wording mirrors the CLI describe_warning. "runtime.python_monotonic_qpc": "This Python app measures time with perf_counter and monotonic - both use QueryPerformanceCounter on Python 3.13+, which is left real, so a timer built on them does not scale (time.time and the wall clock do).", @@ -500,7 +504,7 @@ "report.verdict": "verdict", "report.no_verdict": "no verdict emitted", "report.did_not_take_effect": "DID NOT TAKE EFFECT - the target vanished right after injection", - "report.vanish_detail": "suspected single-instance app: {0} - lived {1} ms", + "report.vanish_detail": "{0} - lived {1} ms", "report.processes": "processes: {0}", "report.session": "session", "report.session_reached": "fake clock reached {0}", diff --git a/gui/ChronoMock.App/Localization/Strings.pl.json b/gui/ChronoMock.App/Localization/Strings.pl.json index e9547b69..cfbf0670 100644 --- a/gui/ChronoMock.App/Localization/Strings.pl.json +++ b/gui/ChronoMock.App/Localization/Strings.pl.json @@ -442,7 +442,9 @@ "time.fake_clock_clamped": "Fałszywy zegar doszedł do ostatniej daty, jaką ta wersja potrafi wyrazić (rok 30828), i stanął tam do końca sesji. Późniejsze odczyty nie są momentami, które dałaby wybrana prędkość.", "time.duration_axis_clamped": "Liczniki monotoniczne (licznik tyknięć, nieobciążony czas przerwań oraz QPC, gdy skalowany) doszły do końca swojego zakresu i stanęły, więc czas, jaki upłynął wewnątrz aplikacji, przestał rosnąć, mimo że sesja trwała dalej. Mniejsza prędkość albo krótsza sesja tego unika.", "session.left_running": "Aplikacja nadal działała, gdy sesja się skończyła. Jest już z powrotem na prawdziwej dacie i godzinie, a jej liczniki czasu biegną dalej w normalnym tempie od miejsca, w którym zostawiła je sesja, zamiast się cofnąć. Timer cykliczny ustawiony, gdy jej timery były przyspieszone, zachowuje skrócony odstęp, który wtedy dostał. Żeby wystartowała od zera na prawdziwym zegarze, uruchom ją ponownie.", - "target.single_instance_suspected": "zakończył się zaraz po uruchomieniu, zanim podmianę dało się potwierdzić", + "session.followed_family": "Program wybrany do sesji zakończył się, gdy uruchomione przez niego programy nadal działały na fałszywym zegarze, więc sesja trwała, dopóki ostatni z nich się nie zamknął. Program, który działa dalej po zamknięciu aplikacji, też trzyma sesję otwartą - zatrzymaj sesję, gdy skończysz.", + "target.single_instance_suspected": "zakończył się zaraz po uruchomieniu, zanim podmianę dało się potwierdzić - zwykle to aplikacja jednoinstancyjna, która przekazała pracę swojej działającej już kopii", + "target.handed_off_uncovered": "zakończył się zaraz po uruchomieniu innego programu, któremu nie udało się podać fałszywego zegara - zwykle programu o innej bitowości - więc ten program działa na prawdziwym", // Runtime detected statically from the target's files (B1): its monotonic/elapsed clocks stand on QueryPerformanceCounter, which stays real (ADR-2), so a timer built on them does not scale even though the wall clock does. Wording mirrors the CLI describe_warning. "runtime.python_monotonic_qpc": "Ta aplikacja Python mierzy czas przez perf_counter i monotonic - oba używają QueryPerformanceCounter w Pythonie 3.13+, który zostaje realny, więc licznik na nich oparty nie skaluje (time.time i zegar ścienny tak).", @@ -481,7 +483,7 @@ "report.verdict": "werdykt", "report.no_verdict": "brak werdyktu", "report.did_not_take_effect": "NIE ZADZIAŁAŁO - cel zniknął zaraz po wstrzyknięciu", - "report.vanish_detail": "podejrzenie aplikacji jednoinstancyjnej: {0} - działał {1} ms", + "report.vanish_detail": "{0} - działał {1} ms", "report.processes": "procesy: {0}", "report.session": "sesja", "report.session_reached": "fałszywy zegar osiągnął {0}", diff --git a/site/pages/cli-reference/en.html b/site/pages/cli-reference/en.html index 39a91a09..36d831ef 100644 --- a/site/pages/cli-reference/en.html +++ b/site/pages/cli-reference/en.html @@ -185,7 +185,7 @@

chrono run - exit codes

10works partially - some channels covered, some not 11does not work - the substitution did not reach the key channels 4undetermined - coverage could not be established. An honest "cannot tell", never a pretended pass - 12the target vanished right after injection, which suggests a single-instance application handing over to a copy already running + 12the target vanished right after injection and left nothing running on the session clock, which suggests a single-instance application handing over to a copy already running, or a hand-off to a program the session could not enter, usually one of the other bitness. A target that starts the application and ends is a launcher, and the session goes on for the application 1usage error - a bad flag, a bad expression, or a preset this command will not accept 2the target could not be launched or injected 3internal error - the engine could not start or hit an unexpected state diff --git a/site/pages/cli-reference/pl.html b/site/pages/cli-reference/pl.html index 02c8d2c0..d524afe5 100644 --- a/site/pages/cli-reference/pl.html +++ b/site/pages/cli-reference/pl.html @@ -185,7 +185,7 @@

chrono run - kody wyjścia

10działa częściowo - część kanałów objęta, część nie 11nie działa - podmiana nie dosięgła kluczowych kanałów 4nieokreślony - nie dało się ustalić pokrycia. Uczciwe „nie wiem", nigdy udawane „działa" - 12cel zniknął zaraz po wstrzyknięciu, co wskazuje na aplikację jednoinstancyjną, która oddała robotę już działającej kopii + 12cel zniknął zaraz po wstrzyknięciu i nie zostawił niczego na zegarze sesji, co wskazuje na aplikację jednoinstancyjną, która oddała robotę już działającej kopii, albo na przekazanie programowi, do którego sesja nie mogła wejść, zwykle o innej bitowości. Cel, który uruchamia aplikację i się kończy, to launcher - sesja idzie dalej za aplikacją 1błąd użycia - zła flaga, złe wyrażenie albo preset, którego ta komenda nie przyjmuje 2nie udało się uruchomić celu albo wstrzyknąć do niego biblioteki 3błąd wewnętrzny - rdzeń nie wystartował albo trafił na nieoczekiwany stan From 3121f7b37e0c4b7dc93f85ddb31ab7562fd6a391 Mon Sep 17 00:00:00 2001 From: DonislawDev Date: Fri, 25 Sep 2026 11:45:45 +0200 Subject: [PATCH 3/3] fix: say the session went on for the processes it followed, not until they closed Review round on the session that lasts for its family (ADR-16): - The warning and the report heading said the session went on until the last followed program closed. A Stop or `--ticks` ends the session while one still runs, and `session.left_running` says so beside it. Both now say the session went on for them, in the CLI and in the window (EN, PL), and the report test keeps the heading from claiming they closed. - A followed process was opened for waiting and for querying, and only waiting is used. Asking for the unused right could fail on a process that grants waiting alone and end the session under it. It now asks for waiting only. A process that denies even that still counts as ended, because it cannot be told from one that exited. - The two new state-sheet renders only had to be non-empty. They now have to show the translated reason and warning on a visible element. - `--ticks` in the CLI reference, and the `--dry-run` plan without it, said the tool stays until the target exits. They now say until the target and what it started on the session clock have exited. Co-Authored-By: Claude Opus 5.5 --- crates/cli/src/core.rs | 2 ++ crates/cli/src/report.rs | 8 ++++++-- crates/cli/src/run/mod.rs | 5 +++-- crates/cli/src/run/plan.rs | 4 +++- crates/mech/src/family.rs | 10 ++++++---- gui/ChronoMock.App.Tests/StateSheetTests.cs | 17 +++++++++++++++-- gui/ChronoMock.App/Localization/Strings.en.json | 2 +- gui/ChronoMock.App/Localization/Strings.pl.json | 2 +- site/pages/cli-reference/en.html | 4 +++- site/pages/cli-reference/pl.html | 4 +++- 10 files changed, 43 insertions(+), 15 deletions(-) diff --git a/crates/cli/src/core.rs b/crates/cli/src/core.rs index 10e6ad4c..a699fc0b 100644 --- a/crates/cli/src/core.rs +++ b/crates/cli/src/core.rs @@ -603,6 +603,8 @@ const KEY_LEFT_RUNNING: &str = "session.left_running"; /// The target closed while processes it had started were still running on the session clock, and /// the session went on for them (ADR-16). Said because a session that outlives the program the /// tester named is a surprise unless it is explained, and a helper that never ends keeps it open. +/// It says the session went on for them, never that it lasted until they closed: a Stop or `--ticks` +/// can end it while one still runs, and `session.left_running` then says that beside it. const KEY_FOLLOWED_FAMILY: &str = "session.followed_family"; /// The target vanished inside the guard window after starting a process the hook could not enter, diff --git a/crates/cli/src/report.rs b/crates/cli/src/report.rs index 13894ec9..db9e6ab9 100644 --- a/crates/cli/src/report.rs +++ b/crates/cli/src/report.rs @@ -317,7 +317,7 @@ pub(crate) fn describe_warning(key: &str) -> String { // A session that outlives the program the tester named is a surprise unless it is explained - // a launcher is the case it exists for, a helper that never ends is the case it warns about. "session.followed_family" => { - "the target closed while programs it had started were still running on the session clock, so the session went on until the last of them closed - the programs listed under 'followed' are the ones it went on for, and one that keeps running after the application closes keeps the session open too" + "the target closed while programs it had started were still running on the session clock, so the session went on for them instead of ending with it - the programs listed under 'followed' are the ones it went on for, and one that keeps running after the application closes keeps the session open too" } "embedded.pages_not_released" => { "a page inside the application did not confirm it was handed back to the real clock when the session ended, so it may keep the session date until it is reloaded or closed" @@ -607,7 +607,9 @@ fn render_followed(followed: &[chrono_proto::FollowedProcess]) -> String { if followed.is_empty() { return String::new(); } - let mut out = String::from(" followed: the target had started these, and the session went on until they closed:\n"); + // "went on for", not "until they closed": a Stop or `--ticks` can end the session while one of them + // still runs, and `session.left_running` says so on its own line. + let mut out = String::from(" followed: the target had started these, and the session went on for them:\n"); for p in followed { match &p.image { Some(image) => out.push_str(&format!(" - {image} (pid {})\n", p.pid)), @@ -1091,6 +1093,8 @@ mod tests { assert!(exited < followed, "got:\n{out}"); assert!(out.contains("- app.exe (pid 5150)"), "got:\n{out}"); assert!(out.contains("- pid 5151\n"), "got:\n{out}"); + // A Stop can end the session while one of them still runs, so the heading never says they closed. + assert!(!out.contains("closed:"), "got:\n{out}"); // Nothing followed, no line. assert!(!render_report(&empty_report()).contains("followed:")); } diff --git a/crates/cli/src/run/mod.rs b/crates/cli/src/run/mod.rs index 95083f73..51054fb1 100644 --- a/crates/cli/src/run/mod.rs +++ b/crates/cli/src/run/mod.rs @@ -261,8 +261,9 @@ pub(crate) fn driver_run(argv: &[String]) -> i32 { } // Everything else is evidence rather than a cue to act, so the collector owns // it. Nothing happens on a verdict on purpose: with ticks == 0 the run stays - // attached until the target exits, because detaching early would revert it to - // real time (self-detach). With ticks > 0 the state arm above ends the session + // attached until the session ends by itself, when the target and everything it + // started on the session clock have exited (ADR-16), because detaching early would + // revert them to real time (self-detach). With ticks > 0 the state arm above ends the session // after that many heartbeats. `ended` is the one event that stops the read. Ok(event) => { if collected.record(event) { diff --git a/crates/cli/src/run/plan.rs b/crates/cli/src/run/plan.rs index 5f61615c..fbfb54e0 100644 --- a/crates/cli/src/run/plan.rs +++ b/crates/cli/src/run/plan.rs @@ -313,7 +313,9 @@ fn session_block(p: &Plan) -> String { out.push_str(&line( "session", &match p.ra.ticks { - 0 => "runs until the target exits".to_string(), + // The target and whatever it started on the session clock (ADR-16): a launcher that ends + // at once does not end the session. + 0 => "runs until the target, and whatever it started on the session clock, has exited".to_string(), n => format!("ends after {n} state heartbeats, about {n} real seconds"), }, )); diff --git a/crates/mech/src/family.rs b/crates/mech/src/family.rs index befb4081..b415a862 100644 --- a/crates/mech/src/family.rs +++ b/crates/mech/src/family.rs @@ -17,9 +17,7 @@ use std::collections::HashSet; use windows::Win32::Foundation::{CloseHandle, HANDLE, WAIT_TIMEOUT}; -use windows::Win32::System::Threading::{ - OpenProcess, WaitForSingleObject, PROCESS_QUERY_LIMITED_INFORMATION, PROCESS_SYNCHRONIZE, -}; +use windows::Win32::System::Threading::{OpenProcess, WaitForSingleObject, PROCESS_SYNCHRONIZE}; use crate::tree::{process_entries, ProcessEntry}; @@ -65,8 +63,12 @@ impl Family { if Some(slot) == self.root_slot { continue; } + // Waiting is all the handle is for, so waiting is all it asks: a process that grants that and + // denies more stays watchable. One that denies even this cannot be told from one that ended + // (both fail to open), so it counts as ended - the session then ends as it did before ADR-16, + // rather than holding on to a process it can never see close. // SAFETY: a plain open by pid. The handle is closed below once the process ends, or in `Drop`. - match unsafe { OpenProcess(PROCESS_SYNCHRONIZE | PROCESS_QUERY_LIMITED_INFORMATION, false, pid) } { + match unsafe { OpenProcess(PROCESS_SYNCHRONIZE, false, pid) } { Ok(handle) => opened.push((slot, pid, handle)), Err(_) => self.watch[slot] = Watch::Done, } diff --git a/gui/ChronoMock.App.Tests/StateSheetTests.cs b/gui/ChronoMock.App.Tests/StateSheetTests.cs index a1b3a7d7..f054e094 100644 --- a/gui/ChronoMock.App.Tests/StateSheetTests.cs +++ b/gui/ChronoMock.App.Tests/StateSheetTests.cs @@ -202,8 +202,8 @@ public void The_result_phase_renders_in_the_outcomes_a_session_can_end_in() total += RenderResult("result-embedded", PhaseStates.ResultPartialWithEmbeddedPages(), "AuditSection").Count; total += RenderResult("result-refused", PhaseStates.ResultRefused()).Count; total += RenderResult("result-vanished", PhaseStates.ResultVanished()).Count; - total += RenderResult("result-vanished-handoff", PhaseStates.ResultVanishedHandedOff()).Count; - total += RenderResult("result-followed", PhaseStates.ResultWorksAfterHandOff(), "AuditSection").Count; + total += Shows(RenderResult("result-vanished-handoff", PhaseStates.ResultVanishedHandedOff()), "target.handed_off_uncovered"); + total += Shows(RenderResult("result-followed", PhaseStates.ResultWorksAfterHandOff(), "AuditSection"), "session.followed_family"); total += RenderResult("result-not-started", PhaseStates.ResultNotStarted()).Count; total += RenderResult("result-history", PhaseStates.ResultWithHistoryChosen(), "HistorySection").Count; @@ -217,6 +217,19 @@ public void The_result_phase_renders_in_the_outcomes_a_session_can_end_in() Assert.True(written > 0); } + /// + /// The render shows the text translates to, on a visible element. A state whose + /// reason or warning went missing still lays out its card and its sections, so a non-empty render says + /// nothing about the one line the state exists to show (ADR-16). + /// + private static int Shows(IReadOnlyList rendered, string key) + { + var text = Application.Current.TryFindResource(key) as string; + Assert.False(string.IsNullOrEmpty(text), $"{key} has no translation to look for"); + Assert.Contains(rendered, e => e.IsVisible && e.Text.Contains(text!, StringComparison.Ordinal)); + return rendered.Count; + } + private static IReadOnlyList RenderResult( string name, SessionViewModel model, diff --git a/gui/ChronoMock.App/Localization/Strings.en.json b/gui/ChronoMock.App/Localization/Strings.en.json index d4cbf527..3fb356fa 100644 --- a/gui/ChronoMock.App/Localization/Strings.en.json +++ b/gui/ChronoMock.App/Localization/Strings.en.json @@ -462,7 +462,7 @@ // The session does not stop the application, so it says which way each clock went once it lets go: "back to real time" alone reads as "the counters went back too", which is what letting go used to do. "session.left_running": "The application was still running when the session ended. It is back on the real date and time now, and its tick counts and elapsed-time counters carry on at normal speed from where the session left them instead of jumping back. A repeating timer it set while its timers were sped up keeps the shorter interval it was given. Restart it for a clean run on the real clock.", // A launcher, a restart after an update, a script that runs "start app.exe": the program the tester chose ends on purpose and the session goes on for what it started (ADR-16). Says why the session outlived it, and the one way that can surprise. - "session.followed_family": "The program you started closed while programs it had started were still running on the fake clock, so the session went on until the last of them closed. A program that keeps running after the application closes keeps the session open too - stop the session when you are done.", + "session.followed_family": "The program you started closed while programs it had started were still running on the fake clock, so the session went on for them instead of ending with it. A program that keeps running after the application closes keeps the session open too - stop the session when you are done.", // The vanish reasons complete the sentence under "The application ran for N ms and then vanished", and each carries its own suspicion, because report.vanish_detail no longer names one for all of them. "target.single_instance_suspected": "exited right after it started, before the substitution could be confirmed - usually a single-instance application handing over to a copy that is already running", "target.handed_off_uncovered": "closed right after starting another program that could not be given the fake clock - usually one of a different bitness - so that program runs on the real one", diff --git a/gui/ChronoMock.App/Localization/Strings.pl.json b/gui/ChronoMock.App/Localization/Strings.pl.json index cfbf0670..677a2669 100644 --- a/gui/ChronoMock.App/Localization/Strings.pl.json +++ b/gui/ChronoMock.App/Localization/Strings.pl.json @@ -442,7 +442,7 @@ "time.fake_clock_clamped": "Fałszywy zegar doszedł do ostatniej daty, jaką ta wersja potrafi wyrazić (rok 30828), i stanął tam do końca sesji. Późniejsze odczyty nie są momentami, które dałaby wybrana prędkość.", "time.duration_axis_clamped": "Liczniki monotoniczne (licznik tyknięć, nieobciążony czas przerwań oraz QPC, gdy skalowany) doszły do końca swojego zakresu i stanęły, więc czas, jaki upłynął wewnątrz aplikacji, przestał rosnąć, mimo że sesja trwała dalej. Mniejsza prędkość albo krótsza sesja tego unika.", "session.left_running": "Aplikacja nadal działała, gdy sesja się skończyła. Jest już z powrotem na prawdziwej dacie i godzinie, a jej liczniki czasu biegną dalej w normalnym tempie od miejsca, w którym zostawiła je sesja, zamiast się cofnąć. Timer cykliczny ustawiony, gdy jej timery były przyspieszone, zachowuje skrócony odstęp, który wtedy dostał. Żeby wystartowała od zera na prawdziwym zegarze, uruchom ją ponownie.", - "session.followed_family": "Program wybrany do sesji zakończył się, gdy uruchomione przez niego programy nadal działały na fałszywym zegarze, więc sesja trwała, dopóki ostatni z nich się nie zamknął. Program, który działa dalej po zamknięciu aplikacji, też trzyma sesję otwartą - zatrzymaj sesję, gdy skończysz.", + "session.followed_family": "Program wybrany do sesji zakończył się, gdy uruchomione przez niego programy nadal działały na fałszywym zegarze, więc sesja trwała dalej dla nich, zamiast skończyć się razem z nim. Program, który działa dalej po zamknięciu aplikacji, też trzyma sesję otwartą - zatrzymaj sesję, gdy skończysz.", "target.single_instance_suspected": "zakończył się zaraz po uruchomieniu, zanim podmianę dało się potwierdzić - zwykle to aplikacja jednoinstancyjna, która przekazała pracę swojej działającej już kopii", "target.handed_off_uncovered": "zakończył się zaraz po uruchomieniu innego programu, któremu nie udało się podać fałszywego zegara - zwykle programu o innej bitowości - więc ten program działa na prawdziwym", diff --git a/site/pages/cli-reference/en.html b/site/pages/cli-reference/en.html index 36d831ef..bcf67115 100644 --- a/site/pages/cli-reference/en.html +++ b/site/pages/cli-reference/en.html @@ -86,7 +86,9 @@

chrono run - options

--ticks N End the session after N heartbeats, one real second each, and report. Without it - the tool stays attached until the target exits. + the tool stays attached until the target, and every program it started that runs on the + session clock, has exited - a launcher that ends at once leaves the session to the + application it started. --timeout <s> diff --git a/site/pages/cli-reference/pl.html b/site/pages/cli-reference/pl.html index d524afe5..c5c9d70a 100644 --- a/site/pages/cli-reference/pl.html +++ b/site/pages/cli-reference/pl.html @@ -85,7 +85,9 @@

chrono run - opcje

--ticks N Kończy sesję po N biciach serca, każde po jednej realnej sekundzie, i raportuje. - Bez tej flagi narzędzie zostaje przy celu do jego wyjścia. + Bez tej flagi narzędzie zostaje przy sesji, dopóki działa cel albo którykolwiek + uruchomiony przez niego program na zegarze sesji - launcher, który kończy się od razu, + zostawia sesję uruchomionej przez siebie aplikacji. --timeout <s>