main
Drew Owens 0.11.2 source 784acbf 5d ago
//! ADVERSARIAL REVIEW OF 0.4.1 — round two.
//!
//! Round one's fourteen findings are closed (see `tests/adversary.rs`, all
//! passing). These are the ways round to the same places, plus the surfaces the
//! fixes themselves opened. Every test here FAILS on 6af68ab.
//!
//! The theme, again: an unanswerable question answered definitely. The kill
//! path now verifies identity beautifully at the moment of the kill — and
//! decides WHICH processes are ours from a first-come-first-served rule that
//! cannot tell our launcher chain from the user's.

mod common;

use common::{Bridge, TempDir};
use serde_json::{json, Value};
use std::time::{Duration, Instant};
use swx_bridge::launch;
use swx_bridge::launchos::{stamp_of, LogFile, ProcInfo};

fn s(v: &Value) -> String {
    serde_json::to_string_pretty(v).unwrap_or_default()
}

fn p(pid: u32, image: &str, created: u64, ppid: Option<u32>) -> ProcInfo {
    ProcInfo { pid, image: image.to_string(), created_at: Some(created), ppid }
}

struct Sim {
    dir: TempDir,
}

impl Sim {
    fn new(tag: &str, routes: Value) -> Sim {
        let dir = TempDir::new(tag);
        std::fs::write(dir.join("routes.json"), routes.to_string()).unwrap();
        let sim = Sim { dir };
        sim.write_preexisting(Sim::daemons());
        sim
    }

    fn daemons() -> Vec<Value> {
        vec![
            json!({"pid": 6076, "image": "3DEXPERIENCELauncher.exe", "ageSeconds": 30000}),
            json!({"pid": 90552, "image": "3DEXPERIENCELauncherSysTray.exe", "ageSeconds": 30000}),
            json!({"pid": 90553, "image": "3DEXPERIENCELauncherService.exe", "ageSeconds": 30000}),
        ]
    }

    fn write_preexisting(&self, rows: Vec<Value>) {
        std::fs::write(self.dir.join("preexisting.json"), Value::Array(rows).to_string()).unwrap();
    }

    fn lines(&self, file: &str) -> Vec<Value> {
        std::fs::read_to_string(self.dir.join(file))
            .unwrap_or_default()
            .lines()
            .filter_map(|l| serde_json::from_str(l).ok())
            .collect()
    }

    fn invocations(&self) -> Vec<String> {
        self.lines("invocations.jsonl")
            .iter()
            .filter_map(|v| v.get("route").and_then(|r| r.as_str()).map(String::from))
            .collect()
    }

    fn terminated(&self) -> Vec<u64> {
        self.lines("terminated.jsonl").iter().filter_map(|v| v.get("pid")?.as_u64()).collect()
    }

    fn boot(&self, scratch: TempDir, extra: &[(&str, &str)]) -> Bridge {
        let lnk = format!("{}/SOLIDWORKS Design.lnk", self.dir.path());
        std::fs::write(&lnk, "not really a shortcut").unwrap();
        let mut env: Vec<(&str, &str)> = vec![
            ("SWX_SOLIDWORKS_SHORTCUT", Box::leak(lnk.into_boxed_str())),
            ("SWX_LAUNCH_FAKE_DIR", Box::leak(self.dir.path().into_boxed_str())),
            ("SWX_LAUNCH_RUN_BEGIN_SECS", "2"),
            ("SWX_LAUNCH_SLDWORKS_SECS", "4"),
            ("SWX_LAUNCH_ATTACH_SECS", "8"),
            ("SWX_LAUNCH_POLL_MS", "100"),
            ("SWX_LAUNCH_RETRY_SETTLE_MS", "400"),
            ("SWX_LAUNCH_ATTACH_POLL_MS", "150"),
            ("SWX_LAUNCH_INFLIGHT_SECS", "120"),
            ("SWX_LAUNCH_BACKOFF_SECS", "0"),
        ];
        env.extend_from_slice(extra);
        Bridge::start_in(scratch, &env)
    }
}

fn wait_for_launch(b: &Bridge, secs: u64) -> Value {
    let deadline = Instant::now() + Duration::from_secs(secs);
    loop {
        let last = b.call("swx_status", json!({}));
        if last["launch"]["finished"] == true || Instant::now() > deadline {
            return last;
        }
        std::thread::sleep(Duration::from_millis(150));
    }
}

// ════════════════════════════════════════════════════════════════════════════
// 1. CHAIN ATTRIBUTION — the fix moved the problem, it did not remove it
// ════════════════════════════════════════════════════════════════════════════

/// `chain_candidates` doc: *"A process whose parent is a pid we never started is
/// never adopted."* — except for the one that matters. The root rule is
///
/// ```text
/// let is_root = p.is("CATSTART.exe") && ids.is_empty();
/// ```
///
/// i.e. **the first CATSTART to appear after our invoke, in census order, is
/// declared ours** with no evidence at all. Parentage cannot help: the census
/// only contains `WATCHED_IMAGES`, so a CATSTART's parent (explorer.exe,
/// cmd.exe, powershell.exe) is never in it and `descends` is always false for
/// the root. Worse, for route `explorer` — the DEFAULT, tried first — our
/// CATSTART and a Start-Menu CATSTART have literally the same parent: the
/// user's shell.
///
/// The field case is the one the release already documents: a route that starts
/// nothing (`M1`, fixed in this very round), while the user — watching nothing
/// happen — starts SOLIDWORKS themselves. Their chain is then the only CATSTART
/// younger than our invoke, so it is adopted as ours and ended at the deadline.
#[test]
fn a_user_chain_that_appears_while_our_route_started_nothing_is_never_adopted() {
    // Every route invokes and starts nothing at all — the failure this round
    // taught the bridge to name honestly.
    let m = Sim::new(
        "adv2-adopt",
        json!({"explorer": {"chain": false}, "shellExecute": {"chain": false},
               "powershell": {"chain": false}, "cmdStart": {"chain": false}}),
    );
    let b = m.boot(TempDir::new("adv2-scratch"), &[]);
    b.call("swx_start", json!({"reason": "modelling a bracket", "waitSeconds": 0}));

    // The user gives up waiting and starts SOLIDWORKS from their Start Menu.
    // ageSeconds 0 => created now, i.e. after our invoke and not in our baseline.
    std::thread::sleep(Duration::from_millis(400));
    let mut rows = Sim::daemons();
    rows.push(json!({"pid": 70003, "image": "CATSTART.exe", "ageSeconds": 0}));
    rows.push(json!({"pid": 70004, "image": "SWXDesktopLauncher.exe", "ageSeconds": 0, "ppid": 70003}));
    m.write_preexisting(rows);

    // Watch what the bridge decides is "our chain" while it is deciding it.
    let mut adopted: Vec<Value> = Vec::new();
    for _ in 0..8 {
        std::thread::sleep(Duration::from_millis(150));
        let st = b.call("swx_status", json!({}));
        if let Some(pids) = st["launch"]["chainPids"].as_array() {
            adopted.extend(pids.iter().cloned());
        }
    }
    let st = wait_for_launch(&b, 30);

    let claimed: Vec<u64> =
        adopted.iter().filter_map(|c| c.get("pid").and_then(|p| p.as_u64())).collect();
    for theirs in [70003u64, 70004] {
        assert!(
            !claimed.contains(&theirs),
            "the bridge recorded pid {theirs} — a launcher chain the USER started — as part of \
             the chain IT started. Nothing it invoked ever ran, so the first CATSTART to appear \
             after the invoke was adopted on the strength of being first.\n\
             claimed: {claimed:?}\nlaunch: {}\n--- server log ---\n{}",
            s(&st["launch"]),
            b.log()
        );
        assert!(
            !m.terminated().contains(&theirs),
            "...and then terminated it: {:?}",
            m.terminated()
        );
    }
}

/// The same rule, stated purely: two CATSTARTs appear after our invoke and
/// neither is in the baseline. One is ours, one is the user's, and nothing in
/// the census distinguishes them — so the answer must be "I cannot tell", not
/// "whichever the OS listed first".
#[test]
fn the_first_catstart_after_our_invoke_is_not_proof_that_it_is_ours() {
    let invoked = 1_000_000u64;
    let census = vec![
        // The user's, listed first — toolhelp order is roughly pid order, and
        // pids do not say who asked for the process.
        p(70003, "CATSTART.exe", invoked + 2, Some(4444)),
        p(70004, "SWXDesktopLauncher.exe", invoked + 3, Some(70003)),
        // Ours.
        p(90010, "CATSTART.exe", invoked + 1, Some(4444)),
        p(90011, "SWXDesktopLauncher.exe", invoked + 2, Some(90010)),
    ];
    let ours = launch::chain_candidates(&census, &[], &[], invoked);
    let pids: Vec<u32> = ours.iter().map(|x| x.pid).collect();
    assert!(
        !pids.contains(&70003) && !pids.contains(&70004),
        "with two indistinguishable chains the bridge adopted the one the census listed FIRST \
         and called it ours: {pids:?}. Both have the same parent (the shell), which is what \
         route 'explorer' produces for our own launch too, so parentage cannot break the tie \
         either. The honest answer is to attribute neither and say the chain is unknown."
    );
}

/// `chain_candidates` pass 1 re-confirms the previous census's answer by PID
/// ALONE:
///
/// ```text
/// if ids.contains(&p.pid) && may_terminate(&p.image, p.created_at, invoked_at) {
/// ```
///
/// `ProcInfo::same_process` — added this round precisely because "a pid alone is
/// not an identity" — is used at the kill and not here. CATSTART exits about
/// three seconds into a healthy launch, so its number is free for the rest of a
/// four-minute watch; anything that takes it and happens to be a launcher image
/// is re-adopted into our chain, and the kill path then verifies the identity of
/// the process we wrongly adopted.
#[test]
fn a_recycled_pid_is_not_re_adopted_into_our_chain_by_number_alone() {
    let invoked = 1_000_000u64;
    // 90010 WAS our CATSTART: seeded from an earlier census, created at
    // invoked+1. It exited. The number now belongs to a chain the user started
    // two minutes later.
    let census = vec![p(90010, "CATSTART.exe", invoked + 120, Some(4444))];
    let ours = launch::chain_candidates(&census, &[], &[90010], invoked);
    assert!(
        ours.is_empty(),
        "pid 90010 was re-adopted into our chain although it is a different process now \
         (created at {} vs the {} we recorded). The seed is a list of numbers, not of \
         identities — ProcInfo::same_process exists for exactly this and is not used here.",
        invoked + 120,
        invoked + 1
    );
}

/// `run_supervisor` records `baseline_known`, and `watch_route` correctly
/// records NO chain when the baseline could not be taken. What it then does is
/// go on as if there were nothing to clean: `clean_up_chain` reads an empty
/// recorded chain, asks the census (which now works), and answers
/// `failed: false` — "there was nothing to attribute" rather than "I was never
/// able to attribute anything". Three more routes follow, each starting another
/// chain, with the first still running.
#[test]
fn a_baseline_that_could_not_be_taken_is_not_a_clean_cleanup() {
    let m = Sim::new("adv2-blindbaseline", json!({}));
    // The census is down when the route takes its baseline...
    std::fs::write(m.dir.join("census-fails"), "").unwrap();
    let b = m.boot(TempDir::new("adv2-scratch"), &[]);
    b.call("swx_start", json!({"reason": "starting SOLIDWORKS", "waitSeconds": 0}));
    // ...and back up a moment later, so every LATER look succeeds.
    std::thread::sleep(Duration::from_millis(400));
    let _ = std::fs::remove_file(m.dir.join("census-fails"));
    let st = wait_for_launch(&b, 40);

    assert!(
        !m.invocations().is_empty(),
        "precondition: a route was invoked and started a chain: {:?}",
        m.invocations()
    );
    let first = &st["launch"]["routesTried"][0];
    let killed = m.terminated();
    // The simulator's first chain is 900010/900011.
    let accounted = killed.contains(&900010)
        || first["cleanupFailed"] == true
        || !first["chainLeftRunning"].as_array().map(|a| a.is_empty()).unwrap_or(true);
    assert!(
        accounted,
        "route 1 started a launcher chain the bridge could not attribute (its baseline census \
         failed), and the report records the stall with cleanupFailed:false and nothing left \
         running — so the machine went on to invoke {} routes in total while that chain was \
         still on the machine, unkilled and unmentioned.\nterminated: {killed:?}\n\
         routesTried[0]: {}\n--- server log ---\n{}",
        m.invocations().len(),
        s(first),
        b.log()
    );
}

// ════════════════════════════════════════════════════════════════════════════
// 2. THE LAUNCHER-LOG BASELINE — a new empty-to-confident collapse
// ════════════════════════════════════════════════════════════════════════════

/// `run_supervisor`:
///
/// ```text
/// let (base_stamp, base_created) = newest_log(&os.launcher_logs().unwrap_or_default());
/// ```
///
/// A launcher-log listing that FAILED (APPDATA unset, the directory unreadable,
/// a permissions change) becomes "there were no logs" — and `is_newer_than`
/// answers `(Some(_), None) => true`, i.e. **any log is ours**. The bridge then
/// reads a log from a previous day, finds `Run Begin` in it (five of the nine
/// logs on the real machine contain it), jumps straight to `runBegin`, skips
/// stall detection entirely, and two minutes later reports "logged 'Run Begin'
/// but no sldworks.exe appeared" — a fabricated account of a stall that never
/// happened, drawn from somebody else's launch.
#[test]
fn a_log_listing_that_failed_does_not_make_every_old_log_ours() {
    let three_days_old = LogFile {
        path: r"C:\Users\drew\AppData\Roaming\DassaultSystemes\SWXDesktopLauncher\20260902162153_V6R2026x.HF4.13.log".into(),
        created_at: Some(1_788_384_116),
        stamp: stamp_of("20260902162153_V6R2026x.HF4.13.log"),
    };
    assert!(
        three_days_old.stamp.is_some(),
        "precondition: the launcher's own filename stamp parses"
    );
    assert!(
        !three_days_old.is_newer_than(None, None),
        "with NO baseline — which is what a failed directory listing produces, because \
         `launcher_logs()` is `unwrap_or_default()`ed — a three-day-old log is accepted as \
         evidence that the chain we just invoked started. An unreadable listing is UNKNOWN; it \
         is not 'the directory was empty'."
    );
}

/// `is_newer_than` short-circuits on the stamps and never consults the
/// filesystem when both are present: `(Some(mine), Some(base)) => return mine > base`.
///
/// The launcher stamps LOCAL time. For the one hour a year that a local clock
/// repeats, a log written after our invoke carries a stamp LOWER than one
/// written before it, and the bridge concludes its own log does not exist — so
/// every route reports "produced NO launcher log at all: nothing started",
/// kills nothing, and moves on. Any single log with a stamp from the future
/// (a clock correction, a file copied from another machine) poisons the
/// directory permanently, because these logs are never pruned.
#[test]
fn a_launch_during_the_repeated_daylight_saving_hour_still_finds_its_own_log() {
    // 01:59:00 EDT, then the clock goes back: our launch runs at 01:30:00 EST,
    // twenty-nine minutes LATER in real time and an hour earlier on the wall.
    let baseline = stamp_of("20261101015900_V6R2026x.HF4.13.log");
    let ours = LogFile {
        path: "…/20261101013000_V6R2026x.HF4.13.log".into(),
        // The filesystem, which records UTC, knows perfectly well it is newer.
        created_at: Some(1_793_000_000),
        stamp: stamp_of("20261101013000_V6R2026x.HF4.13.log"),
    };
    assert!(
        ours.is_newer_than(baseline, Some(1_792_998_000)),
        "our own launcher log was rejected because its LOCAL-time filename stamp is lower than \
         a log written half an hour earlier on the other side of a daylight-saving change. The \
         stamp comparison returns before the filesystem time — which is monotonic — is even \
         looked at, so the bridge reports that nothing started."
    );
}

// ════════════════════════════════════════════════════════════════════════════
// 3. THE NEWLY NULLABLE COUNTS — the shape is right, the guidance is not
// ════════════════════════════════════════════════════════════════════════════

/// `cmd_interference` now answers `count: null` when SOLIDWORKS would not give
/// a count — correct, and the most consequential null in the bridge, because
/// this verb's output is a clearance report somebody builds a physical thing
/// from. Its `_hint` still says only:
///
/// > `count==0` means no interferences at the components' CURRENT positions
///
/// A caller told that, holding `{"count": null}`, writes `if (!r.count)` — and
/// in every language the bridge's callers use, `null` is falsy exactly like
/// `0`. The verb that took the most care to stop manufacturing an all-clear
/// still teaches the idiom that manufactures one.
#[test]
fn the_interference_verb_says_what_an_unknown_count_means() {
    let b = Bridge::start();
    b.call("swx_start", json!({"reason": "checking clearances"}));
    let made = b.call("swx_new_document", json!({"type": "assembly"}));
    let title = made["created"]["title"].as_str().unwrap_or("Assem1").to_string();
    let r = b.call("swx_interference", json!({"targetDocument": title}));
    assert!(r["success"] == true, "precondition: the verb runs: {}", s(&r));

    let hint = r["_hint"].as_str().unwrap_or("").to_lowercase();
    assert!(
        hint.contains("null") || hint.contains("unknown") || hint.contains("could not"),
        "the hint explains count==0 and says nothing about count==null, which this verb can now \
         return and which every caller's truthiness check will read as zero. On a clearance \
         report that is the one mistake that reaches a physical part.\nhint: {}\n{}",
        r["_hint"],
        s(&r)
    );
}

/// The consequence of the adoption above, measured on the machine rather than
/// in the report: does the bridge actually END the user's launcher chain?
///
/// Kept separate from the attribution test because the two are different
/// claims, and this is the one that says whether 0.4.1 can act on somebody's
/// desktop without their consent.
#[test]
fn a_user_chain_that_appears_while_our_route_started_nothing_is_never_terminated() {
    let m = Sim::new(
        "adv2-adoptkill",
        json!({"explorer": {"chain": false}, "shellExecute": {"chain": false},
               "powershell": {"chain": false}, "cmdStart": {"chain": false}}),
    );
    let b = m.boot(TempDir::new("adv2-scratch"), &[]);
    b.call("swx_start", json!({"reason": "modelling a bracket", "waitSeconds": 0}));
    std::thread::sleep(Duration::from_millis(300));
    let mut rows = Sim::daemons();
    rows.push(json!({"pid": 70003, "image": "CATSTART.exe", "ageSeconds": 0}));
    rows.push(json!({"pid": 70004, "image": "SWXDesktopLauncher.exe", "ageSeconds": 0, "ppid": 70003}));
    m.write_preexisting(rows);
    let st = wait_for_launch(&b, 30);

    let killed = m.terminated();
    assert!(
        !killed.contains(&70003) && !killed.contains(&70004),
        "the bridge TERMINATED the user's own launcher chain — processes it never started, on a \
         machine where nothing it invoked ever ran. terminated: {killed:?}\nlaunch: {}\n\
         --- server log ---\n{}",
        s(&st["launch"]),
        b.log()
    );
}