fix: let the session last for the processes on its clock, not the first one

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

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.

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(),
     });
 }
 

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<Vec<FamilyMember>>,
 }
 
 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,35 @@ 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.
+/// 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,
+/// 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 +646,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 +717,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 +746,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 +1338,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");
+    }
 }

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<chrono_proto::ReachedEngine>,
+    /// 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<chrono_proto::FollowedProcess>,
     /// 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 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"
         }
@@ -581,6 +589,36 @@ 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();
+    }
+    // "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)),
+            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 +708,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 +779,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 +920,7 @@ mod tests {
             warnings: vec![],
             context_count: 0,
             engines: vec![],
+            followed: vec![],
             uncovered: vec![],
             unobserved: vec![],
             installed_late: vec![],
@@ -1020,6 +1058,45 @@ 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}");
+        // 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:"));
     }
 
     #[test]