From f709ba72d65716e9ea73999a66e58d8652939c24 Mon Sep 17 00:00:00 2001 From: Jacob Stephens Date: Mon, 19 Oct 2026 06:53:37 +0000 Subject: [PATCH 01/10] Give same-second Commands distinct owned logs and records (#795) --- CONTEXT.md | 2 +- ...ift-keeps-a-per-repository-activity-log.md | 2 +- docs/code-navigation.md | 1 + docs/guide.md | 14 +- src/logs.rs | 23 +- src/logs/command_log.rs | 14 -- src/logs/effects.rs | 24 +- src/logs/owner.rs | 215 +++++++++++++++++ src/logs/owner/tests.rs | 150 ++++++++++++ src/logs/recording.rs | 49 ++-- src/logs/recording/tests.rs | 216 ++++++++++++------ src/logs/status.rs | 27 ++- src/logs/status/history.rs | 44 ++-- src/logs/status/inspect.rs | 25 +- tests/command_logs.rs | 12 +- tests/run_notification.rs | 6 + tests/show_logs.rs | 93 ++++++++ tests/status.rs | 55 +++++ 18 files changed, 760 insertions(+), 212 deletions(-) delete mode 100644 src/logs/command_log.rs create mode 100644 src/logs/owner.rs create mode 100644 src/logs/owner/tests.rs diff --git a/CONTEXT.md b/CONTEXT.md index 9364f8a4..230e945f 100644 --- a/CONTEXT.md +++ b/CONTEXT.md @@ -224,7 +224,7 @@ One invocation of thirdshift that does factory work: a **Run** or **Spec run** s _Avoid_: invocation, job **Command log**: -Everything one **Run**, **Spec run**, **Architect run**, **Pickup run** or **Security run** printed, kept in a file of its own with its repository's other logs, stamped like its **Session logs**. An Architect run's, Pickup run's or Security run's covers the Spec runs or Runs it dispatched, and a Spec run's covers its **Tickets**' Runs, as a Run's covers its **Base fix**: none of those keeps one of its own. It is kept once the command starts work: a Pickup run, Architect run or Security run skipped before doing any work keeps none, and neither does a Run that fails before it starts work, such as on **Origin match**. +Everything one **Run**, **Spec run**, **Architect run**, **Pickup run** or **Security run** printed, kept in a file of its own with its repository's other logs, stamped like its **Session logs**. Commands with the same start time still keep separate Command logs and **Command records**. An Architect run's, Pickup run's or Security run's covers the Spec runs or Runs it dispatched, and a Spec run's covers its **Tickets**' Runs, as a Run's covers its **Base fix**: none of those keeps one of its own. It is kept once the command starts work: a Pickup run, Architect run or Security run skipped before doing any work keeps none, and neither does a Run that fails before it starts work, such as on **Origin match**. _Avoid_: cron log, output log, run log (a **Run** is one kind of command) **Activity log**: diff --git a/docs/adr/0011-thirdshift-keeps-a-per-repository-activity-log.md b/docs/adr/0011-thirdshift-keeps-a-per-repository-activity-log.md index f6606d3f..4108d07f 100644 --- a/docs/adr/0011-thirdshift-keeps-a-per-repository-activity-log.md +++ b/docs/adr/0011-thirdshift-keeps-a-per-repository-activity-log.md @@ -15,6 +15,6 @@ This replaces ADR 0009's consequence that a skip leaves only its line in the sch ## Consequences -- The repository in the path is the GitHub repository, `/`, not the name of the local checkout, so log file names drop it: `commands/pickup/41-.log`, `sessions/41--implement.jsonl`. +- The repository in the path is the GitHub repository, `/`, not the name of the local checkout, so log file names drop it: `commands/pickup/41-~.log`. Command logs are exclusively allocated with an immutable random owner token, so Commands sharing a start stamp retain separate output and records. Session writers temporarily retain `commands/pickup/41--implement.jsonl` until the Session-ownership Ticket; readers accept both tokenless and token-bearing Session names. Existing legacy Command logs and records remain readable. - Whether the scheduler is still firing is no longer a line per pass: an idle repository's Activity log ends on one skip line. - Logs written before this, under `/sessions/` and `/commands/`, are not moved by thirdshift. diff --git a/docs/code-navigation.md b/docs/code-navigation.md index c7f25a74..28dd7cec 100644 --- a/docs/code-navigation.md +++ b/docs/code-navigation.md @@ -18,6 +18,7 @@ Start with the issue's terms in `CONTEXT.md`, then use this index to find their | Session prompt, Factory skills | `src/prompt.rs`; `src/skills.rs`; `skills/` | `src/skills/tests.rs`, `tests/packaging.rs` | | Session log, Resume | `src/session.rs` and `src/session/` | `src/session/execution_tests.rs`, `tests/background_work.rs` | | Command log, Activity log | `src/logs.rs`; `src/logs/recording.rs` — `Record` | `src/logs/recording/tests.rs`, `tests/command_logs.rs`, `tests/activity_log.rs` | +| Command-log allocation, artifact ownership and filename decoding | `src/logs/owner.rs` — `allocate`, `Owner`, `decode`, `session_matches` | `src/logs/owner/tests.rs`, `src/logs/recording/tests.rs`, `tests/status.rs`, `tests/show_logs.rs` | | Command record, status | `src/logs/recording.rs`; `src/logs/command_record.rs`; `src/logs/status.rs` and `src/logs/status/history.rs`; `src/logs/process_identity.rs` | `tests/status.rs`, `src/logs/recording/tests.rs` | | Command naming, show, logs | `src/logs/status/inspect.rs` — Command resolution, detailed state, Session selection and log following | `tests/show_logs.rs` | | Stop | `src/logs/stop.rs` — request, signaling and waiting; `src/claim.rs` — Stop endings | `tests/stop.rs`; inline Claim and Stop tests | diff --git a/docs/guide.md b/docs/guide.md index 82f12631..e4600a40 100644 --- a/docs/guide.md +++ b/docs/guide.md @@ -624,10 +624,10 @@ Everything thirdshift logs goes under `~/.thirdshift/logs/`, or the `logs.dir` s ├── audits/ each Security audit's report, with its evidence ├── security-reviews/ each Security review's private report of old findings └── commands/ - ├── architect/ .log and Session logs - ├── pickup/ -.log and Session logs - ├── secure/ .log and Session logs - └── issue/ -.log and Session logs + ├── architect/ ~.log and Session logs + ├── pickup/ -~.log and Session logs + ├── secure/ ~.log and Session logs + └── issue/ -~.log and Session logs ``` The folder already names the repository, so no file name repeats it. `audits/` and `security-reviews/` hold vulnerability evidence, so keep the logs private (see [Security runs](#security-runs)). A **Session log** is one session's full transcript, as the Harness's JSON output, such as Claude Code's `stream-json`: @@ -646,11 +646,13 @@ A **Command log** is everything one command printed, stderr and stdout in the or The stamp is the local time the command started, with its UTC offset, as in `20261003T120000-0400`, in the machine's time zone, or `TZ`'s if set, so it agrees with `date` and `ls -l`. A command's Command log and all of its Session logs, its Tickets' Runs' and its Base fix's included, share that one stamp, so they sort together and each can be found from the other. When a Run fails, stderr ends with the path of its most recent Session log, the place to start looking, then that of its Command log. +New Command logs insert `~` immediately after the stamp. The random token gives each Command its own storage even when start times agree; its Command record uses that exact stem followed by `.command.json`. Human Command names stay the same. Session writers still use the tokenless examples above during this transition; readers also accept Session names with `~`. A matching stamp alone does not attach a tokenless Session to a new Command: a record reference or exact Model evidence must establish that ownership. Legacy logs and records remain readable without renaming. + The **Activity log**, `activity.log`, is a short running record of what the factory did on the repository ([ADR-0011](adr/0011-thirdshift-keeps-a-per-repository-activity-log.md)). A Run, a Spec run or a Pass writes a line when it starts work, naming its Command log, and one when it ends, with its outcome; a Run you type by hand writes them too, and the run a Pass dispatched, a Spec run's Tickets and a Base fix write none of their own. A skipped Pass writes a line only when its reason differs from the last line of its own kind, so a repository that sits idle shows one line, not one per pass, and the first skip after a pass that did work always shows: that is when the repository went idle. Every line starts with the local date and time: ``` 2026-10-03 02:00:01 Pickup run skipped: no Ready issue on acme/widgets -2026-10-03 09:30:01 Pickup run #41 started: commands/pickup/41-20261003T093001-0400.log +2026-10-03 09:30:01 Pickup run #41 started: commands/pickup/41-20261003T093001-0400~aB3cD4eF5gH6iJ7k.log 2026-10-03 09:52:17 Pickup run #41 ended: PR https://github.com/acme/widgets/pull/42 is merged 2026-10-03 10:00:01 Pickup run skipped: no Ready issue on acme/widgets ``` @@ -1086,7 +1088,7 @@ thirdshift: 03:00:01 Pickup run starting, 2026-10-03 -0400 thirdshift: 03:00:02 #18 labelled needs-info thirdshift: 03:00:03 #20 blocked by #17 thirdshift: 03:00:04 taking Ready issue #22 "Sharpen the widgets", as thirdshift https://github.com/acme/widgets/issues/22 would -thirdshift: 03:00:04 logging this command to ~/.thirdshift/logs/acme/widgets/commands/pickup/22-20261003T030001-0400.log +thirdshift: 03:00:04 logging this command to ~/.thirdshift/logs/acme/widgets/commands/pickup/22-20261003T030001-0400~aB3cD4eF5gH6iJ7k.log ``` ### One Run notification for the issue taken diff --git a/src/logs.rs b/src/logs.rs index 20a82c8d..30f2d54d 100644 --- a/src/logs.rs +++ b/src/logs.rs @@ -12,9 +12,9 @@ //! process-wide interface serializes its operations, including emitted output. mod activity; -mod command_log; mod command_record; mod effects; +mod owner; mod process_identity; mod recording; pub mod status; @@ -356,27 +356,6 @@ impl Work<'_> { Work::ArchitectRun(_) | Work::SecurityRun(_) => None, } } - - /// Where its Command log goes, under its repository's logs at `root`, - /// for the command started at `stamp`: - /// `/commands//.log`, one folder per - /// command typed, so the repository, already in the path, is not in the - /// name. `thirdshift `, a Run or a Spec run, is in `issue/`, - /// `thirdshift pickup` in `pickup/`, both named for the issue, and - /// `thirdshift architect` in `architect/`. - fn command_log(self, root: &Path, stamp: &str) -> PathBuf { - let (folder, prefix) = match self { - Work::Run(issue) | Work::BaseFix(issue) | Work::SpecRun(issue) => { - (CommandKind::Issue, format!("{}-", issue.number)) - } - Work::PickupRun(issue) => (CommandKind::Pickup, format!("{}-", issue.number)), - Work::ArchitectRun(_) => (CommandKind::Architect, String::new()), - Work::SecurityRun(_) => (CommandKind::Secure, String::new()), - }; - root.join("commands") - .join(folder.folder()) - .join(format!("{prefix}{stamp}.log")) - } } /// The [`Record`], locked, even if a thread panicked holding it. diff --git a/src/logs/command_log.rs b/src/logs/command_log.rs deleted file mode 100644 index a92cac21..00000000 --- a/src/logs/command_log.rs +++ /dev/null @@ -1,14 +0,0 @@ -//! Stateless Command log file effects. The recording owner decides its -//! path, held lines, lifetime and warning policy. - -use std::fs::{self, File}; -use std::path::Path; - -use anyhow::{Context, Result}; - -pub(super) fn open(path: &Path) -> Result { - if let Some(dir) = path.parent() { - fs::create_dir_all(dir).with_context(|| format!("could not create {}", dir.display()))?; - } - File::create(path).with_context(|| format!("could not create {}", path.display())) -} diff --git a/src/logs/effects.rs b/src/logs/effects.rs index f74f18c2..ffe1b5b7 100644 --- a/src/logs/effects.rs +++ b/src/logs/effects.rs @@ -8,7 +8,7 @@ use std::path::Path; use anyhow::{Context, Result}; use chrono::{DateTime, FixedOffset, Local}; -use super::{activity, command_log}; +use super::{activity, owner}; #[derive(Clone, Copy, Debug, PartialEq, Eq)] pub(super) enum Stream { @@ -21,13 +21,9 @@ pub(super) struct Tail { pub bytes: Vec, } -pub(super) trait Outside { - type CommandLog: Write + Send; - +pub(super) trait Outside: owner::Files { fn now(&mut self) -> DateTime; fn emit(&mut self, stream: Stream, line: &str) -> io::Result<()>; - fn open_command_log(&mut self, path: &Path) -> Result; - fn command_log_exists(&mut self, path: &Path) -> bool; fn activity_tail(&mut self, path: &Path, limit: u64) -> Result; fn append_activity(&mut self, path: &Path, line: &str) -> Result<()>; fn hostname(&mut self) -> String; @@ -38,9 +34,15 @@ pub(super) trait Outside { pub(super) struct OnMachine; -impl Outside for OnMachine { +impl owner::Files for OnMachine { type CommandLog = File; + fn create_command_log(&mut self, path: &Path) -> io::Result { + owner::create(path) + } +} + +impl Outside for OnMachine { fn stop_request(&mut self, record: &Path) -> Option { super::stop::requested(record) } @@ -80,14 +82,6 @@ impl Outside for OnMachine { } } - fn open_command_log(&mut self, path: &Path) -> Result { - command_log::open(path) - } - - fn command_log_exists(&mut self, path: &Path) -> bool { - path.exists() - } - fn activity_tail(&mut self, path: &Path, limit: u64) -> Result { activity::tail(path, limit) } diff --git a/src/logs/owner.rs b/src/logs/owner.rs new file mode 100644 index 00000000..5c8cbe35 --- /dev/null +++ b/src/logs/owner.rs @@ -0,0 +1,215 @@ +//! Command artifact allocation and the shared legacy/new filename format. +//! A storage owner never changes after allocation, even if its writer fails. + +use std::fs::{self, File, OpenOptions}; +use std::io::{self, Write}; +use std::path::{Path, PathBuf}; + +use anyhow::Result; +use chrono::{DateTime, FixedOffset}; +use serde::Deserialize; + +use super::{CommandKind, Work}; + +pub(super) trait Files { + type CommandLog: Write + Send; + + /// Exclusively acquire a file, reporting AlreadyExists without changing it. + fn create_command_log(&mut self, path: &Path) -> io::Result; +} + +pub(super) struct Owner { + path: PathBuf, +} + +impl Owner { + pub fn log_path(&self) -> &Path { + &self.path + } + + pub fn record_path(&self) -> PathBuf { + self.path.with_extension("command.json") + } +} + +pub(super) struct Allocation { + pub owner: Owner, + pub writer: io::Result, +} + +/// tempfile supplies opaque randomness and collision retries; the adapter +/// supplies exclusive file effects. Non-collision failures retain the selected +/// identity, but do not claim that a file was acquired. +pub(super) fn allocate( + files: &mut F, + root: &Path, + work: Work<'_>, + stamp: &str, +) -> Result> { + let (kind, subject) = match work { + Work::Run(issue) | Work::BaseFix(issue) | Work::SpecRun(issue) => { + (CommandKind::Issue, format!("{}-", issue.number)) + } + Work::PickupRun(issue) => (CommandKind::Pickup, format!("{}-", issue.number)), + Work::ArchitectRun(_) => (CommandKind::Architect, String::new()), + Work::SecurityRun(_) => (CommandKind::Secure, String::new()), + }; + let folder = root.join("commands").join(kind.folder()); + let allocated = tempfile::Builder::new() + .prefix(&format!("{subject}{stamp}~")) + .suffix(".log") + .rand_bytes(16) + .disable_cleanup(true) + .make_in(folder, |path| match files.create_command_log(path) { + Err(error) if error.kind() == io::ErrorKind::AlreadyExists => Err(error), + result => Ok(result), + })?; + let (writer, path) = allocated.into_parts(); + Ok(Allocation { + owner: Owner { + path: path.to_path_buf(), + }, + writer, + }) +} + +pub(super) fn create(path: &Path) -> io::Result { + let create = || { + if let Some(parent) = path.parent() { + fs::create_dir_all(parent)?; + } + OpenOptions::new().write(true).create_new(true).open(path) + }; + create().map_err(|error: io::Error| { + io::Error::new( + error.kind(), + format!("could not create {}: {error}", path.display()), + ) + }) +} + +pub(super) fn child_record(parent: &Path, dispatch: Option<&str>, issue: u64) -> PathBuf { + let dispatch = dispatch + .and_then(|issue| crate::issue::IssueUrl::parse(issue).ok()) + .map_or_else(String::new, |issue| format!("dispatch-{}-", issue.number)); + parent.with_extension(format!("{dispatch}issue-{issue}.child.json")) +} + +#[derive(Clone, Copy, Debug, PartialEq, Eq)] +pub(super) struct Identity<'a> { + pub stamp: &'a str, + pub token: Option<&'a str>, +} + +pub(super) struct Decoded<'a> { + pub subject: &'a str, + pub identity: Identity<'a>, + pub session_kind: Option<&'a str>, +} + +impl Decoded<'_> { + pub fn time(&self) -> DateTime { + parse_stamp(self.identity.stamp).expect("decoded stamp is valid") + } + + pub fn command_log(&self, path: &Path) -> PathBuf { + let subject = match self.subject { + "" | "architect" | "secure" => String::new(), + subject => format!("{subject}-"), + }; + let token = self + .identity + .token + .map(|token| format!("~{token}")) + .unwrap_or_default(); + path.with_file_name(format!("{subject}{}{token}.log", self.identity.stamp)) + } +} + +fn parse_stamp(stamp: &str) -> Option> { + DateTime::parse_from_str(stamp, "%Y%m%dT%H%M%S%z").ok() +} + +/// Read current legacy record suffixes, owned records/logs, and both Session +/// forms. All byte offsets and token syntax live here. +pub(super) fn decode(path: &Path) -> Option> { + let name = path.file_name()?.to_str()?; + let (stem, session) = if let Some(stem) = name.strip_suffix(".jsonl") { + (stem, true) + } else if let Some(stem) = name.strip_suffix(".log") { + (stem, false) + } else { + ( + name.strip_suffix(".command.json") + .or_else(|| name.strip_suffix(".child.json"))? + .split('.') + .next()?, + false, + ) + }; + let (subject, rest) = if stem.get(..20).and_then(parse_stamp).is_some() { + ("", stem) + } else { + stem.split_once('-')? + }; + let stamp = rest.get(..20)?; + parse_stamp(stamp)?; + let tail = rest.get(20..)?; + let (token, tail) = if let Some(tail) = tail.strip_prefix('~') { + let end = tail.find('-').unwrap_or(tail.len()); + let token = &tail[..end]; + if token.is_empty() || !token.bytes().all(|byte| byte.is_ascii_alphanumeric()) { + return None; + } + (Some(token), &tail[end..]) + } else { + (None, tail) + }; + let session_kind = if session { + Some(tail.strip_prefix('-').filter(|kind| !kind.is_empty())?) + } else { + if !tail.is_empty() { + return None; + } + None + }; + Some(Decoded { + subject, + identity: Identity { stamp, token }, + session_kind, + }) +} + +/// Preserve current legacy suffix stripping, including non-stamped fixture +/// records, while keeping an owned stem's entire token. +pub(super) fn record_log(path: &Path) -> PathBuf { + if let Some(decoded) = decode(path) { + return decoded.command_log(path); + } + let name = path.file_name().unwrap_or_default().to_string_lossy(); + path.with_file_name(format!("{}.log", name.split('.').next().unwrap_or(&name))) +} + +/// Explicit Model evidence can link a transitional tokenless Session to its +/// owned Command. Timestamp equality alone cannot establish that link. +pub(super) fn evidenced_log(session: &Path) -> Option { + #[derive(Deserialize)] + struct Evidence { + command_log: Option, + } + let bytes = fs::read(session.with_extension("models.json")).ok()?; + serde_json::from_slice::(&bytes).ok()?.command_log +} + +pub(super) fn session_matches(session: &Path, log: &Path) -> bool { + if let Some(evidence) = evidenced_log(session) { + return evidence == log; + } + match (decode(session), decode(log)) { + (Some(session), Some(command)) => session.identity == command.identity, + _ => false, + } +} + +#[cfg(test)] +mod tests; diff --git a/src/logs/owner/tests.rs b/src/logs/owner/tests.rs new file mode 100644 index 00000000..cb75942e --- /dev/null +++ b/src/logs/owner/tests.rs @@ -0,0 +1,150 @@ +use super::*; +use crate::issue::IssueUrl; +use crate::logs::effects::OnMachine; + +const STAMP: &str = "20261003T120000-0400"; + +#[test] +fn real_files_keep_interleaved_command_output_and_records_separate() { + let root = tempfile::tempdir().unwrap(); + let issue = IssueUrl::parse("https://github.com/acme/widgets/issues/7").unwrap(); + let mut files = OnMachine; + let first = allocate(&mut files, root.path(), Work::Run(&issue), STAMP).unwrap(); + let first_path = first.owner.log_path().to_path_buf(); + let mut first_writer = first.writer.unwrap(); + first_writer.write_all(b"first before\n").unwrap(); + let second = allocate(&mut files, root.path(), Work::Run(&issue), STAMP).unwrap(); + let mut second_writer = second.writer.unwrap(); + second_writer.write_all(b"second before\n").unwrap(); + first_writer.write_all(b"first after\n").unwrap(); + second_writer.write_all(b"second after\n").unwrap(); + assert_ne!(first_path, second.owner.log_path()); + assert_ne!(first.owner.record_path(), second.owner.record_path()); + assert_eq!( + fs::read(first_path).unwrap(), + b"first before\nfirst after\n" + ); + assert_eq!( + fs::read(second.owner.log_path()).unwrap(), + b"second before\nsecond after\n" + ); + for owner in [&first.owner, &second.owner] { + assert_eq!(record_log(&owner.record_path()), owner.log_path()); + let decoded = decode(owner.log_path()).unwrap(); + assert_eq!(decoded.identity.stamp, STAMP); + assert!(decoded.identity.token.is_some()); + assert_eq!(decoded.subject, "7"); + } +} + +#[test] +fn a_forced_collision_preserves_the_existing_file_and_retries_with_a_fresh_token() { + struct Colliding { + occupied: Option, + } + impl Files for Colliding { + type CommandLog = File; + fn create_command_log(&mut self, path: &Path) -> io::Result { + if self.occupied.is_none() { + fs::create_dir_all(path.parent().unwrap())?; + fs::write(path, b"another Command's output\n")?; + self.occupied = Some(path.to_path_buf()); + } + create(path) + } + } + let root = tempfile::tempdir().unwrap(); + let issue = IssueUrl::parse("https://github.com/acme/widgets/issues/7").unwrap(); + let mut files = Colliding { occupied: None }; + let allocated = allocate(&mut files, root.path(), Work::Run(&issue), STAMP).unwrap(); + allocated + .writer + .unwrap() + .write_all(b"new output\n") + .unwrap(); + let occupied = files.occupied.unwrap(); + assert_ne!(occupied, allocated.owner.log_path()); + assert_eq!(fs::read(occupied).unwrap(), b"another Command's output\n"); + assert_eq!( + fs::read(allocated.owner.log_path()).unwrap(), + b"new output\n" + ); +} + +#[test] +fn legacy_and_owned_artifacts_share_one_decoder() { + for (name, subject, token, kind, log) in [ + ( + "7-20261003T120000-0400.log", + "7", + None, + None, + "7-20261003T120000-0400.log", + ), + ( + "7-20261003T120000-0400.123-start-1-9.command.json", + "7", + None, + None, + "7-20261003T120000-0400.log", + ), + ( + "7-20261003T120000-0400~ownerA.command.json", + "7", + Some("ownerA"), + None, + "7-20261003T120000-0400~ownerA.log", + ), + ( + "20261003T120000-0400~ownerB.log", + "", + Some("ownerB"), + None, + "20261003T120000-0400~ownerB.log", + ), + ( + "7-20261003T120000-0400-implement.jsonl", + "7", + None, + Some("implement"), + "7-20261003T120000-0400.log", + ), + ( + "7-20261003T120000-0400~ownerA-repair-1-resume.jsonl", + "7", + Some("ownerA"), + Some("repair-1-resume"), + "7-20261003T120000-0400~ownerA.log", + ), + ( + "architect-20261003T120000-0400~ownerB-architecture-review.jsonl", + "architect", + Some("ownerB"), + Some("architecture-review"), + "20261003T120000-0400~ownerB.log", + ), + ( + "secure-20261003T120000+0530~ownerC-security-review.jsonl", + "secure", + Some("ownerC"), + Some("security-review"), + "20261003T120000+0530~ownerC.log", + ), + ] { + let path = Path::new(name); + let decoded = decode(path).unwrap_or_else(|| panic!("{name}")); + assert_eq!(decoded.subject, subject); + assert_eq!(decoded.identity.token, token); + assert_eq!(decoded.session_kind, kind); + assert_eq!(decoded.command_log(path), Path::new(log)); + } + for name in [ + "7-bad.log", + "7-20261003T120000-0400~.log", + "7-20261003T120000-0400~owner-.log", + "7-20261003T120000-0400~owner.jsonl", + "7-20261003T120000-0400-.jsonl", + ] { + assert!(decode(Path::new(name)).is_none(), "{name}"); + } +} diff --git a/src/logs/recording.rs b/src/logs/recording.rs index 6c0cf4e1..0e1bfc47 100644 --- a/src/logs/recording.rs +++ b/src/logs/recording.rs @@ -5,13 +5,13 @@ use std::collections::VecDeque; use std::fmt::Display; use std::io::Write; use std::path::{Path, PathBuf}; -use std::sync::atomic::{AtomicU64, Ordering}; use anyhow::{Context, Result}; use super::activity::{self, Kind}; use super::command_record::{CommandRecord, CommandTree, Stage, StageName, TicketRecord}; use super::effects::{Outside, Stream}; +use super::owner::{self, Owner}; use super::{Begin, CommandKind, Pass, Work, root_under}; use crate::config::UserConfig; use crate::harness::Choice; @@ -19,11 +19,11 @@ use crate::issue::Repo; use crate::progress; const STAMP_FORMAT: &str = "%Y%m%dT%H%M%S%z"; -static NEXT_RECORD: AtomicU64 = AtomicU64::new(0); pub(super) struct Record { outside: O, stamp: Option, + owner: Option, logs_dir: Option, child: bool, command: CommandKind, @@ -72,6 +72,7 @@ impl Record { Self { outside, stamp: None, + owner: None, logs_dir: None, child: false, command: CommandKind::Issue, @@ -148,7 +149,7 @@ impl Record { let root = self.root(&work.repo()); let stamp = self.stamp(); let began = matches!(self.command_log, Log::Held { .. }); - self.keep(work.command_log(&root, &stamp)); + self.keep(&root, work, &stamp); if began { self.start_record(work, harness); } @@ -216,26 +217,16 @@ impl Record { facts.parent_record = self.parent_record.clone(); facts.parent_dispatch = self.parent_dispatch.clone(); let path = if let Some(parent) = &self.parent_record { - let dispatch = self - .parent_dispatch - .as_ref() - .and_then(|issue| crate::issue::IssueUrl::parse(issue).ok()) - .map_or_else(String::new, |issue| format!("dispatch-{}-", issue.number)); - parent.with_extension(format!( - "{dispatch}issue-{}.child.json", - work.issue().unwrap() - )) + owner::child_record( + parent, + self.parent_dispatch.as_deref(), + work.issue().unwrap(), + ) } else { - // Process identity and a serial separate Commands sharing a stamp. - let owner = format!( - "{}-{}-{}", - facts.process_id, - facts.process_start.replace(':', "-"), - NEXT_RECORD.fetch_add(1, Ordering::Relaxed) - ); - let root = self.root(&work.repo()); - work.command_log(&root, &stamp) - .with_extension(format!("{owner}.command.json")) + let Some(owner) = &self.owner else { + return; + }; + owner.record_path() }; self.command_record = Some(( path, @@ -445,7 +436,7 @@ impl Record { } } - fn keep(&mut self, path: PathBuf) { + fn keep(&mut self, root: &Path, work: Work<'_>, stamp: &str) { self.show_held(); if !matches!(self.command_log, Log::Held { .. }) { return; @@ -453,8 +444,13 @@ impl Record { let Log::Held { lines, .. } = std::mem::replace(&mut self.command_log, Log::NotKept) else { unreachable!() }; + let mut acquired = false; let created: Result = (|| { - let mut writer = self.outside.open_command_log(&path)?; + let allocation = owner::allocate(&mut self.outside, root, work, stamp)?; + self.owner = Some(allocation.owner); + let mut writer = allocation.writer?; + acquired = true; + let path = self.owner.as_ref().unwrap().log_path(); for (_, line) in lines { writeln!(writer, "{line}") .with_context(|| format!("could not write {}", path.display()))?; @@ -464,14 +460,15 @@ impl Record { match created { Ok(writer) => { self.command_log = Log::Kept { - path: path.clone(), + path: self.owner.as_ref().unwrap().log_path().to_path_buf(), writer, }; + let path = self.command_log_path().unwrap(); self.step(format_args!("logging this command to {}", path.display())); } Err(error) => { self.command_log = Log::Failed { - path: self.outside.command_log_exists(&path).then_some(path), + path: acquired.then(|| self.owner.as_ref().unwrap().log_path().to_path_buf()), }; self.step(format_args!( "warning: could not keep the Command log: {error:#}" diff --git a/src/logs/recording/tests.rs b/src/logs/recording/tests.rs index 0a3ce6ed..0f79bc8d 100644 --- a/src/logs/recording/tests.rs +++ b/src/logs/recording/tests.rs @@ -10,7 +10,6 @@ use crate::issue::IssueUrl; use crate::logs::effects::Tail; const STAMP: &str = "20261003T120000-0400"; -const COMMAND: &str = "/logs/acme/widgets/commands/issue/7-20261003T120000-0400.log"; const ACTIVITY: &str = "/logs/acme/widgets/activity.log"; #[derive(Default)] @@ -19,6 +18,7 @@ struct Memory { terminal: Vec<(Stream, String)>, files: BTreeMap, command_open_fails: bool, + existing_on_open_failure: Option, command_bytes_left: Option, activity_read_fails: bool, activity_write_fails: bool, @@ -93,9 +93,32 @@ impl Write for Writer { } } -impl Outside for Scripted { +impl owner::Files for Scripted { type CommandLog = Writer; + fn create_command_log(&mut self, path: &Path) -> io::Result { + let mut memory = self.0.lock().unwrap(); + if memory.command_open_fails { + if memory.existing_on_open_failure.is_some() { + memory + .files + .insert(path.into(), "previous content\n".into()); + memory.existing_on_open_failure = Some(path.into()); + } + return Err(io::Error::other("Command open failed")); + } + if memory.files.contains_key(path) { + return Err(io::ErrorKind::AlreadyExists.into()); + } + memory.files.insert(path.to_path_buf(), String::new()); + Ok(Writer { + memory: self.clone(), + path: path.to_path_buf(), + }) + } +} + +impl Outside for Scripted { fn stop_request(&mut self, record: &Path) -> Option { let memory = self.0.lock().unwrap(); serde_json::from_str(memory.files.get(&record.with_extension("stop.json"))?).ok() @@ -143,22 +166,6 @@ impl Outside for Scripted { Ok(()) } - fn open_command_log(&mut self, path: &Path) -> Result { - let mut memory = self.0.lock().unwrap(); - if memory.command_open_fails { - anyhow::bail!("Command open failed"); - } - memory.files.insert(path.to_path_buf(), String::new()); - Ok(Writer { - memory: self.clone(), - path: path.to_path_buf(), - }) - } - - fn command_log_exists(&mut self, path: &Path) -> bool { - self.0.lock().unwrap().files.contains_key(path) - } - fn activity_tail(&mut self, path: &Path, limit: u64) -> Result { let mut memory = self.0.lock().unwrap(); if memory.activity_read_fails { @@ -265,7 +272,7 @@ fn a_reused_process_id_is_not_a_live_command() { } #[test] -fn commands_started_on_the_same_issue_in_one_second_keep_separate_records() { +fn commands_started_on_the_same_issue_in_one_second_keep_separate_output_and_records() { let memory = Scripted::default(); let issue = issue(); let mut first = Record::new(memory.clone()); @@ -273,12 +280,38 @@ fn commands_started_on_the_same_issue_in_one_second_keep_separate_records() { first.configured(&config(false)); first.started(Work::Run(&issue), &harness()); first.issue_title(Some("first Command".into())); + first.print("first before second starts"); + let first_log = first.command_log_path().unwrap(); + let first_record = first.record_path().unwrap(); let mut second = Record::new(memory.clone()); second.begin(Begin::Run(&issue)); second.configured(&config(false)); second.started(Work::Run(&issue), &harness()); second.issue_title(Some("second Command".into())); + second.print("second before interleaving"); + first.print("first after second starts"); + second.print("second after interleaving"); + let second_log = second.command_log_path().unwrap(); + assert!( + memory + .file(&first_log) + .contains("first before second starts\n"), + "starting the second Command erased the first Command output" + ); + assert_ne!(first_log, second_log); + assert_ne!(first_record, second.record_path().unwrap()); + for (path, own, other) in [ + (&first_log, "first", "second"), + (&second_log, "second", "first"), + ] { + let bytes = memory.file(path); + assert_eq!( + bytes.lines().filter(|line| line.starts_with(own)).count(), + 2 + ); + assert!(!bytes.lines().any(|line| line.starts_with(other))); + } // The effects adapter keeps its clock fixed, so both owners have the same // issue, repository, and second-resolution Command-log stamp. @@ -414,13 +447,22 @@ fn a_run_records_its_complete_output_and_activity_under_its_repository() { record.ended("ready for review"); assert_eq!(record.stamp(), STAMP); - assert_eq!(record.command_log_path(), Some(PathBuf::from(COMMAND))); - let output = "thirdshift: 12:00:00 starting on https://github.com/acme/widgets/issues/7, 2026-10-03 -0400\nchecking Origin match\nthirdshift: 12:00:00 logging this command to /logs/acme/widgets/commands/issue/7-20261003T120000-0400.log\nthirdshift: 12:00:00 sessions run on claude · opus · high\nhttps://github.com/acme/widgets/pull/8\n"; + let path = record.command_log_path().unwrap(); + let relative = path + .strip_prefix(record.root(&issue.repo())) + .unwrap() + .display(); + let output = format!( + "thirdshift: 12:00:00 starting on https://github.com/acme/widgets/issues/7, 2026-10-03 -0400\nchecking Origin match\nthirdshift: 12:00:00 logging this command to {}\nthirdshift: 12:00:00 sessions run on claude · opus · high\nhttps://github.com/acme/widgets/pull/8\n", + path.display() + ); assert_eq!(memory.terminal(), output); - assert_eq!(memory.file(COMMAND), output); + assert_eq!(memory.file(&path), output); assert_eq!( memory.file(ACTIVITY), - "2026-10-03 12:00:00 Run #7 started: commands/issue/7-20261003T120000-0400.log, on claude · opus · high\n2026-10-03 12:00:00 Run #7 ended: ready for review\n" + format!( + "2026-10-03 12:00:00 Run #7 started: {relative}, on claude · opus · high\n2026-10-03 12:00:00 Run #7 ended: ready for review\n" + ) ); } @@ -467,14 +509,19 @@ fn each_work_kind_records_only_its_first_start_and_keeps_its_own_command_folder( record.started(Work::Run(&dispatched), &Choice::default()); record.started(Work::SpecRun(&dispatched), &Choice::default()); record.ended("ready"); - let path = Path::new("/logs/acme/widgets").join(relative); - assert_eq!(record.command_log_path(), Some(path.clone())); + let path = record.command_log_path().unwrap(); + assert_eq!(owner::decode(&path).unwrap().identity.stamp, STAMP); + assert_eq!( + path.parent(), + Path::new("/logs/acme/widgets").join(relative).parent() + ); + let relative = path.strip_prefix("/logs/acme/widgets").unwrap().display(); let output = format!( "thirdshift: 12:00:00 {beginning}, 2026-10-03 -0400\nthirdshift: 12:00:00 logging this command to {}\nthirdshift: 12:00:00 sessions run on claude · opus · high\n", path.display() ); assert_eq!(memory.terminal(), output); - assert_eq!(memory.file(path), output); + assert_eq!(memory.file(&path), output); assert_eq!( memory.file(ACTIVITY), format!( @@ -508,7 +555,8 @@ fn held_output_keeps_streams_and_order_through_configuration_release_and_start() record.show_held(); record.print("after start"); record.ended("done"); - let path = "/logs/acme/widgets/commands/pickup/7-20261003T120000-0400.log"; + let path = record.command_log_path().unwrap(); + let path = path.to_str().unwrap(); let expected = format!( "{held}\nthirdshift: 09:08:07 #21: relayed unchanged\nthirdshift: 12:00:00 logging this command to {path}\nthirdshift: 12:00:00 sessions run on claude · opus · high\nafter start\n" ); @@ -612,7 +660,13 @@ fn lazy_stamps_are_owned_stable_and_independent_of_other_recordings() { first.configured(&config(false)); first.started(Work::Run(&issue()), &harness()); assert_eq!(first.stamp(), STAMP); - assert_eq!(first.command_log_path(), Some(PathBuf::from(COMMAND))); + assert_eq!( + owner::decode(&first.command_log_path().unwrap()) + .unwrap() + .identity + .stamp, + STAMP + ); assert!(memory.terminal().starts_with("thirdshift: 13:01:02 starting on https://github.com/acme/widgets/issues/7, 2026-10-04 +0530\n")); assert!( memory @@ -709,9 +763,21 @@ fn separate_recordings_suppress_skips_from_shared_history_until_their_kind_chang pickup.ended("ready"); skip(&memory, Pass::Pickup, "idle"); skip(&memory, Pass::Architect, "a plan is open"); + let run_path = run.command_log_path().unwrap(); + let run_path = run_path + .strip_prefix("/logs/acme/widgets") + .unwrap() + .display(); + let pickup_path = pickup.command_log_path().unwrap(); + let pickup_path = pickup_path + .strip_prefix("/logs/acme/widgets") + .unwrap() + .display(); assert_eq!( memory.file(ACTIVITY), - "2026-10-03 12:00:00 Pickup run skipped: idle\n2026-10-03 12:00:00 Architect run skipped: a plan is open\n2026-10-03 12:00:00 Run #7 started: commands/issue/7-20261003T120000-0400.log, on claude · opus · high\n2026-10-03 12:00:00 Run #7 ended: ready\n2026-10-03 12:00:00 Pickup run skipped: at the Claim limit\n2026-10-03 12:00:00 Pickup run skipped: idle\n2026-10-03 12:00:00 Pickup run #7 started: commands/pickup/7-20261003T120000-0400.log, on claude · opus · high\n2026-10-03 12:00:00 Pickup run skipped: idle\n2026-10-03 12:00:00 Pickup run #7 ended: ready\n2026-10-03 12:00:00 Pickup run skipped: idle\n" + format!( + "2026-10-03 12:00:00 Pickup run skipped: idle\n2026-10-03 12:00:00 Architect run skipped: a plan is open\n2026-10-03 12:00:00 Run #7 started: {run_path}, on claude · opus · high\n2026-10-03 12:00:00 Run #7 ended: ready\n2026-10-03 12:00:00 Pickup run skipped: at the Claim limit\n2026-10-03 12:00:00 Pickup run skipped: idle\n2026-10-03 12:00:00 Pickup run #7 started: {pickup_path}, on claude · opus · high\n2026-10-03 12:00:00 Pickup run skipped: idle\n2026-10-03 12:00:00 Pickup run #7 ended: ready\n2026-10-03 12:00:00 Pickup run skipped: idle\n" + ) ); } @@ -752,26 +818,21 @@ fn skip_history_uses_the_last_64_kib_and_discards_a_cut_first_line() { } #[test] -fn command_creation_failure_warns_once_and_retains_an_existing_path() { +fn command_creation_failure_warns_once_and_never_adopts_an_existing_path() { for existing in [false, true] { let memory = Scripted::default(); { let mut files = memory.0.lock().unwrap(); files.command_open_fails = true; if existing { - files - .files - .insert(PathBuf::from(COMMAND), "previous content\n".into()); + files.existing_on_open_failure = Some(PathBuf::new()); } } let mut record = Record::new(memory.clone()); record.begin(Begin::Run(&issue())); record.configured(&config(false)); record.started(Work::Run(&issue()), &harness()); - assert_eq!( - record.command_log_path(), - existing.then(|| PathBuf::from(COMMAND)) - ); + assert_eq!(record.command_log_path(), None); // File writes stay disabled even if the underlying problem clears. memory.0.lock().unwrap().command_open_fails = false; record.eprint("carried on"); @@ -792,15 +853,18 @@ fn command_creation_failure_warns_once_and_retains_an_existing_path() { ); assert!(!memory.terminal().contains("logging this command to")); assert!(memory.terminal().ends_with("carried on\nresult\n")); - assert_eq!( - memory.file(COMMAND), - if existing { "previous content\n" } else { "" } - ); - let named = if existing { - "commands/issue/7-20261003T120000-0400.log" - } else { - "no Command log" - }; + if existing { + let path = memory + .0 + .lock() + .unwrap() + .existing_on_open_failure + .clone() + .unwrap(); + assert_eq!(memory.file(&path), "previous content\n"); + assert_eq!(owner::record_log(&record.record_path().unwrap()), path); + } + let named = "no Command log"; assert_eq!( memory.file(ACTIVITY), format!( @@ -821,8 +885,8 @@ fn a_failure_writing_held_lines_retains_the_partial_command_log_path() { record.started(Work::Run(&issue()), &harness()); record.eprint("after failure"); record.ended("done"); - assert_eq!(record.command_log_path(), Some(PathBuf::from(COMMAND))); - assert_eq!(memory.file(COMMAND), "thi"); + let path = record.command_log_path().unwrap(); + assert_eq!(memory.file(&path), "thi"); assert_eq!( memory .terminal() @@ -831,13 +895,13 @@ fn a_failure_writing_held_lines_retains_the_partial_command_log_path() { 1 ); assert!(memory.terminal().contains(&format!( - "warning: could not keep the Command log: could not write {COMMAND}: Command write failed\n" + "warning: could not keep the Command log: could not write {}: Command write failed\n", + path.display() + ))); + assert!(memory.file(ACTIVITY).contains(&format!( + "Run #7 started: {},", + path.strip_prefix("/logs/acme/widgets").unwrap().display() ))); - assert!( - memory - .file(ACTIVITY) - .contains("Run #7 started: commands/issue/7-20261003T120000-0400.log,") - ); assert!(memory.file(ACTIVITY).ends_with("Run #7 ended: done\n")); } @@ -848,7 +912,8 @@ fn an_activity_warning_can_fail_the_command_append_without_recursion_and_each_wa record.begin(Begin::Run(&issue())); record.configured(&config(false)); record.started(Work::Run(&issue()), &harness()); - let command_before = memory.file(COMMAND); + let path = record.command_log_path().unwrap(); + let command_before = memory.file(&path); { let mut faults = memory.0.lock().unwrap(); faults.command_bytes_left = Some(0); @@ -858,12 +923,13 @@ fn an_activity_warning_can_fail_the_command_append_without_recursion_and_each_wa record.ended("failed again"); record.eprint("carried on"); let warning = format!( - "thirdshift: 12:00:00 warning: could not keep the Activity log: Activity write failed\nthirdshift: 12:00:00 warning: could not keep the Command log: could not write {COMMAND}: Command write failed\ncarried on\n" + "thirdshift: 12:00:00 warning: could not keep the Activity log: Activity write failed\nthirdshift: 12:00:00 warning: could not keep the Command log: could not write {}: Command write failed\ncarried on\n", + path.display() ); assert!(memory.terminal().ends_with(&warning)); assert_eq!(memory.terminal().matches("warning:").count(), 2); - assert_eq!(memory.file(COMMAND), command_before); - assert_eq!(record.command_log_path(), Some(PathBuf::from(COMMAND))); + assert_eq!(memory.file(&path), command_before); + assert_eq!(record.command_log_path(), Some(path.clone())); { let mut faults = memory.0.lock().unwrap(); faults.command_bytes_left = None; @@ -871,10 +937,13 @@ fn an_activity_warning_can_fail_the_command_append_without_recursion_and_each_wa } record.ended("recovered"); record.print("result"); - assert_eq!(memory.file(COMMAND), command_before); + assert_eq!(memory.file(&path), command_before); assert_eq!( memory.file(ACTIVITY), - "2026-10-03 12:00:00 Run #7 started: commands/issue/7-20261003T120000-0400.log, on claude · opus · high\n2026-10-03 12:00:00 Run #7 ended: recovered\n" + format!( + "2026-10-03 12:00:00 Run #7 started: {}, on claude · opus · high\n2026-10-03 12:00:00 Run #7 ended: recovered\n", + path.strip_prefix("/logs/acme/widgets").unwrap().display() + ) ); assert_eq!(memory.terminal().matches("warning:").count(), 2); } @@ -961,7 +1030,8 @@ fn terminal_failures_are_ignored_with_creation_append_and_activity_failure_combi record.begin(Begin::Run(&issue())); record.configured(&config(false)); record.started(Work::Run(&issue()), &harness()); - let created = memory.file(COMMAND); + let path = record.command_log_path(); + let created = path.as_ref().map(|path| memory.file(path)); if command_failure == "append" { memory.0.lock().unwrap().command_bytes_left = Some(0); } @@ -980,17 +1050,17 @@ fn terminal_failures_are_ignored_with_creation_append_and_activity_failure_combi .count(), usize::from(!terminal_failure && activity_failure) ); - assert_eq!( - record.command_log_path(), - (command_failure != "open").then(|| PathBuf::from(COMMAND)) - ); - if command_failure != "none" { - assert_eq!(memory.file(COMMAND), created); + assert_eq!(record.command_log_path(), path); + if command_failure == "open" { + assert!(path.is_none()); + } else if command_failure != "none" { + assert_eq!(Some(memory.file(path.as_ref().unwrap())), created); } else { - assert!(memory.file(COMMAND).starts_with("thirdshift: 12:00:00 starting on https://github.com/acme/widgets/issues/7, 2026-10-03 -0400\n")); - assert!(memory.file(COMMAND).ends_with("ordinary output\n")); + let bytes = memory.file(path.as_ref().unwrap()); + assert!(bytes.starts_with("thirdshift: 12:00:00 starting on https://github.com/acme/widgets/issues/7, 2026-10-03 -0400\n")); + assert!(bytes.ends_with("ordinary output\n")); assert_eq!( - memory.file(COMMAND).matches("warning:").count(), + bytes.matches("warning:").count(), usize::from(activity_failure) ); } @@ -1046,10 +1116,10 @@ fn concurrent_output_and_start_have_the_same_terminal_and_command_log_order() { }); record.lock().unwrap().ended("done"); let output = memory.terminal(); - let path = "/logs/acme/widgets/commands/pickup/7-20261003T120000-0400.log"; - assert_eq!(memory.file(path), output); + let path = record.lock().unwrap().command_log_path().unwrap(); + assert_eq!(memory.file(&path), output); assert_eq!(output.lines().count(), 35); - assert!(output.contains(&format!("thirdshift: 12:00:00 logging this command to {path}\nthirdshift: 12:00:00 sessions run on claude · opus · high\n"))); + assert!(output.contains(&format!("thirdshift: 12:00:00 logging this command to {}\nthirdshift: 12:00:00 sessions run on claude · opus · high\n", path.display()))); for worker in 0..2 { for number in 0..16 { let line = format!("worker {worker} line {number}"); diff --git a/src/logs/status.rs b/src/logs/status.rs index bfe9b2bf..b4c091b2 100644 --- a/src/logs/status.rs +++ b/src/logs/status.rs @@ -181,6 +181,21 @@ fn read(all: bool) -> Result { if record.parent_record.is_none() { covered.insert(command_log(&path)); } + for session in record + .stages + .iter() + .filter_map(|stage| stage.session_log.as_ref()) + .chain(record.session_log.as_ref()) + .chain(tree.dispatched.iter().flat_map(|record| { + record + .stages + .iter() + .filter_map(|stage| stage.session_log.as_ref()) + .chain(record.session_log.as_ref()) + })) + { + covered.insert(session.clone()); + } records.insert(path, tree); } } @@ -272,19 +287,13 @@ pub(super) fn retained_resources(path: &Path) -> Result> { } fn command_log(path: &Path) -> PathBuf { - let name = path.file_name().unwrap().to_string_lossy(); - path.with_file_name(format!("{}.log", name.split('.').next().unwrap_or(&name))) -} - -fn parse_stamp(stamp: &str) -> Option> { - DateTime::parse_from_str(stamp, "%Y%m%dT%H%M%S%z").ok() + super::owner::record_log(path) } /// Keep the filename spelling alongside its parsed time for naming and history. fn command_stamp(path: &Path) -> Option<(&str, DateTime)> { - let stem = path.file_stem()?.to_str()?; - let stamp = stem.get(stem.len().checked_sub(20)?..)?; - Some((stamp, parse_stamp(stamp)?)) + let decoded = super::owner::decode(path)?; + Some((decoded.identity.stamp, decoded.time())) } fn tree( diff --git a/src/logs/status/history.rs b/src/logs/status/history.rs index da0053d8..819d9bbc 100644 --- a/src/logs/status/history.rs +++ b/src/logs/status/history.rs @@ -10,6 +10,7 @@ use serde::Serialize; use crate::logs::activity::TIME_FORMAT; use crate::logs::command_record::Issue; +use crate::logs::owner; use crate::progress::ChildLine; #[derive(Clone, Serialize)] @@ -196,14 +197,12 @@ pub(super) fn read(repo: &Path, covered: &HashSet) -> Result) -> Result, - shared_stamps: &HashSet<(PathBuf, String)>, + shared_owners: &[PathBuf], ) -> Result> { let mut groups: BTreeMap = BTreeMap::new(); for folder in super::directories(&repo.join("commands"))? { @@ -300,32 +299,27 @@ fn sessions( if !entry.file_type()?.is_file() { continue; } - let name = entry.file_name(); - let Some(name) = name.to_str().and_then(|name| name.strip_suffix(".jsonl")) else { - continue; - }; - let Some((prefix, rest)) = name.split_once('-') else { - continue; - }; - let Some(stamp) = rest.get(..20).and_then(super::parse_stamp) else { + let path = entry.path(); + let Some(decoded) = + owner::decode(&path).filter(|decoded| decoded.session_kind.is_some()) + else { continue; }; - if rest - .get(20..) - .and_then(|rest| rest.strip_prefix('-')) - .is_none_or(str::is_empty) - { - continue; - } + let prefix = decoded.subject; + let stamp = decoded.time(); let (kind, number) = match prefix.parse::() { Ok(number) => ("Run", Some(number)), Err(_) if prefix == "architect" => ("Architect run", None), Err(_) if prefix == "secure" => ("Security run", None), Err(_) => continue, }; - let command_log = folder.join(format!("{prefix}-{}.log", &rest[..20])); - if covered.contains(&command_log) - || shared_stamps.contains(&(folder.clone(), rest[..20].into())) + let command_log = + owner::evidenced_log(&path).unwrap_or_else(|| decoded.command_log(&path)); + if covered.contains(&path) + || covered.contains(&command_log) + || shared_owners.iter().any(|log| { + log.parent() == Some(folder.as_path()) && owner::session_matches(&path, log) + }) { continue; } diff --git a/src/logs/status/inspect.rs b/src/logs/status/inspect.rs index 4646a2cf..ce2ade43 100644 --- a/src/logs/status/inspect.rs +++ b/src/logs/status/inspect.rs @@ -10,6 +10,7 @@ use serde::Serialize; use super::{Command, Entry}; use crate::issue::IssueUrl; use crate::logs::effects::Outside; +use crate::logs::owner; enum Name { Issue { repository: String, number: u64 }, @@ -170,22 +171,22 @@ impl<'a> Selected<'a> { // A stage can cover several sessions (for example Architecture review // and its Resume), so stage references alone are not a log inventory. if let Some(log) = self.command_log() - && let Some((stamp, _)) = super::command_stamp(log) + && owner::decode(log).is_some() { let prefix = issue .map(|issue| issue.number.to_string()) .or_else(|| pass_prefix(kind).map(String::from)) .context("cannot name Session logs for this Command kind")?; - let prefix = format!("{prefix}-{stamp}-"); for entry in super::entries(log.parent().context("Command log has no directory")?)? { - let name = entry.file_name(); - let name = name.to_string_lossy(); + let path = entry.path(); if entry.file_type()?.is_file() - && name.starts_with(&prefix) - && name.ends_with(".jsonl") - && !paths.contains(&entry.path()) + && owner::decode(&path).is_some_and(|decoded| { + decoded.session_kind.is_some() && decoded.subject == prefix + }) + && owner::session_matches(&path, log) + && !paths.contains(&path) { - paths.push(entry.path()); + paths.push(path); } } } @@ -207,13 +208,7 @@ impl<'a> Selected<'a> { .into_iter() .rev() .find(|path| { - let Some(name) = path.file_name().and_then(|name| name.to_str()) else { - return false; - }; - let Some((_, rest)) = name.split_once('-') else { - return false; - }; - let Some(session) = rest.get(21..).and_then(|rest| rest.strip_suffix(".jsonl")) + let Some(session) = owner::decode(path).and_then(|decoded| decoded.session_kind) else { return false; }; diff --git a/tests/command_logs.rs b/tests/command_logs.rs index 9a7cd83b..69799150 100644 --- a/tests/command_logs.rs +++ b/tests/command_logs.rs @@ -63,7 +63,7 @@ fn logs_in(scenario: &Scenario, folder: &str) -> Vec { } /// The one Command log in `commands/`, which must be named -/// `.log`, and its stamp. +/// `~.log`, and its display stamp. fn the_one_command_log(scenario: &Scenario, folder: &str, prefix: &str) -> (PathBuf, String) { let logs: Vec<_> = logs_in(scenario, &format!("commands/{folder}")) .into_iter() @@ -74,6 +74,8 @@ fn the_one_command_log(scenario: &Scenario, folder: &str, prefix: &str) -> (Path .strip_prefix(prefix) .and_then(|rest| rest.strip_suffix(".log")) .unwrap_or_else(|| panic!("not {prefix}.log: {}", logs[0])); + let (stamp, token) = stamp.split_once('~').expect("owned Command log"); + assert!(!token.is_empty()); assert_local_stamp(stamp); let path = scenario .path(LOGS) @@ -138,7 +140,7 @@ fn a_run_keeps_a_command_log_of_everything_it_printed_and_its_session_logs_share [ format!("7-{stamp}-implement.jsonl"), format!("7-{stamp}-implement.models.json"), - format!("7-{stamp}.log") + path.file_name().unwrap().to_str().unwrap().to_string() ] ); assert_eq!(logs_in(&scenario, ""), ["activity.log", "commands"]); @@ -204,7 +206,7 @@ fn a_pickup_run_that_takes_an_issue_keeps_a_command_log_from_its_first_line() { [ format!("7-{stamp}-implement.jsonl"), format!("7-{stamp}-implement.models.json"), - format!("7-{stamp}.log") + path.file_name().unwrap().to_str().unwrap().to_string() ] ); } @@ -220,13 +222,13 @@ fn a_pickup_spec_keeps_its_tickets_session_logs_beside_its_command_log() { let result = run_in_zone(&scenario, &["pickup"], &[]); assert_eq!(result.code, Some(0), "stderr: {}", result.stderr); - let (_, stamp) = the_one_command_log(&scenario, "pickup", "20-"); + let (path, stamp) = the_one_command_log(&scenario, "pickup", "20-"); assert_eq!( logs_in(&scenario, "commands/pickup"), [ format!("20-{stamp}-spec-review.jsonl"), format!("20-{stamp}-spec-review.models.json"), - format!("20-{stamp}.log"), + path.file_name().unwrap().to_str().unwrap().to_string(), format!("21-{stamp}-implement.jsonl"), format!("21-{stamp}-implement.models.json"), format!("22-{stamp}-implement.jsonl"), diff --git a/tests/run_notification.rs b/tests/run_notification.rs index 32c6faaa..7792d224 100644 --- a/tests/run_notification.rs +++ b/tests/run_notification.rs @@ -143,6 +143,9 @@ fn a_notification_keeps_current_models_when_an_unrelated_record_is_corrupt() { .strip_prefix("7-") .unwrap() .strip_suffix(".log") + .unwrap() + .split('~') + .next() .unwrap(); std::fs::write( scenario @@ -191,6 +194,9 @@ fn a_notification_excludes_an_unrelated_commands_models_with_the_same_stamp() { .strip_prefix("7-") .unwrap() .strip_suffix(".log") + .unwrap() + .split('~') + .next() .unwrap(); let directory = scenario.path(folder); diff --git a/tests/show_logs.rs b/tests/show_logs.rs index 0321be2f..9e933f6d 100644 --- a/tests/show_logs.rs +++ b/tests/show_logs.rs @@ -7,6 +7,99 @@ use support::Scenario; const OPENS_PR: &str = "echo work > work.txt\ngit add work.txt\ngit commit -qm 'Make widgets'\ngh pr create --base main --head issue-7 --title 'Make widgets' --body 'Closes #7'\n"; +#[test] +fn owned_and_legacy_commands_keep_exact_paths_and_record_precedence() { + let scenario = Scenario::new(); + let folder = scenario.path("home/.thirdshift/logs/acme/widgets/commands/issue"); + fs::create_dir_all(&folder).unwrap(); + let mut activity = String::new(); + for (stem, suffix, started, marker) in [ + ( + "7-20261003T120000-0400", + ".123-start-1-0", + "2026-10-03T12:00:00-04:00", + "legacy", + ), + ( + "7-20261003T120000-0400~ownerA", + "", + "2026-10-03T12:00:01-04:00", + "first", + ), + ( + "7-20261003T120000-0400~ownerB", + "", + "2026-10-03T12:00:02-04:00", + "second", + ), + ] { + let log = folder.join(format!("{stem}.log")); + let session = folder.join(format!("{stem}-implement.jsonl")); + fs::write(&log, format!("{marker} Command output\n")).unwrap(); + fs::write(&session, format!("{marker} Session output\n")).unwrap(); + let record = serde_json::json!({ + "version": 1, "kind": "Run", "repository": "acme/widgets", "name": "acme/widgets#7", + "issue": {"number": 7, "url": scenario.issue_url(7), "title": marker}, + "hostname": "factory", "process_id": 0, "process_start": "gone", "harness": "claude", + "model": null, "effort": null, "started_at": started, "ended_at": started, + "stages": [], "session_log": null, "outcome": "ready for review", "cause": null, + "issue_branch": null, "pull_request": null + }); + fs::write( + folder.join(format!("{stem}{suffix}.command.json")), + serde_json::to_vec(&record).unwrap(), + ) + .unwrap(); + activity.push_str(&format!("2026-10-03 12:00:00 Run #7 started: commands/issue/{stem}.log, on claude\n2026-10-03 12:00:01 Run #7 ended: ready for review\n")); + } + fs::write( + folder + .parent() + .unwrap() + .parent() + .unwrap() + .join("activity.log"), + activity, + ) + .unwrap(); + let status = scenario.run(&["status", "--all", "--json"]); + assert_eq!(status.code, Some(0), "{}", status.stderr); + let status: Value = serde_json::from_str(&status.stdout).unwrap(); + assert_eq!(status["version"], 1); + let commands = status["commands"].as_array().unwrap(); + assert_eq!(commands.len(), 3, "{status}"); + for command in commands { + assert_eq!(command["source"], "command_record"); + let output = fs::read_to_string(command["command_log"].as_str().unwrap()).unwrap(); + assert!(output.starts_with(command["issue"]["title"].as_str().unwrap())); + } + let shown = scenario.run(&["show", "widgets#7", "--json"]); + assert_eq!(shown.code, Some(0), "{}", shown.stderr); + let shown: Value = serde_json::from_str(&shown.stdout).unwrap(); + assert_eq!( + shown["command"]["command_log"], + folder + .join("7-20261003T120000-0400~ownerB.log") + .to_str() + .unwrap() + ); + assert_eq!( + shown["command"]["session_logs"], + serde_json::json!([folder.join("7-20261003T120000-0400~ownerB-implement.jsonl")]) + ); + for args in [ + vec!["logs", "widgets#7"], + vec!["logs", "widgets#7", "--follow"], + ] { + let output = scenario.run(&args); + assert_eq!(output.code, Some(0), "{}", output.stderr); + assert_eq!(output.stdout, "second Command output\n"); + } + let session = scenario.run(&["logs", "widgets#7", "--session", "implement"]); + assert_eq!(session.code, Some(0), "{}", session.stderr); + assert_eq!(session.stdout, "second Session output\n"); +} + #[test] fn show_activity_history_lists_its_session_logs() { let scenario = Scenario::new(); diff --git a/tests/status.rs b/tests/status.rs index cf3db3a6..0fb21886 100644 --- a/tests/status.rs +++ b/tests/status.rs @@ -234,6 +234,61 @@ fn write_record(scenario: &Scenario, number: u32, started: &str, ended: Option<& .unwrap(); } +#[test] +fn tokenless_sessions_require_explicit_evidence_to_belong_to_an_owned_command() { + for evidence in ["none", "record", "models"] { + let scenario = Scenario::new(); + write_record( + &scenario, + 7, + "2026-10-03T12:00:01-04:00", + Some("2026-10-03T13:00:00-04:00"), + ); + let folder = scenario.path(LOGS); + let record = folder.join("7-20261003T120000-0400~ownerA.command.json"); + fs::rename(folder.join("7-fixture.command.json"), &record).unwrap(); + let log = folder.join("7-20261003T120000-0400~ownerA.log"); + fs::write(&log, "owned Command output\n").unwrap(); + let session = folder.join("7-20261003T120000-0400-implement.jsonl"); + fs::write(&session, "tokenless Session\n").unwrap(); + match evidence { + "record" => { + let mut facts: Value = serde_json::from_slice(&fs::read(&record).unwrap()).unwrap(); + facts["session_log"] = serde_json::json!(session); + fs::write(&record, serde_json::to_vec(&facts).unwrap()).unwrap(); + } + "models" => fs::write( + session.with_extension("models.json"), + serde_json::json!({"command_log": log}).to_string(), + ) + .unwrap(), + _ => {} + } + let status = scenario.run(&["status", "--all", "--json"]); + assert_eq!(status.code, Some(0), "{}", status.stderr); + let status: Value = serde_json::from_str(&status.stdout).unwrap(); + assert_eq!( + status["commands"].as_array().unwrap().len(), + if evidence == "none" { 2 } else { 1 }, + "{evidence}: {status}" + ); + // The later record start keeps selection independent of equal-stamp + // ordering while we test the inventory of the owned Command. + let shown = scenario.run(&["show", "widgets#7", "--json"]); + assert_eq!(shown.code, Some(0), "{}", shown.stderr); + let shown: Value = serde_json::from_str(&shown.stdout).unwrap(); + assert_eq!(shown["command"]["source"], "command_record"); + assert_eq!( + shown["command"]["session_logs"] + .as_array() + .unwrap() + .contains(&serde_json::json!(session)), + evidence != "none", + "{evidence}: {shown}" + ); + } +} + #[test] fn status_shows_recent_outcomes_and_all_history_newest_first() { let scenario = Scenario::new(); From e91f0e5537ce65bcac1de0975f31947bb367e4d4 Mon Sep 17 00:00:00 2001 From: Jacob Stephens Date: Mon, 19 Oct 2026 06:57:30 +0000 Subject: [PATCH 02/10] Address ownership and Session-reference review findings --- src/logs/command_record.rs | 9 +++++++++ src/logs/owner.rs | 11 ++++------- src/logs/owner/tests.rs | 12 ++++-------- src/logs/recording.rs | 9 +++++---- src/logs/recording/tests.rs | 38 +++++++++++++++++++++++++++++++++++-- src/logs/status.rs | 15 +++------------ src/logs/status/inspect.rs | 8 +------- 7 files changed, 62 insertions(+), 40 deletions(-) diff --git a/src/logs/command_record.rs b/src/logs/command_record.rs index 63fbb02d..3cc7b219 100644 --- a/src/logs/command_record.rs +++ b/src/logs/command_record.rs @@ -162,6 +162,15 @@ impl StageName { } impl CommandRecord { + /// Exact retained Session references, including earlier stages. Callers + /// decide whether they need a deduplicated inventory. + pub fn session_references(&self) -> impl Iterator { + self.stages + .iter() + .filter_map(|stage| stage.session_log.as_ref()) + .chain(self.session_log.as_ref()) + } + pub fn finish(&mut self, account: &crate::run_ending::Account<'_>, now: DateTime) { self.ended_at = Some(now.to_rfc3339()); self.outcome = Some(account.outcome.into()); diff --git a/src/logs/owner.rs b/src/logs/owner.rs index 5c8cbe35..74173562 100644 --- a/src/logs/owner.rs +++ b/src/logs/owner.rs @@ -34,12 +34,12 @@ impl Owner { pub(super) struct Allocation { pub owner: Owner, - pub writer: io::Result, + pub writer: W, } /// tempfile supplies opaque randomness and collision retries; the adapter -/// supplies exclusive file effects. Non-collision failures retain the selected -/// identity, but do not claim that a file was acquired. +/// supplies exclusive file effects. Only a successful acquisition establishes +/// an owner; a failed candidate must never be exposed through a root record. pub(super) fn allocate( files: &mut F, root: &Path, @@ -60,10 +60,7 @@ pub(super) fn allocate( .suffix(".log") .rand_bytes(16) .disable_cleanup(true) - .make_in(folder, |path| match files.create_command_log(path) { - Err(error) if error.kind() == io::ErrorKind::AlreadyExists => Err(error), - result => Ok(result), - })?; + .make_in(folder, |path| files.create_command_log(path))?; let (writer, path) = allocated.into_parts(); Ok(Allocation { owner: Owner { diff --git a/src/logs/owner/tests.rs b/src/logs/owner/tests.rs index cb75942e..2093a0b8 100644 --- a/src/logs/owner/tests.rs +++ b/src/logs/owner/tests.rs @@ -11,10 +11,10 @@ fn real_files_keep_interleaved_command_output_and_records_separate() { let mut files = OnMachine; let first = allocate(&mut files, root.path(), Work::Run(&issue), STAMP).unwrap(); let first_path = first.owner.log_path().to_path_buf(); - let mut first_writer = first.writer.unwrap(); + let mut first_writer = first.writer; first_writer.write_all(b"first before\n").unwrap(); let second = allocate(&mut files, root.path(), Work::Run(&issue), STAMP).unwrap(); - let mut second_writer = second.writer.unwrap(); + let mut second_writer = second.writer; second_writer.write_all(b"second before\n").unwrap(); first_writer.write_all(b"first after\n").unwrap(); second_writer.write_all(b"second after\n").unwrap(); @@ -56,12 +56,8 @@ fn a_forced_collision_preserves_the_existing_file_and_retries_with_a_fresh_token let root = tempfile::tempdir().unwrap(); let issue = IssueUrl::parse("https://github.com/acme/widgets/issues/7").unwrap(); let mut files = Colliding { occupied: None }; - let allocated = allocate(&mut files, root.path(), Work::Run(&issue), STAMP).unwrap(); - allocated - .writer - .unwrap() - .write_all(b"new output\n") - .unwrap(); + let mut allocated = allocate(&mut files, root.path(), Work::Run(&issue), STAMP).unwrap(); + allocated.writer.write_all(b"new output\n").unwrap(); let occupied = files.occupied.unwrap(); assert_ne!(occupied, allocated.owner.log_path()); assert_eq!(fs::read(occupied).unwrap(), b"another Command's output\n"); diff --git a/src/logs/recording.rs b/src/logs/recording.rs index 0e1bfc47..3b2a29f9 100644 --- a/src/logs/recording.rs +++ b/src/logs/recording.rs @@ -444,12 +444,10 @@ impl Record { let Log::Held { lines, .. } = std::mem::replace(&mut self.command_log, Log::NotKept) else { unreachable!() }; - let mut acquired = false; let created: Result = (|| { let allocation = owner::allocate(&mut self.outside, root, work, stamp)?; self.owner = Some(allocation.owner); - let mut writer = allocation.writer?; - acquired = true; + let mut writer = allocation.writer; let path = self.owner.as_ref().unwrap().log_path(); for (_, line) in lines { writeln!(writer, "{line}") @@ -468,7 +466,10 @@ impl Record { } Err(error) => { self.command_log = Log::Failed { - path: acquired.then(|| self.owner.as_ref().unwrap().log_path().to_path_buf()), + path: self + .owner + .as_ref() + .map(|owner| owner.log_path().to_path_buf()), }; self.step(format_args!( "warning: could not keep the Command log: {error:#}" diff --git a/src/logs/recording/tests.rs b/src/logs/recording/tests.rs index 0f79bc8d..856954d3 100644 --- a/src/logs/recording/tests.rs +++ b/src/logs/recording/tests.rs @@ -849,7 +849,7 @@ fn command_creation_failure_warns_once_and_never_adopts_an_existing_path() { assert!( memory .terminal() - .contains("warning: could not keep the Command log: Command open failed\n") + .contains("warning: could not keep the Command log: Command open failed") ); assert!(!memory.terminal().contains("logging this command to")); assert!(memory.terminal().ends_with("carried on\nresult\n")); @@ -862,7 +862,7 @@ fn command_creation_failure_warns_once_and_never_adopts_an_existing_path() { .clone() .unwrap(); assert_eq!(memory.file(&path), "previous content\n"); - assert_eq!(owner::record_log(&record.record_path().unwrap()), path); + assert_eq!(record.record_path(), None); } let named = "no Command log"; assert_eq!( @@ -874,6 +874,40 @@ fn command_creation_failure_warns_once_and_never_adopts_an_existing_path() { } } +#[test] +fn acquisition_failure_does_not_publish_a_record_claiming_the_existing_log() { + let memory = Scripted::default(); + { + let mut files = memory.0.lock().unwrap(); + files.command_open_fails = true; + files.existing_on_open_failure = Some(PathBuf::new()); + } + let mut record = Record::new(memory.clone()); + record.begin(Begin::Run(&issue())); + record.configured(&config(false)); + record.started(Work::Run(&issue()), &harness()); + + let occupied = memory + .0 + .lock() + .unwrap() + .existing_on_open_failure + .clone() + .unwrap(); + assert_eq!(memory.file(&occupied), "previous content\n"); + assert_eq!(record.command_log_path(), None); + + if let Some(path) = record.record_path() { + // status::Command::new uses this exact reconstruction for the log + // returned by status/show and selected by logs. + assert_ne!( + owner::record_log(&path), + occupied, + "a persisted record claims a Command log that was never acquired" + ); + } +} + #[test] fn a_failure_writing_held_lines_retains_the_partial_command_log_path() { let memory = Scripted::default(); diff --git a/src/logs/status.rs b/src/logs/status.rs index b4c091b2..be1d11b2 100644 --- a/src/logs/status.rs +++ b/src/logs/status.rs @@ -181,18 +181,9 @@ fn read(all: bool) -> Result { if record.parent_record.is_none() { covered.insert(command_log(&path)); } - for session in record - .stages - .iter() - .filter_map(|stage| stage.session_log.as_ref()) - .chain(record.session_log.as_ref()) - .chain(tree.dispatched.iter().flat_map(|record| { - record - .stages - .iter() - .filter_map(|stage| stage.session_log.as_ref()) - .chain(record.session_log.as_ref()) - })) + for session in std::iter::once(record) + .chain(&tree.dispatched) + .flat_map(CommandRecord::session_references) { covered.insert(session.clone()); } diff --git a/src/logs/status/inspect.rs b/src/logs/status/inspect.rs index ce2ade43..6049fd14 100644 --- a/src/logs/status/inspect.rs +++ b/src/logs/status/inspect.rs @@ -145,13 +145,7 @@ impl<'a> Selected<'a> { let (mut paths, issue, kind) = match self { Self::Record(command) => { let mut paths = Vec::new(); - for path in command - .record - .stages - .iter() - .filter_map(|stage| stage.session_log.as_ref()) - .chain(command.record.session_log.as_ref()) - { + for path in command.record.session_references() { if !paths.contains(path) { paths.push(path.clone()); } From 27d54b2bd89e7906126885cbd5da5804e2ef2a0a Mon Sep 17 00:00:00 2001 From: Jacob Stephens Date: Mon, 19 Oct 2026 07:02:13 +0000 Subject: [PATCH 03/10] Keep Architect name fixture independent of storage owner token --- tests/architect_run.rs | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/tests/architect_run.rs b/tests/architect_run.rs index f39aaf9b..0d49e264 100644 --- a/tests/architect_run.rs +++ b/tests/architect_run.rs @@ -1833,7 +1833,12 @@ fn status_names_a_live_architecture_review_by_kind_and_command_stamp() { "home/.thirdshift/logs/acme/widgets/commands/architect", "log", ); - let name = format!("architect-{}", log[0].strip_suffix(".log").unwrap()); + let (stamp, _) = log[0] + .strip_suffix(".log") + .unwrap() + .split_once('~') + .expect("owned Command log"); + let name = format!("architect-{stamp}"); assert_eq!(command["name"], name); assert!(text.stdout.contains(&name), "{}", text.stdout); assert!( From d36079c191ab0d48e7c331aacd060737359f0630 Mon Sep 17 00:00:00 2001 From: Jacob Stephens Date: Mon, 19 Oct 2026 07:14:10 +0000 Subject: [PATCH 04/10] Use display stamp in Session log failure fixture --- tests/progress_lines.rs | 1 + 1 file changed, 1 insertion(+) diff --git a/tests/progress_lines.rs b/tests/progress_lines.rs index 48965091..dc34ba5b 100644 --- a/tests/progress_lines.rs +++ b/tests/progress_lines.rs @@ -286,6 +286,7 @@ for log in "{logs}/commands/issue/"*.log; do name=${{log##*/}} stamp=${{name#7-}} stamp=${{stamp%.log}} + stamp=${{stamp%%~*}} done mkdir -p "{logs}/commands/issue" ln -s "{pipe}" "{logs}/commands/issue/7-$stamp-implement.jsonl" From d83d24874d301e498431172a229a950f1c6e2042 Mon Sep 17 00:00:00 2001 From: Jacob Stephens Date: Mon, 19 Oct 2026 07:56:17 +0000 Subject: [PATCH 05/10] Regenerate site manual after Command log documentation changes --- site/docs/index.html | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/site/docs/index.html b/site/docs/index.html index a6bc092d..449a9e58 100644 --- a/site/docs/index.html +++ b/site/docs/index.html @@ -522,10 +522,10 @@

Logs

├── audits/ each Security audit's report, with its evidence ├── security-reviews/ each Security review's private report of old findings └── commands/ - ├── architect/ <stamp>.log and Session logs - ├── pickup/ <n>-<stamp>.log and Session logs - ├── secure/ <stamp>.log and Session logs - └── issue/ <n>-<stamp>.log and Session logs + ├── architect/ <stamp>~<token>.log and Session logs + ├── pickup/ <n>-<stamp>~<token>.log and Session logs + ├── secure/ <stamp>~<token>.log and Session logs + └── issue/ <n>-<stamp>~<token>.log and Session logs

The folder already names the repository, so no file name repeats it. audits/ and security-reviews/ hold vulnerability evidence, so keep the logs private (see Security runs). A Session log is one session's full transcript, as the Harness's JSON output, such as Claude Code's stream-json:

~/.thirdshift/logs/<owner>/<repo>/commands/issue/<n>-<stamp>-implement.jsonl
@@ -536,9 +536,10 @@ 

Logs

A Resume is logged as its session's kind plus -resume, e.g. implement-resume.jsonl.

A Command log is everything one command printed, stderr and stdout in the order printed, while the terminal still shows all of it. Its folder is the command typed: thirdshift <Issue URL>, a Run or a Spec run, in issue/, thirdshift pickup in pickup/, named for the issue it took, and thirdshift architect in architect/. A Spec run's covers its Tickets' Runs, a Run's covers its Base fix, and a Pass's covers the Spec run or Run it dispatched: none of those keeps one of its own. So ls -t ~/.thirdshift/logs/acme/widgets/commands/pickup/*.log | head lists the recent passes on acme/widgets that took an issue. A command keeps its Command log once it starts work: a Pass skipped before doing any work keeps none, nor does a Run that fails before it starts work, as on the Origin match, and setup, email-test, update, version and help never keep one. Lines printed before the Command log's name is known, such as a Pickup run's lines on the issues it passed over before it took one, are written first, and once it is created a progress line says logging this command to <path>. A Command log that can't be written produces one warning: line on stderr. A failure confined to the Command log leaves the outcome, stdout and exit code unchanged; if the shared folder also prevents writing a Session log, the Run fails before starting that session.

The stamp is the local time the command started, with its UTC offset, as in 20261003T120000-0400, in the machine's time zone, or TZ's if set, so it agrees with date and ls -l. A command's Command log and all of its Session logs, its Tickets' Runs' and its Base fix's included, share that one stamp, so they sort together and each can be found from the other. When a Run fails, stderr ends with the path of its most recent Session log, the place to start looking, then that of its Command log.

+

New Command logs insert ~<token> immediately after the stamp. The random token gives each Command its own storage even when start times agree; its Command record uses that exact stem followed by .command.json. Human Command names stay the same. Session writers still use the tokenless examples above during this transition; readers also accept Session names with ~<token>. A matching stamp alone does not attach a tokenless Session to a new Command: a record reference or exact Model evidence must establish that ownership. Legacy logs and records remain readable without renaming.

The Activity log, activity.log, is a short running record of what the factory did on the repository (ADR-0011). A Run, a Spec run or a Pass writes a line when it starts work, naming its Command log, and one when it ends, with its outcome; a Run you type by hand writes them too, and the run a Pass dispatched, a Spec run's Tickets and a Base fix write none of their own. A skipped Pass writes a line only when its reason differs from the last line of its own kind, so a repository that sits idle shows one line, not one per pass, and the first skip after a pass that did work always shows: that is when the repository went idle. Every line starts with the local date and time:

2026-10-03 02:00:01 Pickup run skipped: no Ready issue on acme/widgets
-2026-10-03 09:30:01 Pickup run #41 started: commands/pickup/41-20261003T093001-0400.log
+2026-10-03 09:30:01 Pickup run #41 started: commands/pickup/41-20261003T093001-0400~aB3cD4eF5gH6iJ7k.log
 2026-10-03 09:52:17 Pickup run #41 ended: PR https://github.com/acme/widgets/pull/42 is merged
 2026-10-03 10:00:01 Pickup run skipped: no Ready issue on acme/widgets
 
@@ -840,7 +841,7 @@

Why an issue was passed over

thirdshift: 03:00:02 #18 labelled needs-info thirdshift: 03:00:03 #20 blocked by #17 thirdshift: 03:00:04 taking Ready issue #22 "Sharpen the widgets", as thirdshift https://github.com/acme/widgets/issues/22 would -thirdshift: 03:00:04 logging this command to ~/.thirdshift/logs/acme/widgets/commands/pickup/22-20261003T030001-0400.log +thirdshift: 03:00:04 logging this command to ~/.thirdshift/logs/acme/widgets/commands/pickup/22-20261003T030001-0400~aB3cD4eF5gH6iJ7k.log

One Run notification for the issue taken

A Pickup run asked for a Run notification, by email or by email.always = true in the User config without no-email, sends exactly one when it took a Ready issue: the notification the Spec run or Run it dispatched would have sent started by hand. An address after email wins over email.to, as for a Run.

From 1feb839ba1b0ac3ef90c39115639c0777a1d1faf Mon Sep 17 00:00:00 2001 From: Jacob Stephens Date: Mon, 19 Oct 2026 08:30:28 +0000 Subject: [PATCH 06/10] Carry exact Command ownership through Session logs and child Runs (#796) --- CONTEXT.md | 4 +- ...ift-keeps-a-per-repository-activity-log.md | 2 +- docs/code-navigation.md | 2 +- docs/guide.md | 30 ++--- site/docs/index.html | 30 ++--- src/logs.rs | 7 +- src/logs/owner.rs | 118 ++++++++++++++++-- src/logs/owner/tests.rs | 22 ++-- src/logs/recording.rs | 37 +++++- src/logs/recording/tests.rs | 12 ++ src/session.rs | 104 ++++++++++++--- src/session/execution_tests.rs | 24 +++- src/session/recording.rs | 56 +++++---- src/session/recording/tests.rs | 97 +++++++++----- tests/command_logs.rs | 17 ++- tests/run_notification.rs | 5 +- tests/show_logs.rs | 39 ++++++ tests/spec_run.rs | 37 ++++++ 18 files changed, 510 insertions(+), 133 deletions(-) diff --git a/CONTEXT.md b/CONTEXT.md index 230e945f..7f9dc9ea 100644 --- a/CONTEXT.md +++ b/CONTEXT.md @@ -216,7 +216,7 @@ A commit that appears on the **Issue branch** during a **Run** and was made neit A continuation of the same agent session, started once when that session ended its turn with background work still running, which was killed with it: thirdshift takes it as work the session was waiting on. Its **Session prompt** asks the agent to re-run that work in the foreground and finish. A Resume that ends the same way gets no second Resume and does not fail the **Run**: the work may have been abandoned rather than awaited, so thirdshift names it in a progress line and carries on, and the steps that follow decide the outcome. If the Run is then a **Failed run**, its cause names the killed work ahead of the step that failed. A Resume is not a **Repair** and does not count against the Repair cap. **Session log**: -The full transcript of one agent session, one per session, a **Resume** and each **Repair** included. Kept with its repository's other logs, named for the session's kind and stamped with the local time its command started, so all of a command's Session logs sort together. Model evidence is kept beside each Session log and belongs to the exact owning **Command**, including across child Runs. It survives an interrupted stream and is replaced by completed retained evidence only when a report is available, even when that report has no observed Models; an absent report leaves the stream evidence intact. Requested **Model** and **Effort** choices are recorded separately from observed Models. A session that ran the code review has its reviewers' reports kept beside its Session log. +The full transcript of one agent session, one per session, a **Resume** and each **Repair** included. Kept with its repository's other logs, named for the session's kind and stamped with the local time its command started, so all of a command's Session logs sort together. The start stamp is a display and grouping fact; distinct Commands have distinct storage ownership even when their stamps agree. Model evidence is kept beside each Session log and belongs to the exact owning **Command**, including across child Runs. It survives an interrupted stream and is replaced by completed retained evidence only when a report is available, even when that report has no observed Models; an absent report leaves the stream evidence intact. Requested **Model** and **Effort** choices are recorded separately from observed Models. A session that ran the code review has its reviewers' reports kept beside its Session log. _Avoid_: transcript, session file **Command**: @@ -224,7 +224,7 @@ One invocation of thirdshift that does factory work: a **Run** or **Spec run** s _Avoid_: invocation, job **Command log**: -Everything one **Run**, **Spec run**, **Architect run**, **Pickup run** or **Security run** printed, kept in a file of its own with its repository's other logs, stamped like its **Session logs**. Commands with the same start time still keep separate Command logs and **Command records**. An Architect run's, Pickup run's or Security run's covers the Spec runs or Runs it dispatched, and a Spec run's covers its **Tickets**' Runs, as a Run's covers its **Base fix**: none of those keeps one of its own. It is kept once the command starts work: a Pickup run, Architect run or Security run skipped before doing any work keeps none, and neither does a Run that fails before it starts work, such as on **Origin match**. +Everything one **Run**, **Spec run**, **Architect run**, **Pickup run** or **Security run** printed, kept in a file of its own with its repository's other logs, stamped like its **Session logs**. The start stamp is for display and grouping; Commands with the same start time still have distinct storage ownership for their Command logs, Session logs and **Command records**. An Architect run's, Pickup run's or Security run's covers the Spec runs or Runs it dispatched, and a Spec run's covers its **Tickets**' Runs, as a Run's covers its **Base fix**: none of those keeps one of its own. It is kept once the command starts work: a Pickup run, Architect run or Security run skipped before doing any work keeps none, and neither does a Run that fails before it starts work, such as on **Origin match**. _Avoid_: cron log, output log, run log (a **Run** is one kind of command) **Activity log**: diff --git a/docs/adr/0011-thirdshift-keeps-a-per-repository-activity-log.md b/docs/adr/0011-thirdshift-keeps-a-per-repository-activity-log.md index 4108d07f..0d81b8db 100644 --- a/docs/adr/0011-thirdshift-keeps-a-per-repository-activity-log.md +++ b/docs/adr/0011-thirdshift-keeps-a-per-repository-activity-log.md @@ -15,6 +15,6 @@ This replaces ADR 0009's consequence that a skip leaves only its line in the sch ## Consequences -- The repository in the path is the GitHub repository, `/`, not the name of the local checkout, so log file names drop it: `commands/pickup/41-~.log`. Command logs are exclusively allocated with an immutable random owner token, so Commands sharing a start stamp retain separate output and records. Session writers temporarily retain `commands/pickup/41--implement.jsonl` until the Session-ownership Ticket; readers accept both tokenless and token-bearing Session names. Existing legacy Command logs and records remain readable. +- The repository in the path is the GitHub repository, `/`, not the name of the local checkout, so log file names drop it: `commands/pickup/41-~.log`. Command logs are exclusively allocated with an immutable random owner token, so Commands sharing a start stamp retain separate output and records. Session logs share the captured stamp and token, as `commands/pickup/41-~-implement.jsonl`, including across child Runs. Model sidecars and review reports use that Session's owned stem. Start stamps remain display and grouping facts. Existing legacy Command logs, Session logs and records remain readable without migration. - Whether the scheduler is still firing is no longer a line per pass: an idle repository's Activity log ends on one skip line. - Logs written before this, under `/sessions/` and `/commands/`, are not moved by thirdshift. diff --git a/docs/code-navigation.md b/docs/code-navigation.md index 28dd7cec..6d67d35d 100644 --- a/docs/code-navigation.md +++ b/docs/code-navigation.md @@ -18,7 +18,7 @@ Start with the issue's terms in `CONTEXT.md`, then use this index to find their | Session prompt, Factory skills | `src/prompt.rs`; `src/skills.rs`; `skills/` | `src/skills/tests.rs`, `tests/packaging.rs` | | Session log, Resume | `src/session.rs` and `src/session/` | `src/session/execution_tests.rs`, `tests/background_work.rs` | | Command log, Activity log | `src/logs.rs`; `src/logs/recording.rs` — `Record` | `src/logs/recording/tests.rs`, `tests/command_logs.rs`, `tests/activity_log.rs` | -| Command-log allocation, artifact ownership and filename decoding | `src/logs/owner.rs` — `allocate`, `Owner`, `decode`, `session_matches` | `src/logs/owner/tests.rs`, `src/logs/recording/tests.rs`, `tests/status.rs`, `tests/show_logs.rs` | +| Command-log allocation, Session naming, child inheritance and filename decoding | `src/logs/owner.rs` — `allocate`, `Owner`, `decode`, `session_matches`; `src/session/recording.rs` — captured Model recording | `src/logs/owner/tests.rs`, `src/logs/recording/tests.rs`, `src/session/recording/tests.rs`, `tests/command_logs.rs`, `tests/status.rs`, `tests/show_logs.rs` | | Command record, status | `src/logs/recording.rs`; `src/logs/command_record.rs`; `src/logs/status.rs` and `src/logs/status/history.rs`; `src/logs/process_identity.rs` | `tests/status.rs`, `src/logs/recording/tests.rs` | | Command naming, show, logs | `src/logs/status/inspect.rs` — Command resolution, detailed state, Session selection and log following | `tests/show_logs.rs` | | Stop | `src/logs/stop.rs` — request, signaling and waiting; `src/claim.rs` — Stop endings | `tests/stop.rs`; inline Claim and Stop tests | diff --git a/docs/guide.md b/docs/guide.md index e4600a40..9f59b82e 100644 --- a/docs/guide.md +++ b/docs/guide.md @@ -75,7 +75,7 @@ The designed behaviour described in this manual is implemented. Known gaps and p `thirdshift status` names this host and lists live Commands across every repository in `logs.dir`, with their issue and title when present, Harness, Model, Effort, current stage and its age. Architect runs, Pickup runs and Security runs nest the Runs or Spec runs they dispatch beneath themselves, each Spec's Tickets and their Runs, and each Run's Base fix. Every Ticket is listed: running, merged into the Spec branch, failed, waiting on named blockers, or not started. A Pass with no issue is named by its kind and Command log stamp, such as `architect-20261018T120000-0400` or `secure-20261018T120000-0400`. After the live Commands it lists those that ended in the last 24 hours, with their outcomes. `thirdshift status --all` lists every Command this machine has logs for, newest start first. A Command or child Run with no outcome whose process has gone shows as `died at ` in either view. Process start identifiers distinguish a reused process id on Linux and macOS. Records remain beside their Command logs, as `*.command.json`, with child records named for their issue as `*.issue-.child.json`. Each process writes only its own files, replacing them atomically. A record write failure warns once per recording process and does not change its outcome. -History uses each source only for Commands missing from the preceding sources: Command records, then Activity log start/end lines with their Command logs, then Session logs in the current `///commands//` layout. Activity entries have start and end times and outcomes, with no stages. Session entries group logs by issue and Command stamp; they have no known end or outcome and appear only with `--all`. Sessions covered by a Spec run or Pass's stamp belong to that Command. The flat layout from before [ADR 0011](adr/0011-thirdshift-keeps-a-per-repository-activity-log.md) is ignored. +History uses each source only for Commands missing from the preceding sources: Command records, then Activity log start/end lines with their Command logs, then Session logs in the current `///commands//` layout. Activity entries have start and end times and outcomes, with no stages. Session entries group logs by issue and exact Command owner; they have no known end or outcome and appear only with `--all`. A Spec run or Pass's Sessions share that Command's stamp and owner token. Legacy tokenless logs retain their existing grouping. The flat layout from before [ADR 0011](adr/0011-thirdshift-keeps-a-per-repository-activity-log.md) is ignored. For each repository and kind of Pass whose latest Activity log line is a skip, status also shows that Pass as idle with its reason, even when the skip is older than another kind's activity. A later start or end for that kind clears its idle entry. For example: @@ -103,14 +103,14 @@ Architect run idle on acme/widgets: Ready issue #7 "Make widgets" goes first: ht "effort": "high", "started_at": "2026-10-18T12:00:00-04:00", "ended_at": null, - "stages": [{"name": "implement", "began_at": "2026-10-18T12:00:01-04:00", "session_log": "/logs/acme/widgets/commands/issue/7-stamp-implement.jsonl"}], - "session_log": "/logs/acme/widgets/commands/issue/7-stamp-implement.jsonl", + "stages": [{"name": "implement", "began_at": "2026-10-18T12:00:01-04:00", "session_log": "/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA-implement.jsonl"}], + "session_log": "/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA-implement.jsonl", "issue_branch": "issue-7", "pull_request": null, "outcome": null, "cause": null, "source": "command_record", - "command_log": "/logs/acme/widgets/commands/issue/7-stamp.log", + "command_log": "/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA.log", "dispatched": [], "state": "live", "stage": {"name": "implement", "began_at": "2026-10-18T12:00:01-04:00", "age_seconds": 52}, @@ -186,17 +186,17 @@ thirdshift logs 'widgets#7' --session repair --follow "name": "acme/widgets#7", "state": "live", "latest_event": "Bash: cargo test", - "stages": [{"name": "implement", "began_at": "2026-10-18T12:00:01-04:00", "session_log": "/logs/acme/widgets/commands/issue/7-stamp-implement.jsonl"}], - "command_log": "/logs/acme/widgets/commands/issue/7-stamp.log", - "session_log": "/logs/acme/widgets/commands/issue/7-stamp-implement.jsonl", - "session_logs": ["/logs/acme/widgets/commands/issue/7-stamp-implement.jsonl"], + "stages": [{"name": "implement", "began_at": "2026-10-18T12:00:01-04:00", "session_log": "/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA-implement.jsonl"}], + "command_log": "/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA.log", + "session_log": "/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA-implement.jsonl", + "session_logs": ["/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA-implement.jsonl"], "children": [], "dispatched": [] } } ``` -The Command excerpt omits the common fields documented for `status --json`; all those fields are retained, including process identity, issue, Harness, Model, Effort and nullable outcome. `children` and `dispatched` retain the same recursive shape. `session_logs` lists the selected Run's Session log paths, including original sessions and Resumes that share a stage. `latest_event` is optional, present only when a live Run has a readable event, including in child Runs. History without a Command record uses the same Activity-log or Session-log shape as `status --all --json`, with Session logs discovered by issue/kind and Command stamp, without invented stages or liveness. +The Command excerpt omits the common fields documented for `status --json`; all those fields are retained, including process identity, issue, Harness, Model, Effort and nullable outcome. `children` and `dispatched` retain the same recursive shape. `session_logs` lists the selected Run's Session log paths, including original sessions and Resumes that share a stage. `latest_event` is optional, present only when a live Run has a readable event, including in child Runs. History without a Command record uses the same Activity-log or Session-log shape as `status --all --json`, with Session logs discovered by issue/kind and exact Command owner, without invented stages or liveness. `logs` writes the Command log verbatim. `--session ` writes that kind's latest Session log as raw JSON lines; `implement` and `spec-review` include a later Resume, and `repair` selects the latest numbered Repair. A missing log or session kind gives an error. `--follow` first prints the selected log, then flushes appended bytes until the owning Command ends or dies, including its final output. A Ticket shares its Command's Command log but selects its own Session logs. The selected Command and Session log stay fixed while following. @@ -633,12 +633,12 @@ Everything thirdshift logs goes under `~/.thirdshift/logs/`, or the `logs.dir` s The folder already names the repository, so no file name repeats it. `audits/` and `security-reviews/` hold vulnerability evidence, so keep the logs private (see [Security runs](#security-runs)). A **Session log** is one session's full transcript, as the Harness's JSON output, such as Claude Code's `stream-json`: ``` -~/.thirdshift/logs///commands/issue/--implement.jsonl -~/.thirdshift/logs///commands/issue/--repair-.jsonl -~/.thirdshift/logs///commands/architect/architect--architecture-review.jsonl +~/.thirdshift/logs///commands/issue/-~-implement.jsonl +~/.thirdshift/logs///commands/issue/-~-repair-.jsonl +~/.thirdshift/logs///commands/architect/architect-~-architecture-review.jsonl ``` -Session logs share the owning command's folder: a Pickup run's dispatched Run logs in `commands/pickup/`, an Architect run's in `commands/architect/`, and a Security run's in `commands/secure/`. Tickets and Base fixes inherit that folder too. +Session logs share the owning command's folder, stamp and owner token: a Pickup run's dispatched Run logs in `commands/pickup/`, an Architect run's in `commands/architect/`, and a Security run's in `commands/secure/`. Tickets and nested Base fixes inherit that same ownership too. A Resume is logged as its session's kind plus `-resume`, e.g. `implement-resume.jsonl`. @@ -646,7 +646,7 @@ A **Command log** is everything one command printed, stderr and stdout in the or The stamp is the local time the command started, with its UTC offset, as in `20261003T120000-0400`, in the machine's time zone, or `TZ`'s if set, so it agrees with `date` and `ls -l`. A command's Command log and all of its Session logs, its Tickets' Runs' and its Base fix's included, share that one stamp, so they sort together and each can be found from the other. When a Run fails, stderr ends with the path of its most recent Session log, the place to start looking, then that of its Command log. -New Command logs insert `~` immediately after the stamp. The random token gives each Command its own storage even when start times agree; its Command record uses that exact stem followed by `.command.json`. Human Command names stay the same. Session writers still use the tokenless examples above during this transition; readers also accept Session names with `~`. A matching stamp alone does not attach a tokenless Session to a new Command: a record reference or exact Model evidence must establish that ownership. Legacy logs and records remain readable without renaming. +New Command and Session logs insert `~` immediately after the stamp. The random token gives each Command its own storage even when start times agree; its Command record uses the exact Command-log stem followed by `.command.json`. Model sidecars (`.models.json`) and review reports (`.standards` and `.spec`) use the exact Session-log stem. Human Command names stay the same, and start stamps remain display and grouping facts. A matching stamp alone does not attach a tokenless Session to a new Command: a record reference or exact Model evidence must establish that ownership. Legacy logs and records remain readable without renaming. A failed Command-log writer retains its allocated owner; if allocation itself failed, a Session fails with that cause instead of choosing a shared timestamp-only filename. The **Activity log**, `activity.log`, is a short running record of what the factory did on the repository ([ADR-0011](adr/0011-thirdshift-keeps-a-per-repository-activity-log.md)). A Run, a Spec run or a Pass writes a line when it starts work, naming its Command log, and one when it ends, with its outcome; a Run you type by hand writes them too, and the run a Pass dispatched, a Spec run's Tickets and a Base fix write none of their own. A skipped Pass writes a line only when its reason differs from the last line of its own kind, so a repository that sits idle shows one line, not one per pass, and the first skip after a pass that did work always shows: that is when the repository went idle. Every line starts with the local date and time: @@ -977,7 +977,7 @@ A Security run checks its gates in order: another **Pass** on the repository run The Security audit runs in a throwaway worktree detached at origin's Base branch head, leaving the Launch directory and local work untouched, including when `launch.pull` is set. Its Session prompt runs `thirdshift-security-audit` in full audit mode with the `quick` profile, auditing the whole repository except vendored and third-party code. It names a `SECURITY.md` or conventional threat-model document when present, reads compatible earlier runs and ends `incomplete` instead of asking for input. -Each audit keeps a new output directory under `///audits/`, outside the worktree. The audit artifacts and private advisory descriptions contain evidence; keep the logs directory private. thirdshift runs both embedded validators before recording anything. A missing final line, an incomplete session or an invalid report fails the run and names its Session log. Command logs and Session logs are in `commands/secure/`; Session logs are named `secure--security-audit.jsonl`; the Activity log records the start and ending as for other Passes. +Each audit keeps a new output directory under `///audits/`, outside the worktree. The audit artifacts and private advisory descriptions contain evidence; keep the logs directory private. thirdshift runs both embedded validators before recording anything. A missing final line, an incomplete session or an invalid report fails the run and names its Session log. Command logs and Session logs are in `commands/secure/`; Session logs are named `secure-~-security-audit.jsonl`; the Activity log records the start and ending as for other Passes. A finding's title becomes the advisory summary. Its description preserves its write-up, trace, evidence and validation plan, with the fingerprint and audited commit. thirdshift claims no severity, CWE or affected version range. It uses the package in the repository's manifest, or the `other` ecosystem when none is identified. Matching fingerprints in any advisory state are kept rather than recorded again. Rejected candidates stay in the local report and produce no advisory. Draft advisories require GitHub repository security manager or administrator access. On a private repository whose advisory endpoint is unavailable, the private record is an issue labelled `security-finding` and `needs-triage`. It is never replaced by a public finding issue. diff --git a/site/docs/index.html b/site/docs/index.html index 449a9e58..8d94df6c 100644 --- a/site/docs/index.html +++ b/site/docs/index.html @@ -104,7 +104,7 @@

Status

The designed behaviour described in this manual is implemented. Known gaps and planned work are tracked in the open issues.

Machine status

thirdshift status names this host and lists live Commands across every repository in logs.dir, with their issue and title when present, Harness, Model, Effort, current stage and its age. Architect runs, Pickup runs and Security runs nest the Runs or Spec runs they dispatch beneath themselves, each Spec's Tickets and their Runs, and each Run's Base fix. Every Ticket is listed: running, merged into the Spec branch, failed, waiting on named blockers, or not started. A Pass with no issue is named by its kind and Command log stamp, such as architect-20261018T120000-0400 or secure-20261018T120000-0400. After the live Commands it lists those that ended in the last 24 hours, with their outcomes. thirdshift status --all lists every Command this machine has logs for, newest start first. A Command or child Run with no outcome whose process has gone shows as died at <stage> in either view. Process start identifiers distinguish a reused process id on Linux and macOS. Records remain beside their Command logs, as *.command.json, with child records named for their issue as *.issue-<n>.child.json. Each process writes only its own files, replacing them atomically. A record write failure warns once per recording process and does not change its outcome.

-

History uses each source only for Commands missing from the preceding sources: Command records, then Activity log start/end lines with their Command logs, then Session logs in the current <logs.dir>/<owner>/<repo>/commands/<kind>/ layout. Activity entries have start and end times and outcomes, with no stages. Session entries group logs by issue and Command stamp; they have no known end or outcome and appear only with --all. Sessions covered by a Spec run or Pass's stamp belong to that Command. The flat layout from before ADR 0011 is ignored.

+

History uses each source only for Commands missing from the preceding sources: Command records, then Activity log start/end lines with their Command logs, then Session logs in the current <logs.dir>/<owner>/<repo>/commands/<kind>/ layout. Activity entries have start and end times and outcomes, with no stages. Session entries group logs by issue and exact Command owner; they have no known end or outcome and appear only with --all. A Spec run or Pass's Sessions share that Command's stamp and owner token. Legacy tokenless logs retain their existing grouping. The flat layout from before ADR 0011 is ignored.

For each repository and kind of Pass whose latest Activity log line is a skip, status also shows that Pass as idle with its reason, even when the skip is older than another kind's activity. A later start or end for that kind clears its idle entry. For example:

Architect run idle on acme/widgets: Ready issue #7 "Make widgets" goes first: https://github.com/acme/widgets/issues/7
 
@@ -126,14 +126,14 @@

Machine status

"effort": "high", "started_at": "2026-10-18T12:00:00-04:00", "ended_at": null, - "stages": [{"name": "implement", "began_at": "2026-10-18T12:00:01-04:00", "session_log": "/logs/acme/widgets/commands/issue/7-stamp-implement.jsonl"}], - "session_log": "/logs/acme/widgets/commands/issue/7-stamp-implement.jsonl", + "stages": [{"name": "implement", "began_at": "2026-10-18T12:00:01-04:00", "session_log": "/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA-implement.jsonl"}], + "session_log": "/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA-implement.jsonl", "issue_branch": "issue-7", "pull_request": null, "outcome": null, "cause": null, "source": "command_record", - "command_log": "/logs/acme/widgets/commands/issue/7-stamp.log", + "command_log": "/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA.log", "dispatched": [], "state": "live", "stage": {"name": "implement", "began_at": "2026-10-18T12:00:01-04:00", "age_seconds": 52}, @@ -195,16 +195,16 @@

Show and read one Command

"name": "acme/widgets#7", "state": "live", "latest_event": "Bash: cargo test", - "stages": [{"name": "implement", "began_at": "2026-10-18T12:00:01-04:00", "session_log": "/logs/acme/widgets/commands/issue/7-stamp-implement.jsonl"}], - "command_log": "/logs/acme/widgets/commands/issue/7-stamp.log", - "session_log": "/logs/acme/widgets/commands/issue/7-stamp-implement.jsonl", - "session_logs": ["/logs/acme/widgets/commands/issue/7-stamp-implement.jsonl"], + "stages": [{"name": "implement", "began_at": "2026-10-18T12:00:01-04:00", "session_log": "/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA-implement.jsonl"}], + "command_log": "/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA.log", + "session_log": "/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA-implement.jsonl", + "session_logs": ["/logs/acme/widgets/commands/issue/7-20261018T120000-0400~ownerA-implement.jsonl"], "children": [], "dispatched": [] } } -

The Command excerpt omits the common fields documented for status --json; all those fields are retained, including process identity, issue, Harness, Model, Effort and nullable outcome. children and dispatched retain the same recursive shape. session_logs lists the selected Run's Session log paths, including original sessions and Resumes that share a stage. latest_event is optional, present only when a live Run has a readable event, including in child Runs. History without a Command record uses the same Activity-log or Session-log shape as status --all --json, with Session logs discovered by issue/kind and Command stamp, without invented stages or liveness.

+

The Command excerpt omits the common fields documented for status --json; all those fields are retained, including process identity, issue, Harness, Model, Effort and nullable outcome. children and dispatched retain the same recursive shape. session_logs lists the selected Run's Session log paths, including original sessions and Resumes that share a stage. latest_event is optional, present only when a live Run has a readable event, including in child Runs. History without a Command record uses the same Activity-log or Session-log shape as status --all --json, with Session logs discovered by issue/kind and exact Command owner, without invented stages or liveness.

logs writes the Command log verbatim. --session <kind> writes that kind's latest Session log as raw JSON lines; implement and spec-review include a later Resume, and repair selects the latest numbered Repair. A missing log or session kind gives an error. --follow first prints the selected log, then flushes appended bytes until the owning Command ends or dies, including its final output. A Ticket shares its Command's Command log but selects its own Session logs. The selected Command and Session log stay fixed while following.

Install

curl -LsSf https://github.com/JacobStephens2/thirdshift/releases/latest/download/thirdshift-installer.sh | sh
@@ -528,15 +528,15 @@ 

Logs

└── issue/ <n>-<stamp>~<token>.log and Session logs

The folder already names the repository, so no file name repeats it. audits/ and security-reviews/ hold vulnerability evidence, so keep the logs private (see Security runs). A Session log is one session's full transcript, as the Harness's JSON output, such as Claude Code's stream-json:

-
~/.thirdshift/logs/<owner>/<repo>/commands/issue/<n>-<stamp>-implement.jsonl
-~/.thirdshift/logs/<owner>/<repo>/commands/issue/<n>-<stamp>-repair-<i>.jsonl
-~/.thirdshift/logs/<owner>/<repo>/commands/architect/architect-<stamp>-architecture-review.jsonl
+
~/.thirdshift/logs/<owner>/<repo>/commands/issue/<n>-<stamp>~<token>-implement.jsonl
+~/.thirdshift/logs/<owner>/<repo>/commands/issue/<n>-<stamp>~<token>-repair-<i>.jsonl
+~/.thirdshift/logs/<owner>/<repo>/commands/architect/architect-<stamp>~<token>-architecture-review.jsonl
 
-

Session logs share the owning command's folder: a Pickup run's dispatched Run logs in commands/pickup/, an Architect run's in commands/architect/, and a Security run's in commands/secure/. Tickets and Base fixes inherit that folder too.

+

Session logs share the owning command's folder, stamp and owner token: a Pickup run's dispatched Run logs in commands/pickup/, an Architect run's in commands/architect/, and a Security run's in commands/secure/. Tickets and nested Base fixes inherit that same ownership too.

A Resume is logged as its session's kind plus -resume, e.g. implement-resume.jsonl.

A Command log is everything one command printed, stderr and stdout in the order printed, while the terminal still shows all of it. Its folder is the command typed: thirdshift <Issue URL>, a Run or a Spec run, in issue/, thirdshift pickup in pickup/, named for the issue it took, and thirdshift architect in architect/. A Spec run's covers its Tickets' Runs, a Run's covers its Base fix, and a Pass's covers the Spec run or Run it dispatched: none of those keeps one of its own. So ls -t ~/.thirdshift/logs/acme/widgets/commands/pickup/*.log | head lists the recent passes on acme/widgets that took an issue. A command keeps its Command log once it starts work: a Pass skipped before doing any work keeps none, nor does a Run that fails before it starts work, as on the Origin match, and setup, email-test, update, version and help never keep one. Lines printed before the Command log's name is known, such as a Pickup run's lines on the issues it passed over before it took one, are written first, and once it is created a progress line says logging this command to <path>. A Command log that can't be written produces one warning: line on stderr. A failure confined to the Command log leaves the outcome, stdout and exit code unchanged; if the shared folder also prevents writing a Session log, the Run fails before starting that session.

The stamp is the local time the command started, with its UTC offset, as in 20261003T120000-0400, in the machine's time zone, or TZ's if set, so it agrees with date and ls -l. A command's Command log and all of its Session logs, its Tickets' Runs' and its Base fix's included, share that one stamp, so they sort together and each can be found from the other. When a Run fails, stderr ends with the path of its most recent Session log, the place to start looking, then that of its Command log.

-

New Command logs insert ~<token> immediately after the stamp. The random token gives each Command its own storage even when start times agree; its Command record uses that exact stem followed by .command.json. Human Command names stay the same. Session writers still use the tokenless examples above during this transition; readers also accept Session names with ~<token>. A matching stamp alone does not attach a tokenless Session to a new Command: a record reference or exact Model evidence must establish that ownership. Legacy logs and records remain readable without renaming.

+

New Command and Session logs insert ~<token> immediately after the stamp. The random token gives each Command its own storage even when start times agree; its Command record uses the exact Command-log stem followed by .command.json. Model sidecars (.models.json) and review reports (.standards and .spec) use the exact Session-log stem. Human Command names stay the same, and start stamps remain display and grouping facts. A matching stamp alone does not attach a tokenless Session to a new Command: a record reference or exact Model evidence must establish that ownership. Legacy logs and records remain readable without renaming. A failed Command-log writer retains its allocated owner; if allocation itself failed, a Session fails with that cause instead of choosing a shared timestamp-only filename.

The Activity log, activity.log, is a short running record of what the factory did on the repository (ADR-0011). A Run, a Spec run or a Pass writes a line when it starts work, naming its Command log, and one when it ends, with its outcome; a Run you type by hand writes them too, and the run a Pass dispatched, a Spec run's Tickets and a Base fix write none of their own. A skipped Pass writes a line only when its reason differs from the last line of its own kind, so a repository that sits idle shows one line, not one per pass, and the first skip after a pass that did work always shows: that is when the repository went idle. Every line starts with the local date and time:

2026-10-03 02:00:01 Pickup run skipped: no Ready issue on acme/widgets
 2026-10-03 09:30:01 Pickup run #41 started: commands/pickup/41-20261003T093001-0400~aB3cD4eF5gH6iJ7k.log
@@ -758,7 +758,7 @@ 

Security runs

Codex security sessions and their Resumes set agents.max_concurrent_threads_per_session=8 and ask for fresh sub-agents with fork_turns: "none", so the skill's verifiers stay independent.

A Security run checks its gates in order: another Pass on the repository running on the machine, a Ready issue, a failed Security fix whose issue is still open, a Security finding waiting for the Day shift, then an unchanged Base branch since the last completed Security audit. An unreproduced draft advisory with no severity waits; closing it, publishing it or assigning severity ends that wait. A reproduced finding waits while fixing is disabled until its record is closed or published, or its fix Ticket is closed. On a private repository, an open finding issue with needs-triage waits until that label is removed or the issue is closed. The audited commit comes from the skill's own run-metadata.json under the audit root, with no separate state file. A skip exits 0, starts no session, keeps no Command log and sends no Run notification; its reason goes into the repository's Activity log only when it changes, with the usual activity.quiet_skips behavior. Before starting work, thirdshift checks the chosen Harness and that Node.js is on PATH, since the embedded skill's report validators require it.

The Security audit runs in a throwaway worktree detached at origin's Base branch head, leaving the Launch directory and local work untouched, including when launch.pull is set. Its Session prompt runs thirdshift-security-audit in full audit mode with the quick profile, auditing the whole repository except vendored and third-party code. It names a SECURITY.md or conventional threat-model document when present, reads compatible earlier runs and ends incomplete instead of asking for input.

-

Each audit keeps a new output directory under <logs.dir>/<owner>/<repo>/audits/, outside the worktree. The audit artifacts and private advisory descriptions contain evidence; keep the logs directory private. thirdshift runs both embedded validators before recording anything. A missing final line, an incomplete session or an invalid report fails the run and names its Session log. Command logs and Session logs are in commands/secure/; Session logs are named secure-<stamp>-security-audit.jsonl; the Activity log records the start and ending as for other Passes.

+

Each audit keeps a new output directory under <logs.dir>/<owner>/<repo>/audits/, outside the worktree. The audit artifacts and private advisory descriptions contain evidence; keep the logs directory private. thirdshift runs both embedded validators before recording anything. A missing final line, an incomplete session or an invalid report fails the run and names its Session log. Command logs and Session logs are in commands/secure/; Session logs are named secure-<stamp>~<token>-security-audit.jsonl; the Activity log records the start and ending as for other Passes.

A finding's title becomes the advisory summary. Its description preserves its write-up, trace, evidence and validation plan, with the fingerprint and audited commit. thirdshift claims no severity, CWE or affected version range. It uses the package in the repository's manifest, or the other ecosystem when none is identified. Matching fingerprints in any advisory state are kept rather than recorded again. Rejected candidates stay in the local report and produce no advisory. Draft advisories require GitHub repository security manager or administrator access. On a private repository whose advisory endpoint is unavailable, the private record is an issue labelled security-finding and needs-triage. It is never replaced by a public finding issue.

Security review

security-review, or review = true under [security], enables one guidance review after a Run's opening session or a Spec run's Spec review, before Delivery pushes and enters the Repair loop. A Spec run reviews the whole Spec branch against its Base branch once; its Tickets' Runs get none. no-security-review overrides the setting. Both words, with or without dashes, are accepted on commands that start Runs and follow dispatched Runs and Base fixes. Setup asks about the setting; it is off by default.

diff --git a/src/logs.rs b/src/logs.rs index 30f2d54d..11d31682 100644 --- a/src/logs.rs +++ b/src/logs.rs @@ -14,7 +14,7 @@ mod activity; mod command_record; mod effects; -mod owner; +pub(crate) mod owner; mod process_identity; mod recording; pub mod status; @@ -130,6 +130,7 @@ const PARENT_DISPATCH: &str = "THIRDSHIFT_PARENT_DISPATCH"; pub fn begin(begin: Begin) { let mut record = record(); if matches!(begin, Begin::ChildRun(..)) { + record.inherit_owner(owner::Owner::inherited()); record.child_of(std::env::var_os(PARENT_RECORD).map(PathBuf::from)); record.child_dispatch(std::env::var(PARENT_DISPATCH).ok()); } @@ -299,6 +300,10 @@ pub fn command_log_path() -> Option { record().command_log_path() } +pub(crate) fn captured_owner() -> Result { + record().captured_owner() +} + /// Print `line` on stderr, and keep it in the Command log. pub fn eprint(line: &str) { record().eprint(line); diff --git a/src/logs/owner.rs b/src/logs/owner.rs index 74173562..d4d070cf 100644 --- a/src/logs/owner.rs +++ b/src/logs/owner.rs @@ -5,9 +5,9 @@ use std::fs::{self, File, OpenOptions}; use std::io::{self, Write}; use std::path::{Path, PathBuf}; -use anyhow::Result; +use anyhow::{Context, Result, ensure}; use chrono::{DateTime, FixedOffset}; -use serde::Deserialize; +use serde::{Deserialize, Serialize}; use super::{CommandKind, Work}; @@ -18,17 +18,114 @@ pub(super) trait Files { fn create_command_log(&mut self, path: &Path) -> io::Result; } -pub(super) struct Owner { - path: PathBuf, +const INHERITED_OWNER: &str = "THIRDSHIFT_LOG_OWNER"; + +#[derive(Clone, Debug, Serialize, Deserialize)] +pub(crate) struct Owner { + stamp: String, + token: Option, + command_log: Option, } impl Owner { - pub fn log_path(&self) -> &Path { - &self.path + pub fn log_path(&self) -> Option<&Path> { + self.command_log.as_deref() + } + + pub fn record_path(&self) -> Option { + self.command_log + .as_ref() + .map(|path| path.with_extension("command.json")) + } + + pub fn session_path(&self, dir: &Path, subject: &str, kind: &str) -> PathBuf { + let token = self + .token + .as_ref() + .map(|token| format!("~{token}")) + .unwrap_or_default(); + dir.join(format!("{subject}-{}{token}-{kind}.jsonl", self.stamp)) } - pub fn record_path(&self) -> PathBuf { - self.path.with_extension("command.json") + pub fn models_match(&self, path: &Path) -> bool { + let Some(stem) = path + .file_name() + .and_then(|name| name.to_str()) + .and_then(|name| name.strip_suffix(".models.json")) + else { + return false; + }; + let session = path.with_file_name(format!("{stem}.jsonl")); + decode(&session).is_some_and(|decoded| { + decoded.session_kind.is_some() + && decoded.identity + == Identity { + stamp: &self.stamp, + token: self.token.as_deref(), + } + }) + } + + /// Only actual child Runs call this. Top-level Commands allocate locally. + pub fn inherited() -> Result { + let value = + std::env::var(INHERITED_OWNER).context("missing inherited Command log owner")?; + let owner: Self = + serde_json::from_str(&value).context("invalid inherited Command log owner")?; + ensure!( + parse_stamp(&owner.stamp).is_some(), + "invalid inherited Command start stamp" + ); + ensure!( + owner + .token + .as_deref() + .is_some_and(|token| !token.is_empty() + && token.bytes().all(|byte| byte.is_ascii_alphanumeric())), + "invalid inherited Command owner token" + ); + if let Some(log) = owner.log_path() { + let decoded = decode(log).context("invalid inherited Command log path")?; + ensure!( + decoded.session_kind.is_none() + && decoded.identity + == Identity { + stamp: &owner.stamp, + token: owner.token.as_deref() + }, + "inherited Command log disagrees with its owner" + ); + } + Ok(owner) + } + + /// Missing ownership explicitly clears stale state on a reused Command. + pub fn inherit(owner: Option<&Self>, command: &mut std::process::Command) { + match owner { + Some(owner) => { + command.env( + INHERITED_OWNER, + serde_json::to_string(owner).expect("owner metadata is serializable"), + ); + } + None => { + command.env_remove(INHERITED_OWNER); + } + } + } + + #[cfg(test)] + pub fn fixture(log: Option, stamp: String) -> Self { + let token = log + .as_deref() + .and_then(decode) + .and_then(|decoded| decoded.identity.token) + .map(str::to_owned); + Self { + stamp, + token, + command_log: log, + } } } @@ -62,9 +159,12 @@ pub(super) fn allocate( .disable_cleanup(true) .make_in(folder, |path| files.create_command_log(path))?; let (writer, path) = allocated.into_parts(); + let decoded = decode(&path).context("allocated Command log has an invalid name")?; Ok(Allocation { owner: Owner { - path: path.to_path_buf(), + stamp: stamp.to_string(), + token: decoded.identity.token.map(str::to_owned), + command_log: Some(path.to_path_buf()), }, writer, }) diff --git a/src/logs/owner/tests.rs b/src/logs/owner/tests.rs index 2093a0b8..c02aa2e6 100644 --- a/src/logs/owner/tests.rs +++ b/src/logs/owner/tests.rs @@ -10,7 +10,7 @@ fn real_files_keep_interleaved_command_output_and_records_separate() { let issue = IssueUrl::parse("https://github.com/acme/widgets/issues/7").unwrap(); let mut files = OnMachine; let first = allocate(&mut files, root.path(), Work::Run(&issue), STAMP).unwrap(); - let first_path = first.owner.log_path().to_path_buf(); + let first_path = first.owner.log_path().unwrap().to_path_buf(); let mut first_writer = first.writer; first_writer.write_all(b"first before\n").unwrap(); let second = allocate(&mut files, root.path(), Work::Run(&issue), STAMP).unwrap(); @@ -18,19 +18,25 @@ fn real_files_keep_interleaved_command_output_and_records_separate() { second_writer.write_all(b"second before\n").unwrap(); first_writer.write_all(b"first after\n").unwrap(); second_writer.write_all(b"second after\n").unwrap(); - assert_ne!(first_path, second.owner.log_path()); - assert_ne!(first.owner.record_path(), second.owner.record_path()); + assert_ne!(first_path, second.owner.log_path().unwrap()); + assert_ne!( + first.owner.record_path().unwrap(), + second.owner.record_path().unwrap() + ); assert_eq!( fs::read(first_path).unwrap(), b"first before\nfirst after\n" ); assert_eq!( - fs::read(second.owner.log_path()).unwrap(), + fs::read(second.owner.log_path().unwrap()).unwrap(), b"second before\nsecond after\n" ); for owner in [&first.owner, &second.owner] { - assert_eq!(record_log(&owner.record_path()), owner.log_path()); - let decoded = decode(owner.log_path()).unwrap(); + assert_eq!( + record_log(&owner.record_path().unwrap()), + owner.log_path().unwrap() + ); + let decoded = decode(owner.log_path().unwrap()).unwrap(); assert_eq!(decoded.identity.stamp, STAMP); assert!(decoded.identity.token.is_some()); assert_eq!(decoded.subject, "7"); @@ -59,10 +65,10 @@ fn a_forced_collision_preserves_the_existing_file_and_retries_with_a_fresh_token let mut allocated = allocate(&mut files, root.path(), Work::Run(&issue), STAMP).unwrap(); allocated.writer.write_all(b"new output\n").unwrap(); let occupied = files.occupied.unwrap(); - assert_ne!(occupied, allocated.owner.log_path()); + assert_ne!(occupied, allocated.owner.log_path().unwrap()); assert_eq!(fs::read(occupied).unwrap(), b"another Command's output\n"); assert_eq!( - fs::read(allocated.owner.log_path()).unwrap(), + fs::read(allocated.owner.log_path().unwrap()).unwrap(), b"new output\n" ); } diff --git a/src/logs/recording.rs b/src/logs/recording.rs index 3b2a29f9..e10e1cdb 100644 --- a/src/logs/recording.rs +++ b/src/logs/recording.rs @@ -24,6 +24,7 @@ pub(super) struct Record { outside: O, stamp: Option, owner: Option, + owner_error: Option, logs_dir: Option, child: bool, command: CommandKind, @@ -73,6 +74,7 @@ impl Record { outside, stamp: None, owner: None, + owner_error: None, logs_dir: None, child: false, command: CommandKind::Issue, @@ -226,7 +228,10 @@ impl Record { let Some(owner) = &self.owner else { return; }; - owner.record_path() + let Some(path) = owner.record_path() else { + return; + }; + path }; self.command_record = Some(( path, @@ -392,6 +397,23 @@ impl Record { } } + pub(super) fn inherit_owner(&mut self, inherited: Result) { + if self.owner.is_none() { + match inherited { + Ok(owner) => self.owner = Some(owner), + Err(error) => self.owner_error = Some(format!("{error:#}")), + } + } + } + + pub(super) fn captured_owner(&self) -> Result { + self.owner.clone().ok_or_else(|| { + self.owner_error + .clone() + .unwrap_or_else(|| "Command logging has not allocated an owner".into()) + }) + } + pub(super) fn print(&mut self, line: &str) { self.output(Stream::Stdout, line.to_string()); } @@ -448,7 +470,7 @@ impl Record { let allocation = owner::allocate(&mut self.outside, root, work, stamp)?; self.owner = Some(allocation.owner); let mut writer = allocation.writer; - let path = self.owner.as_ref().unwrap().log_path(); + let path = self.owner.as_ref().unwrap().log_path().unwrap(); for (_, line) in lines { writeln!(writer, "{line}") .with_context(|| format!("could not write {}", path.display()))?; @@ -458,18 +480,25 @@ impl Record { match created { Ok(writer) => { self.command_log = Log::Kept { - path: self.owner.as_ref().unwrap().log_path().to_path_buf(), + path: self + .owner + .as_ref() + .unwrap() + .log_path() + .unwrap() + .to_path_buf(), writer, }; let path = self.command_log_path().unwrap(); self.step(format_args!("logging this command to {}", path.display())); } Err(error) => { + self.owner_error = Some(format!("{error:#}")); self.command_log = Log::Failed { path: self .owner .as_ref() - .map(|owner| owner.log_path().to_path_buf()), + .and_then(|owner| owner.log_path().map(Path::to_path_buf)), }; self.step(format_args!( "warning: could not keep the Command log: {error:#}" diff --git a/src/logs/recording/tests.rs b/src/logs/recording/tests.rs index 856954d3..d88a50c3 100644 --- a/src/logs/recording/tests.rs +++ b/src/logs/recording/tests.rs @@ -833,6 +833,12 @@ fn command_creation_failure_warns_once_and_never_adopts_an_existing_path() { record.configured(&config(false)); record.started(Work::Run(&issue()), &harness()); assert_eq!(record.command_log_path(), None); + assert!( + record + .captured_owner() + .unwrap_err() + .contains("Command open failed") + ); // File writes stay disabled even if the underlying problem clears. memory.0.lock().unwrap().command_open_fails = false; record.eprint("carried on"); @@ -921,6 +927,12 @@ fn a_failure_writing_held_lines_retains_the_partial_command_log_path() { record.ended("done"); let path = record.command_log_path().unwrap(); assert_eq!(memory.file(&path), "thi"); + let owner = record.captured_owner().unwrap(); + assert_eq!(owner.log_path(), Some(path.as_path())); + assert_ne!( + owner.session_path(Path::new("/logs"), "7", "implement"), + Path::new("/logs/7-20261003T120000-0400-implement.jsonl") + ); assert_eq!( memory .terminal() diff --git a/src/session.rs b/src/session.rs index 57f452d4..a8cdb66c 100644 --- a/src/session.rs +++ b/src/session.rs @@ -1,6 +1,6 @@ //! Headless agent sessions on the chosen Harness, and their logs. -use std::cell::RefCell; +use std::cell::{OnceCell, RefCell}; #[cfg(test)] use std::fs::{self, File}; #[cfg(test)] @@ -55,6 +55,7 @@ pub struct Logs { /// `architect` for an Architect run. name: String, dir: PathBuf, + recording: OnceCell, } impl Logs { @@ -63,6 +64,7 @@ impl Logs { Logs { name: issue.number.to_string(), dir: logs::session_dir(&issue.repo()), + recording: OnceCell::new(), } } @@ -71,6 +73,7 @@ impl Logs { Logs { name: "architect".to_string(), dir: logs::session_dir(repo), + recording: OnceCell::new(), } } @@ -79,14 +82,20 @@ impl Logs { Logs { name: "secure".to_string(), dir: logs::session_dir(repo), + recording: OnceCell::new(), } } /// Where a session's stream is logged: - /// `/commands//--.jsonl`. - pub fn path(&self, kind: &str) -> PathBuf { - self.dir - .join(format!("{}-{}-{kind}.jsonl", self.name, logs::stamp())) + /// `/commands//-~-.jsonl`. + pub fn path(&self, kind: &str) -> Result { + self.recording().session_path(&self.dir, &self.name, kind) + } + + /// Runs construct Logs before work starts. Capture once the first Session + /// needs it, after the Command has allocated its immutable owner. + fn recording(&self) -> &recording::Recording { + self.recording.get_or_init(recording::Recording::capture) } } @@ -133,6 +142,7 @@ impl<'a> Sessions<'a> { worktree: worktree.to_path_buf(), harness: harness.clone(), adapter, + recording: logs.recording().clone(), }; let (taken, log) = Sessions::taking(logs, worktree, Box::new(on_machine), steps); (taken, log.filter(|log| log.exists())) @@ -256,7 +266,7 @@ impl<'a> Sessions<'a> { prompt: &str, reports: Option<&ReviewReports>, ) -> Result { - let log = self.logs.path(kind); + let log = self.logs.path(kind)?; logs::session(kind, &log); self.step(format!("logging the session to {}", log.display())); *self.last_log.borrow_mut() = Some(log.clone()); @@ -305,6 +315,7 @@ struct OnMachine { worktree: PathBuf, harness: Choice, adapter: &'static dyn Adapter, + recording: recording::Recording, } impl Outside for OnMachine { @@ -361,7 +372,7 @@ impl Outside for OnMachine { } else { None }; - let ended = recording::Recording::capture().run( + let ended = self.recording.run( kind, &self.harness, &mut command, @@ -410,6 +421,7 @@ mod tests { let logs = Logs { name: "670".into(), dir: worktree.path().join("session-logs"), + recording: OnceCell::new(), }; let choice = Choice { harness, @@ -488,6 +500,70 @@ mod tests { Logs { name: "7".to_string(), dir: PathBuf::from("/logs/sessions"), + recording: recording::Recording::new( + Some(PathBuf::from("/logs/7-20261003T120000-0400~fixture.log")), + None, + "20261003T120000-0400".into(), + ) + .into(), + } + } + + #[test] + fn same_second_commands_keep_session_model_and_review_contents_separate() { + let root = crate::test_support::scratch_worktree(); + let stamp = "20261003T120000-0400"; + let mut captured = Vec::new(); + for marker in ["first", "second"] { + let recording = recording::Recording::new( + Some(root.path().join(format!("7-{stamp}~{marker}.log"))), + None, + stamp.into(), + ); + let logs = Logs { + name: "7".into(), + dir: root.path().into(), + recording: recording.clone().into(), + }; + let log = logs.path("implement").unwrap(); + recording.run( + "implement", &Choice::default(), + Command::new("/bin/sh").args(["-c", &format!( + "echo '{{\"type\":\"assistant\",\"message\":{{\"model\":\"{marker}-model\",\"content\":[]}}}}'" + )]), None, &log, + crate::harness::Harness::Claude.adapter().interpretation(root.path(), ""), + ).unwrap(); + let reports = ReviewReports::new(root.path()).unwrap(); + for axis in ["standards", "spec"] { + fs::write( + Path::new(&reports.prompt(prompt::REVIEW_REPORTS_DIRECTORY)) + .join(format!("{axis}.md")), + format!("{marker} {axis}"), + ) + .unwrap(); + } + assert!(reports.keep(&log).is_empty()); + captured.push((marker, log, recording)); + } + for (marker, log, recording) in captured { + assert!( + fs::read_to_string(&log) + .unwrap() + .contains(&format!("{marker}-model")), + "lost {marker} Session" + ); + for axis in ["standards", "spec"] { + assert_eq!( + fs::read_to_string(log.with_extension(axis)).unwrap(), + format!("{marker} {axis}") + ); + } + assert_eq!( + recording.notification_lines(), + [format!( + "- implement: claude · {marker}-model (reported) · session effort: default effort" + )] + ); } } @@ -514,7 +590,7 @@ mod tests { kind: kind.to_string(), resume: resume.map(String::from), prompt: prompt.to_string(), - log: logs().path(kind), + log: logs().path(kind).unwrap(), } } @@ -522,7 +598,7 @@ mod tests { fn logging(kind: &str) -> Call { Call::Step(format!( "logging the session to {}", - logs().path(kind).display() + logs().path(kind).unwrap().display() )) } @@ -549,7 +625,7 @@ mod tests { calls, [logging("implement"), session("implement", None, "do it")] ); - assert_eq!(log, Some(logs().path("implement"))); + assert_eq!(log, Some(logs().path("implement").unwrap())); } #[test] @@ -580,7 +656,7 @@ mod tests { ), ] ); - assert_eq!(log, Some(logs().path("implement-resume"))); + assert_eq!(log, Some(logs().path("implement-resume").unwrap())); } #[test] @@ -637,7 +713,7 @@ mod tests { format!("{:#}", taken.unwrap_err()), format!("implement session {TESTS_KILLED}, and a later step failed: no PR found") ); - assert_eq!(log, Some(logs().path("implement-resume"))); + assert_eq!(log, Some(logs().path("implement-resume").unwrap())); } #[test] @@ -661,7 +737,7 @@ mod tests { ), ] ); - assert_eq!(log, Some(logs().path("implement"))); + assert_eq!(log, Some(logs().path("implement").unwrap())); } #[test] @@ -679,7 +755,7 @@ mod tests { [logging("implement"), session("implement", None, "do it")] ); // The failing session's log is still the last log. - assert_eq!(log, Some(logs().path("implement"))); + assert_eq!(log, Some(logs().path("implement").unwrap())); } #[test] diff --git a/src/session/execution_tests.rs b/src/session/execution_tests.rs index 3745a1ee..a3ab93cb 100644 --- a/src/session/execution_tests.rs +++ b/src/session/execution_tests.rs @@ -109,6 +109,12 @@ fn execute_session(root: &Path) -> anyhow::Error { let logs = Logs { name: "7".into(), dir: root.join("logs"), + recording: recording::Recording::new( + Some(root.join("7-20261003T120000-0400~fixture.log")), + None, + "20261003T120000-0400".into(), + ) + .into(), }; let choice = Choice { harness: Harness::OpenCode, @@ -194,7 +200,7 @@ done echo another-line exec sleep 5"#, ); - let log = fixture.path("logs/7-fixture-implement.jsonl"); + let log = fixture.path("logs/7-20261003T120000-0400~fixture-implement.jsonl"); assert!(Command::new("mkfifo").arg(&log).status().unwrap().success()); let child = fixture .command("session::execution_tests::partial_stdout_is_reported_after_log_failure_with_a_blocked_prompt") @@ -367,6 +373,12 @@ fn with_review_sessions( let logs = Logs { name: "7".into(), dir: root.join("logs"), + recording: recording::Recording::new( + Some(root.join("7-20261003T120000-0400~fixture.log")), + None, + "20261003T120000-0400".into(), + ) + .into(), }; let choice = Choice { harness, @@ -448,7 +460,10 @@ fn a_resumes_review_reports_are_kept_beside_its_own_session_log() { let root = Path::new(&root); let (result, log) = execute_review(root, Harness::Claude); result.unwrap(); - assert_eq!(log.file_name().unwrap(), "7-fixture-implement-resume.jsonl"); + assert_eq!( + log.file_name().unwrap(), + "7-20261003T120000-0400~fixture-implement-resume.jsonl" + ); assert_eq!( fs::read_to_string(log.with_extension("standards")).unwrap(), "Resume Standards report\nFiles read: src/prompt.rs\n" @@ -459,7 +474,10 @@ fn a_resumes_review_reports_are_kept_beside_its_own_session_log() { ); // The first session's reports remain with its own Session log. assert_eq!( - fs::read_to_string(root.join("logs/7-fixture-implement.standards")).unwrap(), + fs::read_to_string( + root.join("logs/7-20261003T120000-0400~fixture-implement.standards") + ) + .unwrap(), "Standards report\nFiles read: src/session.rs\n" ); return; diff --git a/src/session/recording.rs b/src/session/recording.rs index eb153a91..7e0d354b 100644 --- a/src/session/recording.rs +++ b/src/session/recording.rs @@ -13,44 +13,51 @@ use serde::{Deserialize, Serialize}; use crate::harness::interpretation::{Ended, Interpretation}; use crate::harness::{Choice, process}; +use crate::logs::owner::Owner; use crate::{logs, progress}; -const PARENT_COMMAND_LOG: &str = "THIRDSHIFT_PARENT_COMMAND_LOG"; - /// Immutable Command identity, captured after Command logging is established. #[derive(Clone)] pub struct Recording { - command_log: Option, - stamp: String, + owner: std::result::Result, } impl Recording { /// Capture current logging facts once, preferring a local Command log to /// inherited ownership. Child Runs retain their parent's exact path. pub fn capture() -> Self { - Self::new( - logs::command_log_path(), - std::env::var_os(PARENT_COMMAND_LOG).map(PathBuf::from), - logs::stamp(), - ) + Self { + owner: logs::captured_owner(), + } } /// Construct from captured facts; fixtures need no process-global changes. + #[cfg(test)] pub fn new(local: Option, inherited: Option, stamp: String) -> Self { Self { - command_log: local.or(inherited), - stamp, + owner: local + .or(inherited) + .map(|log| Owner::fixture(Some(log), stamp)) + .ok_or_else(|| "no owner in fixture".into()), } } + pub fn session_path(&self, dir: &Path, subject: &str, kind: &str) -> Result { + let owner = self + .owner + .as_ref() + .map_err(|cause| anyhow::anyhow!("cannot name Session log: {cause}"))?; + Ok(owner.session_path(dir, subject, kind)) + } + + fn command_log(&self) -> Option<&Path> { + self.owner.as_ref().ok()?.log_path() + } + /// Give a child this exact owning Command, including through nested Runs. /// Absence removes stale ownership from the child's environment. pub fn inherit_command(&self, command: &mut Command) { - if let Some(log) = &self.command_log { - command.env(PARENT_COMMAND_LOG, log); - } else { - command.env_remove(PARENT_COMMAND_LOG); - } + Owner::inherit(self.owner.as_ref().ok(), command); } /// Collection failures cost attribution, never notification delivery. @@ -127,7 +134,7 @@ impl Recording { /// Record only model metadata; failure costs attribution, never the session. fn keep(&self, kind: &str, log: &Path, choice: &Choice, observed: Vec) { let record = SessionModels { - command_log: self.command_log.clone(), + command_log: self.command_log().map(Path::to_path_buf), kind: kind.to_string(), harness: choice.harness.name().to_string(), requested: choice.model.clone(), @@ -145,23 +152,22 @@ impl Recording { } } - /// Read this command's evidence, including child Runs sharing its start stamp. + /// Read this Command's evidence, including child Runs sharing its owner. /// Other commands in the same repository and folder are excluded. fn collect(&self) -> Result> { - let Some(command_log) = &self.command_log else { + let Some(command_log) = self.command_log() else { return Ok(Vec::new()); }; let Some(dir) = command_log.parent() else { return Ok(Vec::new()); }; - let marker = format!("-{}-", self.stamp); let mut paths = Vec::new(); for entry in fs::read_dir(dir)? { let path = entry?.path(); - if path - .file_name() - .and_then(|name| name.to_str()) - .is_some_and(|name| name.contains(&marker) && name.ends_with(".models.json")) + if self + .owner + .as_ref() + .is_ok_and(|owner| owner.models_match(&path)) { paths.push(path); } @@ -184,7 +190,7 @@ impl Recording { continue; } }; - if record.command_log.as_deref() != Some(command_log.as_path()) { + if record.command_log.as_deref() != Some(command_log) { continue; } let models = if record.observed.is_empty() { diff --git a/src/session/recording/tests.rs b/src/session/recording/tests.rs index 7b5f7cba..c6a2561e 100644 --- a/src/session/recording/tests.rs +++ b/src/session/recording/tests.rs @@ -1,6 +1,8 @@ use super::*; use crate::harness::Harness; +const PARENT_OWNER: &str = "THIRDSHIFT_LOG_OWNER"; + struct Fixture { root: tempfile::TempDir, recording: Recording, @@ -9,12 +11,18 @@ struct Fixture { impl Fixture { fn new() -> Self { let root = tempfile::tempdir().unwrap(); - let recording = Recording::new(Some(root.path().join("7-stamp.log")), None, "stamp".into()); + let recording = Recording::new( + Some(root.path().join("7-20261003T120000-0400.log")), + None, + "20261003T120000-0400".into(), + ); Self { root, recording } } fn log(&self, name: &str) -> PathBuf { - self.root.path().join(format!("7-stamp-{name}.jsonl")) + self.root + .path() + .join(format!("7-20261003T120000-0400-{name}.jsonl")) } fn run(&self, name: &str, script: &str, choice: &Choice) -> Result { @@ -131,14 +139,18 @@ fn absent_completion_report_preserves_the_stream_checkpoint() { with_export( "absent_completion_report_preserves_the_stream_checkpoint", r#"#!/bin/sh -cp "$THIRDSHIFT_RECORDING_EXPORT/7-stamp-implement.models.json" "$THIRDSHIFT_RECORDING_EXPORT/checkpoint.json" +cp "$THIRDSHIFT_RECORDING_EXPORT/7-20261003T120000-0400-implement.models.json" "$THIRDSHIFT_RECORDING_EXPORT/checkpoint.json" kill -INT "$PPID" sleep 1 "#, |root| { crate::interrupt::install().unwrap(); - let recording = Recording::new(Some(root.join("7-stamp.log")), None, "stamp".into()); - let log = root.join("7-stamp-implement.jsonl"); + let recording = Recording::new( + Some(root.join("7-20261003T120000-0400.log")), + None, + "20261003T120000-0400".into(), + ); + let log = root.join("7-20261003T120000-0400-implement.jsonl"); let error = recording .run( "implement", @@ -172,17 +184,17 @@ fn both_evidence_writes_use_the_captured_owning_command() { with_export( "both_evidence_writes_use_the_captured_owning_command", r#"#!/bin/sh -cp "$THIRDSHIFT_RECORDING_EXPORT/7-stamp-implement.models.json" "$THIRDSHIFT_RECORDING_EXPORT/checkpoint.json" +cp "$THIRDSHIFT_RECORDING_EXPORT/7-20261003T120000-0400-implement.models.json" "$THIRDSHIFT_RECORDING_EXPORT/checkpoint.json" echo '{"info":{"outcome":"completed"},"messages":[{"type":"assistant","model":{"providerID":"provider","id":"retained-model"},"content":[]}]}' "#, |root| { - let owner = root.join("7-stamp.log"); + let owner = root.join("7-20261003T120000-0400.log"); let recording = Recording::new( Some(owner.clone()), Some(root.join("other.log")), - "stamp".into(), + "20261003T120000-0400".into(), ); - let log = root.join("7-stamp-implement.jsonl"); + let log = root.join("7-20261003T120000-0400-implement.jsonl"); recording .run( "implement", @@ -264,35 +276,47 @@ fn reader_failure_keeps_models_consumed_before_the_log_failed() { #[test] fn collection_preserves_legacy_selection_order_deduplication_and_fallbacks() { let fixture = Fixture::new(); - let owner = fixture.root.path().join("7-stamp.log"); + let owner = fixture.root.path().join("7-20261003T120000-0400.log"); for (file, command, models, requested, effort) in [ ( - "9-stamp-implement", + "9-20261003T120000-0400-implement", Some(owner.clone()), vec!["a", "b", "a"], None, None, ), ( - "8-stamp-review", + "8-20261003T120000-0400-review", Some(owner.clone()), vec![], Some("requested"), Some("high"), ), - ("7-stamp-implement", Some(owner.clone()), vec![], None, None), ( - "6-stamp-implement", + "7-20261003T120000-0400-implement", + Some(owner.clone()), + vec![], + None, + None, + ), + ( + "6-20261003T120000-0400-implement", Some(fixture.root.path().join("other.log")), vec!["wrong-owner"], None, None, ), - ("5-stamp-implement", None, vec!["unowned"], None, None), + ( + "5-20261003T120000-0400-implement", + None, + vec!["unowned"], + None, + None, + ), ( "4-old-implement", Some(owner), - vec!["old-stamp"], + vec!["old-20261003T120000-0400"], None, None, ), @@ -308,7 +332,10 @@ fn collection_preserves_legacy_selection_order_deduplication_and_fallbacks() { .unwrap(); } fs::write( - fixture.root.path().join("0-stamp-implement.models.json"), + fixture + .root + .path() + .join("0-20261003T120000-0400-implement.models.json"), "{ corrupt", ) .unwrap(); @@ -335,7 +362,7 @@ fn evidence_write_and_directory_read_failures_do_not_change_session_outcomes() { let missing = Recording::new( Some(fixture.root.path().join("missing/command.log")), None, - "stamp".into(), + "20261003T120000-0400".into(), ); assert!(missing.notification_lines().is_empty()); } @@ -343,11 +370,11 @@ fn evidence_write_and_directory_read_failures_do_not_change_session_outcomes() { #[test] fn absent_ownership_removes_stale_child_environment_and_records_no_other_command() { let fixture = Fixture::new(); - let unowned = Recording::new(None, None, "stamp".into()); + let unowned = Recording::new(None, None, "20261003T120000-0400".into()); let mut child = Command::new("/bin/sh"); child - .args(["-c", "test -z \"${THIRDSHIFT_PARENT_COMMAND_LOG+x}\""]) - .env(PARENT_COMMAND_LOG, "stale.log"); + .args(["-c", "test -z \"${THIRDSHIFT_LOG_OWNER+x}\""]) + .env(PARENT_OWNER, "stale.log"); unowned.inherit_command(&mut child); assert!(child.status().unwrap().success()); unowned @@ -375,7 +402,10 @@ fn nested_children_keep_the_exact_owning_command() { .unwrap() .parse() .unwrap(); - logs::begin(logs::Begin::ChildRun("stamp", logs::CommandKind::Issue)); + logs::begin(logs::Begin::ChildRun( + "20261003T120000-0400", + logs::CommandKind::Issue, + )); let recording = Recording::capture(); recording .run( @@ -383,7 +413,9 @@ fn nested_children_keep_the_exact_owning_command() { &Choice::default(), Command::new("/bin/sh").args(["-c", &format!("echo '{MODEL}'")]), None, - &root.join(format!("{depth}-stamp-implement.jsonl")), + &recording + .session_path(root, &depth.to_string(), "implement") + .unwrap(), Harness::Claude.adapter().interpretation(root, ""), ) .unwrap(); @@ -403,9 +435,14 @@ fn nested_children_keep_the_exact_owning_command() { let fixture = Fixture::new(); // A local Command wins even when the supplied inherited owner differs. let recording = Recording::new( - Some(fixture.root.path().join("7-stamp.log")), + Some( + fixture + .root + .path() + .join("7-20261003T120000-0400~fixture.log"), + ), Some(fixture.root.path().join("wrong.log")), - "stamp".into(), + "20261003T120000-0400".into(), ); let mut child = Command::new(std::env::current_exe().unwrap()); child @@ -415,7 +452,7 @@ fn nested_children_keep_the_exact_owning_command() { ]) .env(CHILD, fixture.root.path()) .env("THIRDSHIFT_RECORDING_DEPTH", "8") - .env(PARENT_COMMAND_LOG, "stale.log"); + .env(PARENT_OWNER, "stale.log"); recording.inherit_command(&mut child); let output = child.output().unwrap(); assert!(output.status.success(), "{output:?}"); @@ -435,7 +472,11 @@ fn interrupted_stream_survives_process_owners_suppression_of_recovered_state() { "#!/bin/sh\nexit 99\n", |root| { crate::interrupt::install().unwrap(); - let recording = Recording::new(Some(root.join("7-stamp.log")), None, "stamp".into()); + let recording = Recording::new( + Some(root.join("7-20261003T120000-0400.log")), + None, + "20261003T120000-0400".into(), + ); let error = recording .run( "implement", @@ -445,7 +486,7 @@ fn interrupted_stream_survives_process_owners_suppression_of_recovered_state() { &format!("echo '{MODEL}'; kill -INT \"$PPID\"; sleep 5"), ]), None, - &root.join("7-stamp-implement.jsonl"), + &root.join("7-20261003T120000-0400-implement.jsonl"), Harness::Claude.adapter().interpretation(root, ""), ) .unwrap_err(); diff --git a/tests/command_logs.rs b/tests/command_logs.rs index 69799150..b6969cd1 100644 --- a/tests/command_logs.rs +++ b/tests/command_logs.rs @@ -63,7 +63,7 @@ fn logs_in(scenario: &Scenario, folder: &str) -> Vec { } /// The one Command log in `commands/`, which must be named -/// `~.log`, and its display stamp. +/// `~.log`, and its stamp with storage owner. fn the_one_command_log(scenario: &Scenario, folder: &str, prefix: &str) -> (PathBuf, String) { let logs: Vec<_> = logs_in(scenario, &format!("commands/{folder}")) .into_iter() @@ -82,7 +82,7 @@ fn the_one_command_log(scenario: &Scenario, folder: &str, prefix: &str) -> (Path .join("commands") .join(folder) .join(&logs[0]); - (path, stamp.to_string()) + (path, format!("{stamp}~{token}")) } /// Assert `stamp` is a local time with [`OFFSET`], as in @@ -121,7 +121,11 @@ fn a_run_keeps_a_command_log_of_everything_it_printed_and_its_session_logs_share let scenario = Scenario::new(); scenario.agent_does(&agent_opens_pr(7, "main")); - let result = run_in_zone(&scenario, &[&scenario.issue_url(7)], &[]); + let result = run_in_zone( + &scenario, + &[&scenario.issue_url(7)], + &[("THIRDSHIFT_LOG_OWNER", "stale inherited owner")], + ); assert_eq!(result.code, Some(0), "stderr: {}", result.stderr); let (path, stamp) = the_one_command_log(&scenario, "issue", "7-"); @@ -347,6 +351,13 @@ fn an_obstructed_commands_folder_warns_and_prevents_session_logging() { ); assert!(scenario.claude_calls().is_empty()); assert!(!scenario.path(LOGS).join("sessions").exists()); + assert!( + result + .stderr + .contains("cannot name Session log: could not create"), + "{}", + result.stderr + ); } #[test] diff --git a/tests/run_notification.rs b/tests/run_notification.rs index 7792d224..91a91619 100644 --- a/tests/run_notification.rs +++ b/tests/run_notification.rs @@ -118,7 +118,7 @@ fn a_review_required_notification_and_summary_name_the_refusal() { } #[test] -fn a_notification_keeps_current_models_when_an_unrelated_record_is_corrupt() { +fn a_notification_keeps_current_models_when_an_owned_record_is_corrupt() { let scenario = Scenario::new(); let started = scenario.path("agent-started"); let release = scenario.path("agent-release"); @@ -143,9 +143,6 @@ fn a_notification_keeps_current_models_when_an_unrelated_record_is_corrupt() { .strip_prefix("7-") .unwrap() .strip_suffix(".log") - .unwrap() - .split('~') - .next() .unwrap(); std::fs::write( scenario diff --git a/tests/show_logs.rs b/tests/show_logs.rs index 9e933f6d..09c595b0 100644 --- a/tests/show_logs.rs +++ b/tests/show_logs.rs @@ -7,6 +7,45 @@ use support::Scenario; const OPENS_PR: &str = "echo work > work.txt\ngit add work.txt\ngit commit -qm 'Make widgets'\ngh pr create --base main --head issue-7 --title 'Make widgets' --body 'Closes #7'\n"; +#[test] +fn same_stamp_session_history_keeps_legacy_and_owned_inventories_disjoint() { + let scenario = Scenario::new(); + let folder = scenario.path("home/.thirdshift/logs/acme/widgets/commands/issue"); + fs::create_dir_all(&folder).unwrap(); + for owner in ["", "~first", "~second"] { + let stem = format!("7-20261003T120000-0400{owner}"); + fs::write( + folder.join(format!("{stem}.log")), + format!("{owner} Command\n"), + ) + .unwrap(); + for kind in ["implement", "implement-resume", "repair-1", "repair-2"] { + fs::write( + folder.join(format!("{stem}-{kind}.jsonl")), + format!("{owner} {kind}\n"), + ) + .unwrap(); + } + } + let result = scenario.run(&["status", "--all", "--json"]); + assert_eq!(result.code, Some(0), "{}", result.stderr); + let status: Value = serde_json::from_str(&result.stdout).unwrap(); + assert_eq!(status["version"], 1); + let commands = status["commands"].as_array().unwrap(); + assert_eq!(commands.len(), 3, "{status}"); + for command in commands { + assert_eq!(command["source"], "session_log"); + let log = std::path::Path::new(command["command_log"].as_str().unwrap()); + let stem = log.file_stem().unwrap().to_str().unwrap(); + let sessions = command["session_logs"].as_array().unwrap(); + assert_eq!(sessions.len(), 4, "{command}"); + for kind in ["implement", "implement-resume", "repair-1", "repair-2"] { + let path = folder.join(format!("{stem}-{kind}.jsonl")); + assert!(sessions.contains(&serde_json::json!(path)), "{command}"); + } + } +} + #[test] fn owned_and_legacy_commands_keep_exact_paths_and_record_precedence() { let scenario = Scenario::new(); diff --git a/tests/spec_run.rs b/tests/spec_run.rs index c0d4d766..422e2d69 100644 --- a/tests/spec_run.rs +++ b/tests/spec_run.rs @@ -1178,6 +1178,43 @@ fn with_base_fix_a_tickets_inherited_failure_gets_a_base_fix_into_the_spec_branc assert!(scenario.origin_file("issue-20", file).is_some(), "{file}"); } assert_eq!(spec_pr(&scenario)["isDraft"], false); + let folder = "home/.thirdshift/logs/acme/widgets/commands/issue"; + let commands = scenario.log_files(folder, "log"); + assert_eq!( + commands.len(), + 1, + "children keep no Command log: {commands:?}" + ); + let owner = commands[0] + .strip_prefix("20-") + .unwrap() + .strip_suffix(".log") + .unwrap(); + let sessions = scenario.log_files(folder, "jsonl"); + assert_eq!( + sessions, + [ + format!("20-{owner}-spec-review.jsonl"), + format!("21-{owner}-implement.jsonl"), + format!("22-{owner}-implement.jsonl") + ] + ); + for session in sessions { + let evidence: serde_json::Value = serde_json::from_slice( + &std::fs::read( + scenario + .path(folder) + .join(session) + .with_extension("models.json"), + ) + .unwrap(), + ) + .unwrap(); + assert_eq!( + evidence["command_log"], + scenario.path(folder).join(&commands[0]).to_str().unwrap() + ); + } } #[test] From 55e69646079e3e63f50c51b2434d939749de407a Mon Sep 17 00:00:00 2001 From: Jacob Stephens Date: Mon, 19 Oct 2026 08:33:21 +0000 Subject: [PATCH 07/10] Address ownership comparison and fixture naming review findings --- src/logs/owner.rs | 21 ++++++++--------- tests/command_logs.rs | 52 +++++++++++++++++++++---------------------- 2 files changed, 35 insertions(+), 38 deletions(-) diff --git a/src/logs/owner.rs b/src/logs/owner.rs index d4d070cf..0a9b82d7 100644 --- a/src/logs/owner.rs +++ b/src/logs/owner.rs @@ -28,6 +28,13 @@ pub(crate) struct Owner { } impl Owner { + fn identity(&self) -> Identity<'_> { + Identity { + stamp: &self.stamp, + token: self.token.as_deref(), + } + } + pub fn log_path(&self) -> Option<&Path> { self.command_log.as_deref() } @@ -57,12 +64,7 @@ impl Owner { }; let session = path.with_file_name(format!("{stem}.jsonl")); decode(&session).is_some_and(|decoded| { - decoded.session_kind.is_some() - && decoded.identity - == Identity { - stamp: &self.stamp, - token: self.token.as_deref(), - } + decoded.session_kind.is_some() && decoded.identity == self.identity() }) } @@ -87,12 +89,7 @@ impl Owner { if let Some(log) = owner.log_path() { let decoded = decode(log).context("invalid inherited Command log path")?; ensure!( - decoded.session_kind.is_none() - && decoded.identity - == Identity { - stamp: &owner.stamp, - token: owner.token.as_deref() - }, + decoded.session_kind.is_none() && decoded.identity == owner.identity(), "inherited Command log disagrees with its owner" ); } diff --git a/tests/command_logs.rs b/tests/command_logs.rs index b6969cd1..95910324 100644 --- a/tests/command_logs.rs +++ b/tests/command_logs.rs @@ -128,7 +128,7 @@ fn a_run_keeps_a_command_log_of_everything_it_printed_and_its_session_logs_share ); assert_eq!(result.code, Some(0), "stderr: {}", result.stderr); - let (path, stamp) = the_one_command_log(&scenario, "issue", "7-"); + let (path, identity_fragment) = the_one_command_log(&scenario, "issue", "7-"); assert_holds_what_was_printed(&path, &result); assert_dated_first_line(&result, &format!("starting on {}", scenario.issue_url(7))); assert!( @@ -142,8 +142,8 @@ fn a_run_keeps_a_command_log_of_everything_it_printed_and_its_session_logs_share assert_eq!( logs_in(&scenario, "commands/issue"), [ - format!("7-{stamp}-implement.jsonl"), - format!("7-{stamp}-implement.models.json"), + format!("7-{identity_fragment}-implement.jsonl"), + format!("7-{identity_fragment}-implement.models.json"), path.file_name().unwrap().to_str().unwrap().to_string() ] ); @@ -167,7 +167,7 @@ fn a_spec_runs_command_log_has_its_tickets_lines_and_its_tickets_keep_none() { let result = run_in_zone(&scenario, &[&scenario.issue_url(20)], &[]); assert_eq!(result.code, Some(0), "stderr: {}", result.stderr); - let (path, stamp) = the_one_command_log(&scenario, "issue", "20-"); + let (path, identity_fragment) = the_one_command_log(&scenario, "issue", "20-"); assert_holds_what_was_printed(&path, &result); let log = fs::read_to_string(&path).unwrap(); for ticket in [21, 22] { @@ -179,9 +179,9 @@ fn a_spec_runs_command_log_has_its_tickets_lines_and_its_tickets_keep_none() { assert_eq!( scenario.log_files(&format!("{LOGS}/commands/issue"), "jsonl"), [ - format!("20-{stamp}-spec-review.jsonl"), - format!("21-{stamp}-implement.jsonl"), - format!("22-{stamp}-implement.jsonl"), + format!("20-{identity_fragment}-spec-review.jsonl"), + format!("21-{identity_fragment}-implement.jsonl"), + format!("22-{identity_fragment}-implement.jsonl"), ] ); } @@ -198,7 +198,7 @@ fn a_pickup_run_that_takes_an_issue_keeps_a_command_log_from_its_first_line() { let result = run_in_zone(&scenario, &["pickup"], &[]); assert_eq!(result.code, Some(0), "stderr: {}", result.stderr); - let (path, stamp) = the_one_command_log(&scenario, "pickup", "7-"); + let (path, identity_fragment) = the_one_command_log(&scenario, "pickup", "7-"); assert_holds_what_was_printed(&path, &result); assert_dated_first_line(&result, "Pickup run starting"); let log = fs::read_to_string(&path).unwrap(); @@ -208,8 +208,8 @@ fn a_pickup_run_that_takes_an_issue_keeps_a_command_log_from_its_first_line() { assert_eq!( logs_in(&scenario, "commands/pickup"), [ - format!("7-{stamp}-implement.jsonl"), - format!("7-{stamp}-implement.models.json"), + format!("7-{identity_fragment}-implement.jsonl"), + format!("7-{identity_fragment}-implement.models.json"), path.file_name().unwrap().to_str().unwrap().to_string() ] ); @@ -226,17 +226,17 @@ fn a_pickup_spec_keeps_its_tickets_session_logs_beside_its_command_log() { let result = run_in_zone(&scenario, &["pickup"], &[]); assert_eq!(result.code, Some(0), "stderr: {}", result.stderr); - let (path, stamp) = the_one_command_log(&scenario, "pickup", "20-"); + let (path, identity_fragment) = the_one_command_log(&scenario, "pickup", "20-"); assert_eq!( logs_in(&scenario, "commands/pickup"), [ - format!("20-{stamp}-spec-review.jsonl"), - format!("20-{stamp}-spec-review.models.json"), + format!("20-{identity_fragment}-spec-review.jsonl"), + format!("20-{identity_fragment}-spec-review.models.json"), path.file_name().unwrap().to_str().unwrap().to_string(), - format!("21-{stamp}-implement.jsonl"), - format!("21-{stamp}-implement.models.json"), - format!("22-{stamp}-implement.jsonl"), - format!("22-{stamp}-implement.models.json"), + format!("21-{identity_fragment}-implement.jsonl"), + format!("21-{identity_fragment}-implement.models.json"), + format!("22-{identity_fragment}-implement.jsonl"), + format!("22-{identity_fragment}-implement.models.json"), ] ); assert!(!scenario.path(LOGS).join("sessions").exists()); @@ -259,7 +259,7 @@ printf 'Architecture review plan: %s\n' "$url" > "$FAKE_CLAUDE_FINAL_MESSAGE" let result = run_in_zone(&scenario, &["architect"], &[]); assert_eq!(result.code, Some(0), "stderr: {}", result.stderr); - let (path, stamp) = the_one_command_log(&scenario, "architect", ""); + let (path, identity_fragment) = the_one_command_log(&scenario, "architect", ""); assert_holds_what_was_printed(&path, &result); assert_dated_first_line(&result, "Architect run starting"); let log = fs::read_to_string(&path).unwrap(); @@ -270,8 +270,8 @@ printf 'Architecture review plan: %s\n' "$url" > "$FAKE_CLAUDE_FINAL_MESSAGE" assert_eq!( scenario.log_files(&format!("{LOGS}/commands/architect"), "jsonl"), [ - format!("8-{stamp}-implement.jsonl"), - format!("architect-{stamp}-architecture-review.jsonl"), + format!("8-{identity_fragment}-implement.jsonl"), + format!("architect-{identity_fragment}-architecture-review.jsonl"), ] ); } @@ -284,10 +284,10 @@ fn a_failed_run_ends_by_naming_its_session_log_then_its_command_log() { let result = run_in_zone(&scenario, &[&scenario.issue_url(7)], &[]); assert_eq!(result.code, Some(1), "stderr: {}", result.stderr); - let (path, stamp) = the_one_command_log(&scenario, "issue", "7-"); - let session = scenario - .path(LOGS) - .join(format!("commands/issue/7-{stamp}-implement.jsonl")); + let (path, identity_fragment) = the_one_command_log(&scenario, "issue", "7-"); + let session = scenario.path(LOGS).join(format!( + "commands/issue/7-{identity_fragment}-implement.jsonl" + )); let ending: Vec<_> = result.stderr.lines().rev().take(2).collect(); assert_eq!( ending, @@ -416,7 +416,7 @@ gh fake checks "$(git rev-parse origin/main)" '[{"name": "test", "conclusion": " let result = run_in_zone(&scenario, &[&scenario.issue_url(7), "base-fix"], &[]); assert_eq!(result.code, Some(0), "stderr: {}", result.stderr); - let (path, stamp) = the_one_command_log(&scenario, "issue", "7-"); + let (path, identity_fragment) = the_one_command_log(&scenario, "issue", "7-"); assert_holds_what_was_printed(&path, &result); let log = fs::read_to_string(&path).unwrap(); assert!( @@ -426,7 +426,7 @@ gh fake checks "$(git rev-parse origin/main)" '[{"name": "test", "conclusion": " assert!( scenario .log_files(&format!("{LOGS}/commands/issue"), "jsonl") - .contains(&format!("8-{stamp}-implement.jsonl")), + .contains(&format!("8-{identity_fragment}-implement.jsonl")), "{:?}", scenario.log_files(&format!("{LOGS}/commands/issue"), "jsonl") ); From dbf46499e31f3d41c22023a27b57b4c5bb16282b Mon Sep 17 00:00:00 2001 From: Jacob Stephens Date: Mon, 19 Oct 2026 08:46:35 +0000 Subject: [PATCH 08/10] Keep the Session log failure fixture on its captured owner --- tests/progress_lines.rs | 9 ++++----- 1 file changed, 4 insertions(+), 5 deletions(-) diff --git a/tests/progress_lines.rs b/tests/progress_lines.rs index dc34ba5b..b9300a7f 100644 --- a/tests/progress_lines.rs +++ b/tests/progress_lines.rs @@ -276,7 +276,7 @@ fn a_log_failure_still_recovers_and_reports_warnings_and_usage() { ); let logs = scenario.path("home/.thirdshift/logs/acme/widgets"); // Install the failing log before the session opens it. The Command log - // supplies the actual start stamp, so this never predicts the clock. + // supplies the captured stamp and owner, so this never predicts the clock. scenario.repo_has_hook( &scenario.launch_dir(), "post-checkout", @@ -284,12 +284,11 @@ fn a_log_failure_still_recovers_and_reports_warnings_and_usage() { r#"#!/bin/sh for log in "{logs}/commands/issue/"*.log; do name=${{log##*/}} - stamp=${{name#7-}} - stamp=${{stamp%.log}} - stamp=${{stamp%%~*}} + identity_fragment=${{name#7-}} + identity_fragment=${{identity_fragment%.log}} done mkdir -p "{logs}/commands/issue" -ln -s "{pipe}" "{logs}/commands/issue/7-$stamp-implement.jsonl" +ln -s "{pipe}" "{logs}/commands/issue/7-$identity_fragment-implement.jsonl" touch "{ready}" "#, logs = logs.display(), From ae021a2dec43621af3d54b428269ef85187dd4db Mon Sep 17 00:00:00 2001 From: Jacob Stephens Date: Mon, 19 Oct 2026 08:48:34 +0000 Subject: [PATCH 09/10] Name the owned Model fixture identity explicitly --- tests/run_notification.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tests/run_notification.rs b/tests/run_notification.rs index 91a91619..27c9da42 100644 --- a/tests/run_notification.rs +++ b/tests/run_notification.rs @@ -139,7 +139,7 @@ fn a_notification_keeps_current_models_when_an_owned_record_is_corrupt() { let folder = "home/.thirdshift/logs/acme/widgets/commands/issue"; let command_logs = scenario.log_files(folder, "log"); assert_eq!(command_logs.len(), 1, "{command_logs:?}"); - let stamp = command_logs[0] + let identity_fragment = command_logs[0] .strip_prefix("7-") .unwrap() .strip_suffix(".log") @@ -147,7 +147,7 @@ fn a_notification_keeps_current_models_when_an_owned_record_is_corrupt() { std::fs::write( scenario .path(folder) - .join(format!("8-{stamp}-implement.models.json")), + .join(format!("8-{identity_fragment}-implement.models.json")), "{ truncated", ) .unwrap(); From 914b0567e58dd15605dfeebbbd74bd0483aa47a7 Mon Sep 17 00:00:00 2001 From: Jacob Stephens Date: Mon, 19 Oct 2026 09:34:40 +0000 Subject: [PATCH 10/10] Share Command and Session storage identity formatting --- src/logs/owner.rs | 24 ++++++++++++------------ 1 file changed, 12 insertions(+), 12 deletions(-) diff --git a/src/logs/owner.rs b/src/logs/owner.rs index 0a9b82d7..998e8876 100644 --- a/src/logs/owner.rs +++ b/src/logs/owner.rs @@ -46,12 +46,7 @@ impl Owner { } pub fn session_path(&self, dir: &Path, subject: &str, kind: &str) -> PathBuf { - let token = self - .token - .as_ref() - .map(|token| format!("~{token}")) - .unwrap_or_default(); - dir.join(format!("{subject}-{}{token}-{kind}.jsonl", self.stamp)) + dir.join(format!("{subject}-{}-{kind}.jsonl", self.identity())) } pub fn models_match(&self, path: &Path) -> bool { @@ -195,6 +190,16 @@ pub(super) struct Identity<'a> { pub token: Option<&'a str>, } +impl std::fmt::Display for Identity<'_> { + fn fmt(&self, formatter: &mut std::fmt::Formatter<'_>) -> std::fmt::Result { + formatter.write_str(self.stamp)?; + if let Some(token) = self.token { + write!(formatter, "~{token}")?; + } + Ok(()) + } +} + pub(super) struct Decoded<'a> { pub subject: &'a str, pub identity: Identity<'a>, @@ -211,12 +216,7 @@ impl Decoded<'_> { "" | "architect" | "secure" => String::new(), subject => format!("{subject}-"), }; - let token = self - .identity - .token - .map(|token| format!("~{token}")) - .unwrap_or_default(); - path.with_file_name(format!("{subject}{}{token}.log", self.identity.stamp)) + path.with_file_name(format!("{subject}{}.log", self.identity)) } }