From 50005dca0435872e4f1d54dbc16e7a711f09c8c4 Mon Sep 17 00:00:00 2001 From: Jacob Stephens Date: Tue, 20 Oct 2026 21:43:39 -0400 Subject: [PATCH 1/3] Name what a Pickup run or Security run dispatched, and when, in its stage MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A Pickup run or Security run now enters a `dispatched Run` or `dispatched Spec run` stage when it dispatches, so status reads `dispatched Spec run · 19 hr 46 min` instead of `starting`, and `died at dispatched Spec run` if its process goes. A dispatch stage has no Usual range and is never Silent or Slow: the dispatched Command carries its own health. A Pickup run's record carries the title its Ready issue was listed with. Closes #889 Co-Authored-By: Claude Opus 5.5 --- docs/guide.md | 4 +- src/logs.rs | 17 ++-- src/logs/command_record.rs | 35 +++++++- src/logs/owner.rs | 2 +- src/logs/reading/health.rs | 6 +- src/logs/recording.rs | 9 ++ src/logs/recording/tests.rs | 164 ++++++++++++++++++++++++++++++++++-- src/pass.rs | 8 +- src/pickup.rs | 2 +- tests/run_health.rs | 42 ++++++++- tests/security_run.rs | 11 ++- tests/spec_run.rs | 17 ++++ tests/status.rs | 126 +++++++++++++++++++++++++++ 13 files changed, 410 insertions(+), 33 deletions(-) diff --git a/docs/guide.md b/docs/guide.md index a5af44dd..386854b4 100644 --- a/docs/guide.md +++ b/docs/guide.md @@ -144,7 +144,7 @@ Times are RFC 3339; ages are nonnegative seconds. `model` and `effort` are null Each top-level `commands` entry adds the computed `group` (`needs you`, `ready for review`, `landing`, `working`, `done`, `resolved` or `history`), nullable `needs_you_kind` (`silent`, `slow`, `died`, `failed`, `triage`, `finding`), `landing` (also true for a Needs you item referenced from Landing), and `count`. A collapsed failure has a `collapsed` array containing the other Commands, each with its own group and kind. These fields are observations, absent from durable records and `show`; child Runs remain within their Command. The durable `security_findings_waiting` flag defaults to false for older records. -`state` is `live`, `died`, `ended`, or `unknown` when historical evidence has no ending. `stage` is null before the first known stage. Readers skip unknown stage names. Known stages are `implement`, `Resume`, `Security review`, `pull request`, `CI watch`, `Repair`, `Self-merge`, `cleanup`, `Tickets`, `Spec review`, `Architecture review`, `Security audit`, `Security reproduction` and `Security fix publishing`. A Pass retains its own stages while its dispatched work records its stages separately. +`state` is `live`, `died`, `ended`, or `unknown` when historical evidence has no ending. `stage` is null before the first known stage. Readers skip unknown stage names. Known stages are `implement`, `Resume`, `Security review`, `pull request`, `CI watch`, `Repair`, `Self-merge`, `cleanup`, `Tickets`, `Spec review`, `Architecture review`, `Security audit`, `Security reproduction`, `Security fix publishing`, `dispatched Run` and `dispatched Spec run`. A Pass retains its own stages while its dispatched work records its stages separately. A Pickup run or Security run enters `dispatched Run` or `dispatched Spec run` when it dispatches, so its row reads, for example, `dispatched Spec run · 19 hr 46 min`, timed from the dispatch, and `died at dispatched Spec run` if its process goes. A Pickup run's `issue.title` is the one its Ready issue was listed with; older records have null. `children` recursively contains the immediate child Runs in separate processes, with the same fields as their parent. A Pickup's `dispatched` contains its Run or Spec run. A Spec's `tickets` is its complete roster in issue-number order; each entry has `issue` (`number`, `url`, nullable `title`), `state` (`running`, `merged`, `failed`, `waiting`, or `not started`) and `blockers` (the named open blocking issues, with the same issue fields). Match a Ticket's `issue.url` to the Run in that Spec's `children` for its stage, age, liveness and Base fix descendants. Tickets without a Run remain in the roster. Completed child Runs stay in the tree while its Command is listed. A killed child's `state: "died"` remains independent of the Spec's Ticket accounting. `parent_record` links each child to its parent's exact file; `parent_dispatch`, when present, names the dispatched issue's URL within that file. A top-level Command has null for both. Records from before these fields existed read as having no children or Tickets. @@ -188,7 +188,7 @@ thirdshift logs 'widgets#7' --session repair --follow `show` includes the Runs, stage history with start times and Usual ranges, outcomes, and Command and Session log paths. Each live Run also gets its latest event, such as `Bash: cargo test`, from the last 64 KiB of its current Session log. It uses the Harness's stream interpretation, including Claude and Codex, and ignores malformed or unknown lines. Missing or unreadable Session logs leave the event unavailable. -`status` and `show` describe live work as **Silent** when neither its Session log nor its Command log has grown for `inbox.silent_minutes` (10 by default). Silence starts no earlier than the current stage. At three times the threshold, the words escalate: `silent 45 min · past 30`. A fresh line in either log keeps the Run from being Silent. Missing logs use the stage's start time. +`status` and `show` describe live work as **Silent** when neither its Session log nor its Command log has grown for `inbox.silent_minutes` (10 by default). Silence starts no earlier than the current stage. A dispatch stage is never Silent or Slow and has no Usual range: the dispatched Run or Spec run carries its own. At three times the threshold, the words escalate: `silent 45 min · past 30`. A fresh line in either log keeps the Run from being Silent. Missing logs use the stage's start time. A stage's **Usual range** is its 25th–75th percentile time over the repository's last 30 Command records on this machine. Completed stages supply times, with the next stage's start or the Command's end marking completion; an unfinished stage supplies none. The range appears once there are at least three stage times. Quartiles interpolate between sorted times. A live Run past the top of the range is **Slow**: `slower than usual (12–17 min), still working`. At twice the top it also shows the multiple, such as `2× usual` or `3× usual`. Silent takes precedence over Slow. diff --git a/src/logs.rs b/src/logs.rs index 5f8d279f..9dc1f0b8 100644 --- a/src/logs.rs +++ b/src/logs.rs @@ -27,6 +27,7 @@ use std::path::{Path, PathBuf}; use std::sync::{LazyLock, Mutex, MutexGuard, PoisonError}; use crate::config::UserConfig; +use crate::github::ListedIssue; use crate::harness::Choice; use crate::issue::{IssueUrl, Repo}; use crate::session::Logged; @@ -91,8 +92,8 @@ pub enum Work<'a> { BaseFix(&'a IssueUrl), /// A Spec run on its Spec. SpecRun(&'a IssueUrl), - /// A Pickup run, on the Ready issue it took. - PickupRun(&'a IssueUrl), + /// A Pickup run, on the Ready issue it took, as the listing named it. + PickupRun(&'a ListedIssue), /// An Architect run, on its repository. ArchitectRun(&'a Repo), /// A Security run, on its repository. @@ -314,10 +315,8 @@ impl Work<'_> { /// The repository whose work it records. fn repo(self) -> Repo { match self { - Work::Run(issue) - | Work::BaseFix(issue) - | Work::SpecRun(issue) - | Work::PickupRun(issue) => issue.repo(), + Work::Run(issue) | Work::BaseFix(issue) | Work::SpecRun(issue) => issue.repo(), + Work::PickupRun(listed) => listed.issue.repo(), Work::ArchitectRun(repo) | Work::SecurityRun(repo) => repo.clone(), } } @@ -336,10 +335,8 @@ impl Work<'_> { /// Its issue's number, if it has one. fn issue(self) -> Option { match self { - Work::Run(issue) - | Work::BaseFix(issue) - | Work::SpecRun(issue) - | Work::PickupRun(issue) => Some(issue.number), + Work::Run(issue) | Work::BaseFix(issue) | Work::SpecRun(issue) => Some(issue.number), + Work::PickupRun(listed) => Some(listed.issue.number), Work::ArchitectRun(_) | Work::SecurityRun(_) => None, } } diff --git a/src/logs/command_record.rs b/src/logs/command_record.rs index 62225a7a..5bf65f4d 100644 --- a/src/logs/command_record.rs +++ b/src/logs/command_record.rs @@ -137,6 +137,10 @@ pub enum StageName { SecurityAudit, SecurityReproduction, SecurityFixPublishing, + /// A Pickup run or Security run waiting on the Run it dispatched. + DispatchedRun, + /// A Pickup run or Security run waiting on the Spec run it dispatched. + DispatchedSpecRun, } impl StageName { @@ -156,9 +160,27 @@ impl StageName { Self::SecurityAudit => "Security audit", Self::SecurityReproduction => "Security reproduction", Self::SecurityFixPublishing => "Security fix publishing", + Self::DispatchedRun => "dispatched Run", + Self::DispatchedSpecRun => "dispatched Spec run", } } + /// The stage a pass enters while `work`, the Command it dispatched, runs. + pub(super) fn dispatched(work: Work<'_>) -> Self { + match work { + Work::SpecRun(_) => Self::DispatchedSpecRun, + _ => Self::DispatchedRun, + } + } + + /// A dispatch has no Usual range and is never Silent: its health is the + /// dispatched Command's. + pub(super) fn is_dispatch(name: &str) -> bool { + [Self::DispatchedRun, Self::DispatchedSpecRun] + .into_iter() + .any(|stage| stage.name() == name) + } + pub(super) fn known(name: &str) -> bool { [ Self::Implement, @@ -175,6 +197,8 @@ impl StageName { Self::SecurityAudit, Self::SecurityReproduction, Self::SecurityFixPublishing, + Self::DispatchedRun, + Self::DispatchedSpecRun, ] .into_iter() .any(|stage| stage.name() == name) @@ -236,14 +260,17 @@ impl CommandRecord { pub fn new(work: Work<'_>, stamp: &str, harness: &Choice, now: DateTime) -> Self { let issue = match work { - Work::Run(issue) - | Work::BaseFix(issue) - | Work::SpecRun(issue) - | Work::PickupRun(issue) => Some(Issue { + Work::Run(issue) | Work::BaseFix(issue) | Work::SpecRun(issue) => Some(Issue { number: issue.number, url: issue.url.clone(), title: None, }), + // The Ready issue listing named it before the Pickup run started. + Work::PickupRun(listed) => Some(Issue { + number: listed.issue.number, + url: listed.issue.url.clone(), + title: Some(listed.title.clone()), + }), Work::ArchitectRun(_) | Work::SecurityRun(_) => None, }; let name = match work { diff --git a/src/logs/owner.rs b/src/logs/owner.rs index 998e8876..89113cbb 100644 --- a/src/logs/owner.rs +++ b/src/logs/owner.rs @@ -139,7 +139,7 @@ pub(super) fn allocate( Work::Run(issue) | Work::BaseFix(issue) | Work::SpecRun(issue) => { (CommandKind::Issue, format!("{}-", issue.number)) } - Work::PickupRun(issue) => (CommandKind::Pickup, format!("{}-", issue.number)), + Work::PickupRun(listed) => (CommandKind::Pickup, format!("{}-", listed.issue.number)), Work::ArchitectRun(_) => (CommandKind::Architect, String::new()), Work::SecurityRun(_) => (CommandKind::Secure, String::new()), }; diff --git a/src/logs/reading/health.rs b/src/logs/reading/health.rs index 6625a5b4..f8944bc5 100644 --- a/src/logs/reading/health.rs +++ b/src/logs/reading/health.rs @@ -83,7 +83,7 @@ impl UsualRanges { fn collect_times(record: &CommandRecord, samples: &mut BTreeMap<(String, String), Vec>) { for timing in record.stage_times(None) { let stage = timing.stage; - if !StageName::known(&stage.name) { + if !StageName::known(&stage.name) || StageName::is_dispatch(&stage.name) { continue; } if let Some(seconds) = timing.seconds() { @@ -164,7 +164,9 @@ pub(super) fn observe( .collect(); if command.state == "live" { command.health = Some(Health::Ok); - if let Some(stage) = &command.stage { + if let Some(stage) = &command.stage + && !StageName::is_dispatch(&stage.name) + { if let Some(range) = ranges.get(&command.record.repository, &stage.name) && stage.age_seconds as f64 > range.upper_seconds { diff --git a/src/logs/recording.rs b/src/logs/recording.rs index c4dca8be..7e0b45e6 100644 --- a/src/logs/recording.rs +++ b/src/logs/recording.rs @@ -144,6 +144,11 @@ impl Record { // The launch checks have now established whether the issue is // a Spec. The dispatch itself was kept before those checks. dispatched.kind = work.kind().to_string(); + if let Some(stage) = tree.command.stages.last_mut() + && StageName::is_dispatch(&stage.name) + { + stage.name = StageName::dispatched(work).name().into(); + } self.stage(work.initial_stage().unwrap(), None); } return; @@ -338,6 +343,10 @@ impl Record { } pub(super) fn dispatching(&mut self, work: Work, harness: &Choice) { + // Entered while the pass is still the active record, timing the dispatch. + if matches!(self.command, CommandKind::Pickup | CommandKind::Secure) { + self.stage(StageName::dispatched(work), None); + } let stamp = self.stamp(); let mut facts = CommandRecord::new(work, &stamp, harness, self.outside.now()); if let Some((_, tree)) = &mut self.command_record { diff --git a/src/logs/recording/tests.rs b/src/logs/recording/tests.rs index d88a50c3..d9d8b58d 100644 --- a/src/logs/recording/tests.rs +++ b/src/logs/recording/tests.rs @@ -5,6 +5,7 @@ use std::sync::{Arc, Mutex}; use chrono::{DateTime, FixedOffset}; use super::*; +use crate::github::ListedIssue; use crate::harness::{ChosenBy, Harness}; use crate::issue::IssueUrl; use crate::logs::effects::Tail; @@ -197,6 +198,14 @@ fn issue() -> IssueUrl { IssueUrl::parse("https://github.com/acme/widgets/issues/7").unwrap() } +fn listed() -> ListedIssue { + ListedIssue { + issue: issue(), + title: "Make widgets".into(), + labels: Default::default(), + } +} + #[test] fn a_stop_request_in_the_file_adapter_is_logged_before_the_ending() { let memory = Scripted::default(); @@ -469,6 +478,7 @@ fn a_run_records_its_complete_output_and_activity_under_its_repository() { #[test] fn each_work_kind_records_only_its_first_start_and_keeps_its_own_command_folder() { let issue = issue(); + let listed = listed(); let repo = issue.repo(); let dispatched = IssueUrl::parse("https://github.com/other/repo/issues/8").unwrap(); for (begin, work, beginning, subject, relative) in [ @@ -488,7 +498,7 @@ fn each_work_kind_records_only_its_first_start_and_keeps_its_own_command_folder( ), ( Begin::PickupRun, - Work::PickupRun(&issue), + Work::PickupRun(&listed), "Pickup run starting", "Pickup run #7", "commands/pickup/7-20261003T120000-0400.log", @@ -534,7 +544,7 @@ fn each_work_kind_records_only_its_first_start_and_keeps_its_own_command_folder( #[test] fn held_output_keeps_streams_and_order_through_configuration_release_and_start() { - let issue = issue(); + let listed = listed(); for quiet in [false, true] { let memory = Scripted::default(); let mut record = Record::new(memory.clone()); @@ -551,7 +561,7 @@ fn held_output_keeps_streams_and_order_through_configuration_release_and_start() assert_eq!(memory.terminal(), held); record.print(""); record.eprint("thirdshift: 09:08:07 #21: relayed unchanged"); - record.started(Work::PickupRun(&issue), &harness()); + record.started(Work::PickupRun(&listed), &harness()); record.show_held(); record.print("after start"); record.ended("done"); @@ -619,6 +629,7 @@ fn a_child_inherits_its_parent_stamp_and_relays_output_without_a_beginning_or_lo let memory = Scripted::default(); let mut record = Record::new(memory.clone()); let issue = issue(); + let listed = listed(); let repo = issue.repo(); record.begin(Begin::ChildRun( "parent-stamp", @@ -629,7 +640,7 @@ fn a_child_inherits_its_parent_stamp_and_relays_output_without_a_beginning_or_lo for work in [ Work::Run(&issue), Work::SpecRun(&issue), - Work::PickupRun(&issue), + Work::PickupRun(&listed), Work::ArchitectRun(&repo), ] { record.started(work, &harness()); @@ -757,7 +768,7 @@ fn separate_recordings_suppress_skips_from_shared_history_until_their_kind_chang let mut pickup = Record::new(memory.clone()); pickup.begin(Begin::PickupRun); pickup.configured(&config(true)); - pickup.started(Work::PickupRun(&issue()), &harness()); + pickup.started(Work::PickupRun(&listed()), &harness()); // Even just an intervening start permits the same skip again. skip(&memory, Pass::Pickup, "idle"); pickup.ended("ready"); @@ -1157,7 +1168,7 @@ fn concurrent_output_and_start_have_the_same_terminal_and_command_log_order() { record .lock() .unwrap() - .started(Work::PickupRun(&issue()), &harness()); + .started(Work::PickupRun(&listed()), &harness()); }); }); record.lock().unwrap().ended("done"); @@ -1192,3 +1203,144 @@ fn a_pass_can_reveal_output_before_configuration_when_loading_it_fails() { assert_eq!(record.command_log_path(), None); assert!(memory.0.lock().unwrap().files.is_empty()); } + +fn command_tree(memory: &Scripted) -> serde_json::Value { + let memory = memory.0.lock().unwrap(); + let (_, record) = memory + .files + .iter() + .find(|(path, _)| path.to_string_lossy().ends_with(".command.json")) + .unwrap(); + serde_json::from_str(record).unwrap() +} + +#[test] +fn a_pickup_or_security_run_enters_a_stage_naming_what_it_dispatched_and_when() { + let ready = listed(); + let repo = ready.issue.repo(); + let dispatched = IssueUrl::parse("https://github.com/acme/widgets/issues/8").unwrap(); + for (begin, work, before, spec, expected) in [ + ( + Begin::PickupRun, + Work::PickupRun(&ready), + None, + false, + "dispatched Run", + ), + ( + Begin::PickupRun, + Work::PickupRun(&ready), + None, + true, + "dispatched Spec run", + ), + ( + Begin::SecurityRun, + Work::SecurityRun(&repo), + Some(StageName::SecurityFixPublishing), + false, + "dispatched Run", + ), + ( + Begin::SecurityRun, + Work::SecurityRun(&repo), + Some(StageName::SecurityFixPublishing), + true, + "dispatched Spec run", + ), + ] { + let memory = Scripted::default(); + let mut record = Record::new(memory.clone()); + record.begin(begin); + record.configured(&config(true)); + record.started(work, &harness()); + if let Some(stage) = before { + record.stage(stage, None); + } + let undispatched = command_tree(&memory)["stages"].clone(); + assert_eq!( + undispatched.as_array().unwrap().len(), + usize::from(before.is_some()) + ); + memory.0.lock().unwrap().now = + Some(DateTime::parse_from_rfc3339("2026-10-03T13:30:00-04:00").unwrap()); + let child = if spec { + Work::SpecRun(&dispatched) + } else { + Work::Run(&dispatched) + }; + record.dispatching(child, &harness()); + // The dispatched Command's own stages are its own, not the pass's. + memory.0.lock().unwrap().now = + Some(DateTime::parse_from_rfc3339("2026-10-03T13:31:00-04:00").unwrap()); + record.started(child, &harness()); + record.stage(StageName::PullRequest, None); + let tree = command_tree(&memory); + let stages = tree["stages"].as_array().unwrap(); + assert_eq!(stages.len(), usize::from(before.is_some()) + 1, "{tree:#}"); + assert_eq!(stages.last().unwrap()["name"], expected); + assert_eq!( + stages.last().unwrap()["began_at"], + "2026-10-03T13:30:00-04:00" + ); + let child_stages: Vec<_> = tree["dispatched"][0]["stages"] + .as_array() + .unwrap() + .iter() + .map(|stage| stage["name"].as_str().unwrap()) + .collect(); + assert_eq!( + child_stages, + [if spec { "Tickets" } else { "implement" }, "pull request"] + ); + } +} + +#[test] +fn a_dispatch_found_to_be_a_spec_by_its_launch_checks_renames_the_pass_stage() { + let ready = listed(); + let dispatched = IssueUrl::parse("https://github.com/acme/widgets/issues/8").unwrap(); + let memory = Scripted::default(); + let mut record = Record::new(memory.clone()); + record.begin(Begin::PickupRun); + record.configured(&config(true)); + record.started(Work::PickupRun(&ready), &harness()); + record.dispatching(Work::Run(&dispatched), &harness()); + record.started(Work::SpecRun(&dispatched), &harness()); + let tree = command_tree(&memory); + assert_eq!(tree["stages"][0]["name"], "dispatched Spec run"); + assert_eq!(tree["dispatched"][0]["kind"], "Spec run"); +} + +#[test] +fn an_architect_run_keeps_its_own_stage_while_its_plan_is_dispatched() { + let repo = issue().repo(); + let plan = IssueUrl::parse("https://github.com/acme/widgets/issues/8").unwrap(); + let memory = Scripted::default(); + let mut record = Record::new(memory.clone()); + record.begin(Begin::ArchitectRun); + record.configured(&config(true)); + record.started(Work::ArchitectRun(&repo), &harness()); + record.dispatching(Work::Run(&plan), &harness()); + record.started(Work::Run(&plan), &harness()); + let tree = command_tree(&memory); + let stages: Vec<_> = tree["stages"] + .as_array() + .unwrap() + .iter() + .map(|stage| stage["name"].as_str().unwrap()) + .collect(); + assert_eq!(stages, ["Architecture review"]); +} + +#[test] +fn a_pickup_run_records_the_title_its_ready_issue_was_listed_with() { + let memory = Scripted::default(); + let mut record = Record::new(memory.clone()); + record.begin(Begin::PickupRun); + record.configured(&config(true)); + record.started(Work::PickupRun(&listed()), &harness()); + let issue = command_tree(&memory)["issue"].clone(); + assert_eq!(issue["number"], 7); + assert_eq!(issue["title"], "Make widgets"); +} diff --git a/src/pass.rs b/src/pass.rs index 611f0ef3..00c8d6ab 100644 --- a/src/pass.rs +++ b/src/pass.rs @@ -726,10 +726,10 @@ mod in_memory { fn started(&mut self, work: Work) { let issue = match work { - Work::Run(issue) - | Work::BaseFix(issue) - | Work::SpecRun(issue) - | Work::PickupRun(issue) => Some(issue.number), + Work::Run(issue) | Work::BaseFix(issue) | Work::SpecRun(issue) => { + Some(issue.number) + } + Work::PickupRun(listed) => Some(listed.issue.number), Work::ArchitectRun(_) | Work::SecurityRun(_) => None, }; self.calls.push(Call::Started(issue)); diff --git a/src/pickup.rs b/src/pickup.rs index 008a47f1..445ec713 100644 --- a/src/pickup.rs +++ b/src/pickup.rs @@ -193,7 +193,7 @@ fn run_through( listed.issue.number, listed.title, listed.issue.url )); outside.check_harness()?; - outside.started(Work::PickupRun(&listed.issue)); + outside.started(Work::PickupRun(&listed)); let ended = outside.dispatch(Dispatch::ReadyIssue { issue: &listed.issue, is_spec, diff --git a/tests/run_health.rs b/tests/run_health.rs index de676426..f05397b8 100644 --- a/tests/run_health.rs +++ b/tests/run_health.rs @@ -40,10 +40,14 @@ impl LiveRun { } fn stage_age(&mut self, minutes: i64) { + self.named_stage_age("implement", minutes); + } + + fn named_stage_age(&mut self, stage: &str, minutes: i64) { let began = (chrono::Local::now() - chrono::Duration::minutes(minutes)).to_rfc3339(); self.record["started_at"] = began.clone().into(); self.record["stages"] = json!([{ - "name": "implement", "began_at": began, + "name": stage, "began_at": began, "session_log": self.record["session_log"] }]); fs::write(&self.path, serde_json::to_vec(&self.record).unwrap()).unwrap(); @@ -93,6 +97,17 @@ impl LiveRun { } fn history(&self, number: u32, duration: Option, minutes_ago: i64, repo: &str) { + self.named_history("implement", number, duration, minutes_ago, repo); + } + + fn named_history( + &self, + stage: &str, + number: u32, + duration: Option, + minutes_ago: i64, + repo: &str, + ) { let mut record = self.record.clone(); let ended = chrono::Local::now() - chrono::Duration::minutes(minutes_ago); let began = ended - chrono::Duration::minutes(duration.unwrap_or(1)); @@ -104,7 +119,7 @@ impl LiveRun { record["session_log"] = Value::Null; record["stages"] = duration.map_or(json!([]), |_| { json!([{ - "name": "implement", "began_at": began.to_rfc3339(), "session_log": null + "name": stage, "began_at": began.to_rfc3339(), "session_log": null }]) }); let folder = self @@ -223,3 +238,26 @@ fn status_warns_when_waiting_lines_are_not_more_frequent_than_silence() { scenario.user_config_is("[logs]\nwaiting_line_minutes = 1\n[inbox]\nsilent_minutes = 2\n"); assert!(!scenario.run(&["status"]).stderr.contains("warning")); } + +#[test] +fn a_dispatch_stage_is_never_slow_or_silent_since_its_dispatched_command_carries_health() { + let mut run = LiveRun::new(); + for number in 10..13 { + run.named_history("dispatched Run", number, Some(10), 100, "acme/widgets"); + } + run.named_stage_age("dispatched Run", 600); + run.log_ages(300, 300); + let status = run.status(); + assert_eq!(status["stage"]["name"], "dispatched Run", "{status}"); + assert_eq!(status["health"]["state"], "ok", "{status}"); + assert!( + status["usual_ranges"]["dispatched Run"].is_null(), + "{status}" + ); + let text = run.scenario.run(&["status"]); + assert!( + text.stdout.contains(" · dispatched Run · 10 hr 0 min\n"), + "{}", + text.stdout + ); +} diff --git a/tests/security_run.rs b/tests/security_run.rs index 4af9c9f8..41d6624f 100644 --- a/tests/security_run.rs +++ b/tests/security_run.rs @@ -456,6 +456,14 @@ fn status_tracks_security_stages_and_nests_the_dispatched_fix() { assert_eq!(active["stage"]["name"], stage, "{status}"); assert!(active["stage"]["age_seconds"].is_number()); if held_session == 4 { + assert_eq!(pass["stage"]["name"], "dispatched Run", "{status}"); + assert_eq!(pass["health"]["state"], "ok", "{status}"); + let row = text + .stdout + .lines() + .find(|line| line.starts_with("Security run ")) + .expect(&text.stdout); + assert!(row.contains(" · dispatched Run · "), "{row}"); assert_eq!(active["issue"]["number"], 8); assert!( text.stdout.contains("\n Run acme/widgets#8"), @@ -476,7 +484,8 @@ fn status_tracks_security_stages_and_nests_the_dispatched_fix() { [ "Security audit", "Security reproduction", - "Security fix publishing" + "Security fix publishing", + "dispatched Run" ] ); assert_eq!(record["outcome"], "ready for review"); diff --git a/tests/spec_run.rs b/tests/spec_run.rs index 2a4b111e..a468c31c 100644 --- a/tests/spec_run.rs +++ b/tests/spec_run.rs @@ -68,6 +68,13 @@ fn status_nests_a_pickups_spec_with_running_waiting_merged_and_not_started_ticke assert_eq!(commands.len(), 1, "{status:#}"); let pickup = &commands[0]; assert_eq!(pickup["kind"], "Pickup run"); + assert_eq!(pickup["issue"]["title"], SPEC_TITLE); + assert_eq!(pickup["stage"]["name"], "dispatched Spec run"); + assert_eq!(pickup["stages"][0]["name"], "dispatched Spec run"); + assert!( + chrono::DateTime::parse_from_rfc3339(pickup["stage"]["began_at"].as_str().unwrap()).is_ok() + ); + assert_eq!(pickup["health"]["state"], "ok"); let spec = &pickup["dispatched"][0]; assert_eq!(spec["kind"], "Spec run"); assert_eq!(spec["stage"]["name"], "Tickets"); @@ -84,6 +91,16 @@ fn status_nests_a_pickups_spec_with_running_waiting_merged_and_not_started_ticke assert_eq!(run["state"], "live"); assert_eq!(run["stage"]["name"], "implement"); assert!(run["stage"]["age_seconds"].is_number()); + let row = text + .stdout + .lines() + .find(|line| line.starts_with("Pickup run ")) + .expect(&text.stdout); + assert!( + row.starts_with(&format!("Pickup run acme/widgets#{SPEC} {SPEC_TITLE} · ")), + "{row}" + ); + assert!(row.contains(" · dispatched Spec run · "), "{row}"); for expected in [ "Pickup run", "Spec run", diff --git a/tests/status.rs b/tests/status.rs index a6e672ca..e51c0f97 100644 --- a/tests/status.rs +++ b/tests/status.rs @@ -167,6 +167,132 @@ gh pr create --base main --head issue-7 --title 'Make widgets' --body 'Closes #7 ); } +#[test] +fn a_live_pickup_run_names_its_issue_and_the_run_it_dispatched() { + let scenario = Scenario::new(); + scenario.issue_titled(7, "Make widgets"); + scenario.issue_labelled(7, &["ready-for-agent"]); + scenario.agent_does(&format!( + "touch '{started}'\nwhile ! test -f '{release}'; do sleep 0.02; done\n{OPENS_PR}", + started = scenario.path("started").display(), + release = scenario.path("release").display() + )); + let held = scenario.run_until(&["pickup"], &[], "started"); + let json = scenario.run(&["status", "--json"]); + let text = scenario.run(&["status"]); + let status: Value = serde_json::from_str(&json.stdout).unwrap(); + let name = status["commands"][0]["name"].as_str().unwrap().to_string(); + let shown = scenario.run(&["show", &name]); + fs::write(scenario.path("release"), "").unwrap(); + let ended = held.finish(); + assert_eq!(ended.code, Some(0), "{}", ended.stderr); + let pickup = &status["commands"][0]; + assert_eq!(pickup["kind"], "Pickup run", "{status:#}"); + assert_eq!(pickup["state"], "live"); + assert_eq!(pickup["issue"]["title"], "Make widgets"); + assert_eq!(pickup["stage"]["name"], "dispatched Run"); + assert_eq!(pickup["stages"][0]["name"], "dispatched Run"); + assert!( + chrono::DateTime::parse_from_rfc3339(pickup["stage"]["began_at"].as_str().unwrap()).is_ok() + ); + assert!(pickup["stage"]["age_seconds"].is_number()); + assert_eq!(pickup["dispatched"][0]["stage"]["name"], "implement"); + let row = text + .stdout + .lines() + .find(|line| line.starts_with("Pickup run ")) + .expect(&text.stdout); + assert!( + row.starts_with("Pickup run acme/widgets#7 Make widgets · "), + "{row}" + ); + assert!(row.contains(" · dispatched Run · "), "{row}"); + assert!( + text.stdout.contains(" Run acme/widgets#7 Make widgets · "), + "{}", + text.stdout + ); + assert_eq!(shown.code, Some(0), "{}", shown.stderr); + assert!( + shown + .stdout + .starts_with(&format!("Pickup run {name} · dispatched Run · ")), + "{}", + shown.stdout + ); + assert!( + shown.stdout.lines().any(|line| line == "Make widgets"), + "{}", + shown.stdout + ); +} + +const PICKUP_LOGS: &str = "home/.thirdshift/logs/acme/widgets/commands/pickup"; + +/// The status line of a Pickup run whose record `change` rewrites, on a +/// Pickup run that took #7 and ended. +fn pickup_row_after(change: impl FnOnce(&mut Value)) -> String { + let scenario = Scenario::new(); + scenario.issue_titled(7, "Make widgets"); + scenario.issue_labelled(7, &["ready-for-agent"]); + scenario.agent_does(OPENS_PR); + let ended = scenario.run(&["pickup"]); + assert_eq!(ended.code, Some(0), "{}", ended.stderr); + let path = fs::read_dir(scenario.path(PICKUP_LOGS)) + .unwrap() + .map(|entry| entry.unwrap().path()) + .find(|path| path.to_string_lossy().ends_with(".command.json")) + .unwrap(); + let mut record: Value = serde_json::from_slice(&fs::read(&path).unwrap()).unwrap(); + change(&mut record); + fs::write(&path, serde_json::to_vec(&record).unwrap()).unwrap(); + let text = scenario.run(&["status"]); + assert_eq!(text.code, Some(0), "{}", text.stderr); + text.stdout + .lines() + .find(|line| line.starts_with("Pickup run ")) + .expect(&text.stdout) + .to_string() +} + +/// Make an ended record read as a Command that died without an outcome. +fn died(record: &mut Value) { + record["outcome"] = Value::Null; + record["ended_at"] = Value::Null; + record["process_start"] = "gone".into(); +} + +#[test] +fn an_ended_pickup_run_shows_its_outcome_and_one_that_died_names_its_dispatch() { + let ended = pickup_row_after(|_| {}); + assert!( + ended.starts_with("Pickup run acme/widgets#7 Make widgets · "), + "{ended}" + ); + assert!(ended.ends_with(" · ready for review"), "{ended}"); + let dead = pickup_row_after(died); + assert!(dead.ends_with(" · died at dispatched Run"), "{dead}"); +} + +#[test] +fn a_pickup_record_from_before_dispatch_stages_and_titles_reads_as_it_did() { + let before = |record: &mut Value| { + record["stages"] = serde_json::json!([]); + record["issue"]["title"] = Value::Null; + }; + let ended = pickup_row_after(before); + assert!( + ended.starts_with("Pickup run acme/widgets#7 (title unavailable) · "), + "{ended}" + ); + assert!(ended.ends_with(" · ready for review"), "{ended}"); + let dead = pickup_row_after(|record| { + before(record); + died(record); + }); + assert!(dead.ends_with(" · died before first stage"), "{dead}"); +} + #[test] fn a_merge_run_retains_delivery_stages_and_their_start_times() { let scenario = Scenario::new(); From fd47fe04fae69da2cd9f8d3e293c5050005b6cb1 Mon Sep 17 00:00:00 2001 From: Jacob Stephens Date: Tue, 20 Oct 2026 22:23:54 -0400 Subject: [PATCH 2/3] Read a Work's issue in one place and spell out the dispatch stage rules Co-Authored-By: Claude Opus 5.5 --- src/logs.rs | 15 ++++++++++----- src/logs/command_record.rs | 34 +++++++++++++++++----------------- src/logs/recording.rs | 4 +++- src/pass.rs | 10 ++-------- 4 files changed, 32 insertions(+), 31 deletions(-) diff --git a/src/logs.rs b/src/logs.rs index 9dc1f0b8..a90a7d99 100644 --- a/src/logs.rs +++ b/src/logs.rs @@ -302,7 +302,7 @@ fn root_under(logs_dir: &Path, repo: &Repo) -> PathBuf { logs_dir.join(&repo.owner).join(&repo.name) } -impl Work<'_> { +impl<'a> Work<'a> { fn initial_stage(self) -> Option { match self { Work::Run(_) | Work::BaseFix(_) => Some(Stage::Implement), @@ -332,14 +332,19 @@ impl Work<'_> { } } - /// Its issue's number, if it has one. - fn issue(self) -> Option { + /// Its issue, if it has one. + pub(crate) fn issue_url(self) -> Option<&'a IssueUrl> { match self { - Work::Run(issue) | Work::BaseFix(issue) | Work::SpecRun(issue) => Some(issue.number), - Work::PickupRun(listed) => Some(listed.issue.number), + Work::Run(issue) | Work::BaseFix(issue) | Work::SpecRun(issue) => Some(issue), + Work::PickupRun(listed) => Some(&listed.issue), Work::ArchitectRun(_) | Work::SecurityRun(_) => None, } } + + /// Its issue's number, if it has one. + fn issue(self) -> Option { + self.issue_url().map(|issue| issue.number) + } } /// The [`Record`], locked, even if a thread panicked holding it. diff --git a/src/logs/command_record.rs b/src/logs/command_record.rs index 5bf65f4d..2fb6caa8 100644 --- a/src/logs/command_record.rs +++ b/src/logs/command_record.rs @@ -169,12 +169,17 @@ impl StageName { pub(super) fn dispatched(work: Work<'_>) -> Self { match work { Work::SpecRun(_) => Self::DispatchedSpecRun, - _ => Self::DispatchedRun, + Work::Run(_) + | Work::BaseFix(_) + | Work::PickupRun(_) + | Work::ArchitectRun(_) + | Work::SecurityRun(_) => Self::DispatchedRun, } } - /// A dispatch has no Usual range and is never Silent: its health is the - /// dispatched Command's. + /// Whether the stage named `name` is a pass's dispatch stage. Such a + /// stage has no Usual range and is never Silent: the dispatched + /// Command's own stages carry its health. pub(super) fn is_dispatch(name: &str) -> bool { [Self::DispatchedRun, Self::DispatchedSpecRun] .into_iter() @@ -259,20 +264,15 @@ impl CommandRecord { } pub fn new(work: Work<'_>, stamp: &str, harness: &Choice, now: DateTime) -> Self { - let issue = match work { - Work::Run(issue) | Work::BaseFix(issue) | Work::SpecRun(issue) => Some(Issue { - number: issue.number, - url: issue.url.clone(), - title: None, - }), - // The Ready issue listing named it before the Pickup run started. - Work::PickupRun(listed) => Some(Issue { - number: listed.issue.number, - url: listed.issue.url.clone(), - title: Some(listed.title.clone()), - }), - Work::ArchitectRun(_) | Work::SecurityRun(_) => None, - }; + let issue = work.issue_url().map(|issue| Issue { + number: issue.number, + url: issue.url.clone(), + // The Ready issue listing named a Pickup run's issue before it started. + title: match work { + Work::PickupRun(listed) => Some(listed.title.clone()), + _ => None, + }, + }); let name = match work { Work::ArchitectRun(_) => format!("architect-{stamp}"), Work::SecurityRun(_) => format!("secure-{stamp}"), diff --git a/src/logs/recording.rs b/src/logs/recording.rs index 7e0b45e6..d5b78dcc 100644 --- a/src/logs/recording.rs +++ b/src/logs/recording.rs @@ -343,7 +343,9 @@ impl Record { } pub(super) fn dispatching(&mut self, work: Work, harness: &Choice) { - // Entered while the pass is still the active record, timing the dispatch. + // Entered while the pass is still the active record, timing the + // dispatch. An Architect run keeps its Architecture review stage, + // as #889 asked only for Pickup runs and Security runs. if matches!(self.command, CommandKind::Pickup | CommandKind::Secure) { self.stage(StageName::dispatched(work), None); } diff --git a/src/pass.rs b/src/pass.rs index 00c8d6ab..2ebd1f00 100644 --- a/src/pass.rs +++ b/src/pass.rs @@ -725,14 +725,8 @@ mod in_memory { } fn started(&mut self, work: Work) { - let issue = match work { - Work::Run(issue) | Work::BaseFix(issue) | Work::SpecRun(issue) => { - Some(issue.number) - } - Work::PickupRun(listed) => Some(listed.issue.number), - Work::ArchitectRun(_) | Work::SecurityRun(_) => None, - }; - self.calls.push(Call::Started(issue)); + self.calls + .push(Call::Started(work.issue_url().map(|issue| issue.number))); } fn pull(&mut self) { From fd3f831781febfee2d800016b4b8bf9f00b16f0c Mon Sep 17 00:00:00 2001 From: Jacob Stephens Date: Tue, 20 Oct 2026 22:43:55 -0400 Subject: [PATCH 3/3] Regenerate the site docs from the guide's dispatch stage rules Co-Authored-By: Claude Opus 5.5 --- site/docs/index.html | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/site/docs/index.html b/site/docs/index.html index c486069c..3d416945 100644 --- a/site/docs/index.html +++ b/site/docs/index.html @@ -188,7 +188,7 @@

Times are RFC 3339; ages are nonnegative seconds. model and effort are null when left to the Harness. issue is null for a Pass with no issue; session_log, issue_branch, pull_request, outcome, cause, ended_at, parent_record and parent_dispatch are nullable. Command kinds are Run, Spec run, Architect run, Pickup run, Security run and Base fix. name identifies an issue or a Pass's kind and stamp. dispatched is an array of the Runs or Spec runs a Pass dispatched, with the same fields as its parent (and an empty dispatched array); it shares the Pass's process identity and Command log. It retains its own outcome, end time, cause, Issue branch and pull request. The retained Command record has the same fields, including dispatched work, without the computed state, stage, source, command_log and children or empty leaf dispatched arrays. Older records without an end time use their last modification time. idle_passes contains one entry per repository and kind whose latest Activity log line is a skip; it is independent of commands, and never creates a Command record or log for a skipped Pass.

Each top-level commands entry adds the computed group (needs you, ready for review, landing, working, done, resolved or history), nullable needs_you_kind (silent, slow, died, failed, triage, finding), landing (also true for a Needs you item referenced from Landing), and count. A collapsed failure has a collapsed array containing the other Commands, each with its own group and kind. These fields are observations, absent from durable records and show; child Runs remain within their Command. The durable security_findings_waiting flag defaults to false for older records.

-

state is live, died, ended, or unknown when historical evidence has no ending. stage is null before the first known stage. Readers skip unknown stage names. Known stages are implement, Resume, Security review, pull request, CI watch, Repair, Self-merge, cleanup, Tickets, Spec review, Architecture review, Security audit, Security reproduction and Security fix publishing. A Pass retains its own stages while its dispatched work records its stages separately.

+

state is live, died, ended, or unknown when historical evidence has no ending. stage is null before the first known stage. Readers skip unknown stage names. Known stages are implement, Resume, Security review, pull request, CI watch, Repair, Self-merge, cleanup, Tickets, Spec review, Architecture review, Security audit, Security reproduction, Security fix publishing, dispatched Run and dispatched Spec run. A Pass retains its own stages while its dispatched work records its stages separately. A Pickup run or Security run enters dispatched Run or dispatched Spec run when it dispatches, so its row reads, for example, dispatched Spec run · 19 hr 46 min, timed from the dispatch, and died at dispatched Spec run if its process goes. A Pickup run's issue.title is the one its Ready issue was listed with; older records have null.

children recursively contains the immediate child Runs in separate processes, with the same fields as their parent. A Pickup's dispatched contains its Run or Spec run. A Spec's tickets is its complete roster in issue-number order; each entry has issue (number, url, nullable title), state (running, merged, failed, waiting, or not started) and blockers (the named open blocking issues, with the same issue fields). Match a Ticket's issue.url to the Run in that Spec's children for its stage, age, liveness and Base fix descendants. Tickets without a Run remain in the roster. Completed child Runs stay in the tree while its Command is listed. A killed child's state: "died" remains independent of the Spec's Ticket accounting. parent_record links each child to its parent's exact file; parent_dispatch, when present, names the dispatched issue's URL within that file. A top-level Command has null for both. Records from before these fields existed read as having no children or Tickets.

For example, this tree excerpt omits the common Run fields shown above:

{
@@ -224,7 +224,7 @@
 thirdshift logs 'widgets#7' --session repair --follow

show includes the Runs, stage history with start times and Usual ranges, outcomes, and Command and Session log paths. Each live Run also gets its latest event, such as Bash: cargo test, from the last 64 KiB of its current Session log. It uses the Harness's stream interpretation, including Claude and Codex, and ignores malformed or unknown lines. Missing or unreadable Session logs leave the event unavailable.

-

status and show describe live work as Silent when neither its Session log nor its Command log has grown for inbox.silent_minutes (10 by default). Silence starts no earlier than the current stage. At three times the threshold, the words escalate: silent 45 min · past 30. A fresh line in either log keeps the Run from being Silent. Missing logs use the stage's start time.

+

status and show describe live work as Silent when neither its Session log nor its Command log has grown for inbox.silent_minutes (10 by default). Silence starts no earlier than the current stage. A dispatch stage is never Silent or Slow and has no Usual range: the dispatched Run or Spec run carries its own. At three times the threshold, the words escalate: silent 45 min · past 30. A fresh line in either log keeps the Run from being Silent. Missing logs use the stage's start time.

A stage's Usual range is its 25th–75th percentile time over the repository's last 30 Command records on this machine. Completed stages supply times, with the next stage's start or the Command's end marking completion; an unfinished stage supplies none. The range appears once there are at least three stage times. Quartiles interpolate between sorted times. A live Run past the top of the range is Slow: slower than usual (12–17 min), still working. At twice the top it also shows the multiple, such as 2× usual or 3× usual. Silent takes precedence over Slow.

Both JSON views add health to recorded Commands: {"state":"ok"}, {"state":"slow","step":1,"usual_range":{"lower_seconds":720.0,"upper_seconds":1020.0},"multiple":1}, or {"state":"silent","step":2,"seconds":2700,"threshold_seconds":600}. Step 1 is the first threshold; step 2 is the escalation. Ended or dead Commands have null health. The usual_ranges map gives each stage's range by name, for example {"implement":{"lower_seconds":720.0,"upper_seconds":1020.0}}; a stage is omitted until enough times exist. Health and ranges are reader observations, never written back to Command records.

show --json is a versioned API, usable outside a repository. Version 1 wraps the selected Command in this shape: