Skip to main content

capsule_runtime/
detached.rs

1//! Shell commands that were moved out of the foreground and run on in the background.
2//!
3//! Every shell command starts in the foreground. One is demoted when it has not exited by the
4//! time a declared `lifecycle.shell_grace_secs` elapses, or when the call waiting on it is
5//! abandoned or its task is canceled: the turn gets a work id and carries on, the command keeps
6//! running on an OS thread of its own, and its output is written to a log in the session's
7//! records directory as it is read. With no `shell_grace_secs` a command is never demoted on a
8//! clock.
9//!
10//! The work id is an address. [`DetachedRegistry`] keeps every demoted command of the session,
11//! running or finished, and the runtime-provided `background-command` tool
12//! ([`crate::background_command`]), offered when `shell_grace_secs` is set, reads its state,
13//! waits for it or stops it by that id. When a
14//! command finishes, the runtime also enqueues a task on this capsule with
15//! [`crate::origin::TaskOrigin::Completion`] carrying the exit code and the log's path, unless
16//! the agent already read the exit through the tool.
17
18use std::{
19    collections::{BTreeMap, VecDeque},
20    io::Write as _,
21    sync::{
22        atomic::{AtomicBool, Ordering},
23        Arc, Mutex,
24    },
25    time::{Duration, Instant},
26};
27
28use tokio::sync::{
29    mpsc::{unbounded_channel, UnboundedReceiver, UnboundedSender},
30    watch,
31};
32
33use crate::{
34    bindings::host::murmur::tool::run::{Status, ToolResult},
35    cancel::CancelSignal,
36    origin::{TaskOrigin, TaskProvenance},
37};
38
39/// Prefix on every work id. Distinct from `tsk_`/`ctx_`/`ses_` so a reader of `trace.jsonl` can
40/// tell at a glance which id space a value belongs to.
41pub const WORK_ID_PREFIX: &str = "wrk_";
42
43/// A fresh work id, matching `^wrk_[0-9a-f]+$`.
44///
45/// Time-ordered like every other id the runtime mints, so two work ids sort in the order their
46/// commands were demoted.
47pub fn new_work_id() -> String {
48    format!("{WORK_ID_PREFIX}{}", uuid::Uuid::now_v7().simple())
49}
50
51/// A shell command's full-output log in the session's records directory.
52#[derive(Debug, Clone, PartialEq, Eq)]
53pub(crate) struct OutputLog {
54    /// Relative to the records directory, `logs/<stem>.log`: what the writer opens and measures
55    /// through the records root.
56    pub relative: String,
57    /// The absolute host path, the one name every text gives the log. A shell command, a plan
58    /// shell step and a process harness can all open it; a WASM tool cannot.
59    pub path: String,
60}
61
62/// Where the full output of the shell command named `stem` lands: `logs/<stem>.log` in the
63/// session's records directory. The stem is the work id for a demoted command and `shell-<ms>`
64/// for a foreground command whose output passed [`crate::shell::MAX_SHELL_OUTPUT_BYTES`].
65///
66/// One rule, used by both writers — [`LiveOutput`] for a demoted command, which writes the log as
67/// the command runs, and `shell::write_shell_output_log` for a foreground one, which writes it
68/// once at exit in its own layout — and by every reader that has to name the file.
69pub(crate) fn output_path_for(
70    records_root: &crate::workdir_fs::WorkdirRoot,
71    stem: &str,
72) -> OutputLog {
73    let relative = format!("logs/{stem}.log");
74    let path = records_root
75        .host_path(&relative)
76        .to_string_lossy()
77        .into_owned();
78    OutputLog { relative, path }
79}
80
81/// A demoted command the session is no longer waiting for.
82#[derive(Debug, Clone)]
83pub(crate) struct DetachedWork {
84    pub work_id: String,
85    /// The program that ran, resolved the same way [`crate::shell::ShellResult::binary`] is.
86    pub binary: String,
87    /// The command text the model supplied, without the binary name.
88    pub command: String,
89    /// When the command was spawned, not when it was demoted — the foreground grace period counts
90    /// as running time, so this lines up with the `duration_ms` a completion carries.
91    pub started_at_ms: u64,
92}
93
94/// What a demoted command left behind when it finished.
95///
96/// Carries no output. The bytes are on disk at [`Self::output_path`] and the agent is told where,
97/// never what — a completion the model reads must not be able to grow with the command's output.
98#[derive(Debug, Clone)]
99pub(crate) struct DetachedCompletion {
100    pub work_id: String,
101    pub binary: String,
102    pub command: String,
103    pub exit_code: i32,
104    pub duration_ms: u64,
105    /// Epoch milliseconds at which the command's own wait returned, before its output finished
106    /// draining and before the completion was recorded.
107    pub exited_at_ms: u64,
108    /// The log's absolute path, [`output_path_for`]'s [`OutputLog::path`] for this work id. Named
109    /// even when [`Self::error`] is set, so a reader knows where the output was meant to be.
110    pub output_path: String,
111    /// Bytes written to that file, header included.
112    pub output_bytes: u64,
113    pub resource_limit: Option<String>,
114    /// Whether anything the command started was still holding its output when it exited, as on
115    /// [`crate::shell::ShellResult::output_holders`].
116    pub output_holders: crate::shell::OutputHolders,
117    /// The conversation the command was started from. The completion task runs under this id, so
118    /// the result joins the thread that asked for it rather than opening a new one.
119    pub context_id: String,
120    /// Stamped [`TaskOrigin::Completion`] with the starting task's trust inherited.
121    pub provenance: TaskProvenance,
122    /// Some only when the wait itself failed — distinct from the command exiting non-zero.
123    pub error: Option<String>,
124}
125
126impl DetachedCompletion {
127    /// The `IncomingTask.message_text` the agent reads: the work id, the status, the exit code,
128    /// the duration and the output path. Never the output itself, nor the command, which the work
129    /// id names and the tool call that started it holds.
130    ///
131    /// An attributed limit adds the [`crate::resources::resource_limit_line`] a foreground call
132    /// would get, naming the limit and what to do about it, and output holders that were killed
133    /// or left running add their [`crate::shell::OutputHolders::note`].
134    pub(crate) fn message_text(&self) -> String {
135        let mut text = format!(
136            "Background shell command finished.\n\
137             work_id: {}\n\
138             status: {}\n\
139             exit_code: {}\n\
140             duration_ms: {}\n\
141             output: {} ({} bytes)",
142            self.work_id,
143            self.status(),
144            self.exit_code,
145            self.duration_ms,
146            self.output_path,
147            self.output_bytes,
148        );
149        if let Some(limit) = &self.resource_limit {
150            text.push('\n');
151            text.push_str(&crate::resources::resource_limit_line(limit));
152        }
153        if let Some(note) = self.output_holders.note() {
154            text.push('\n');
155            text.push_str(&note);
156        }
157        if let Some(error) = &self.error {
158            text.push_str(&format!("\nwait_error: {error}"));
159        }
160        text.push_str(
161            "\n\nThe full stdout and stderr are in that file and are not reproduced here.",
162        );
163        text
164    }
165
166    /// `"ok"` only for a command that ran to a clean exit with nothing attributed against it.
167    ///
168    /// A non-zero exit, a signal kill (which [`crate::shell`] reports as `128 + signal`), an
169    /// attributed resource limit and a wait that itself failed are all `"error"`: a failure is a
170    /// completion, and it is told apart from success by this field rather than by its prose.
171    pub(crate) fn status(&self) -> &'static str {
172        if self.exit_code == 0 && self.error.is_none() && self.resource_limit.is_none() {
173            "ok"
174        } else {
175            "error"
176        }
177    }
178}
179
180/// What a dispatch reports back when its command was demoted rather than finished.
181#[derive(Debug, Clone)]
182pub(crate) struct DetachedDispatchInfo {
183    pub work_id: String,
184    pub binary: String,
185    pub command: String,
186    /// The configured `lifecycle.shell_grace_secs` in milliseconds, recorded so a trace reader
187    /// can see which setting was in force without consulting the manifest. `None` when the
188    /// session declares no grace, so the command was demoted by an abandoned call or a cancel.
189    pub grace_ms: Option<u64>,
190}
191
192/// The tool result a demoted command hands back to the turn. `delivered` is
193/// [`DetachPolicy::delivered`]: whether the completion can also reach the model as a later task.
194/// `tool_offered` is whether the session offers `background-command`, which it does exactly when
195/// `lifecycle.shell_grace_secs` is set; without it the text names no tool.
196///
197/// Constant size by construction for every combination: nothing here derives from the command,
198/// its arguments or its output, so no input can make the text the model reads grow. It names no
199/// path and shows no output; `background-command` reports both.
200pub(crate) fn demotion_tool_result(
201    work_id: &str,
202    delivered: bool,
203    tool_offered: bool,
204) -> ToolResult {
205    let tool = crate::background_command::BACKGROUND_COMMAND_TOOL;
206    let mut data = if tool_offered {
207        format!(
208            "The command is still running and was moved to the background as {work_id}. The \
209             {tool} tool reports on it, waits for it or stops it by that id. A command still \
210             running when the session ends is killed."
211        )
212    } else {
213        format!(
214            "The command is still running and was moved to the background as {work_id}. A \
215             command still running when the session ends is killed."
216        )
217    };
218    match (delivered, tool_offered) {
219        (true, true) => data.push_str(&format!(
220            " If it exits before {tool} has reported its exit, its result also arrives later as a \
221             separate task."
222        )),
223        (true, false) => {
224            data.push_str(" When it exits, its result arrives later as a separate task.");
225        }
226        (false, _) => {}
227    }
228    ToolResult {
229        status: Status::Passed,
230        summary: Some(format!(
231            "Command still running in the background as {work_id}."
232        )),
233        data: Some(data),
234        data_path: None,
235        truncated: false,
236        metadata: vec![("work_id".to_string(), work_id.to_string())],
237        attachments: Vec::new(),
238    }
239}
240
241/// Where a demoted command is in its life, as each registry entry broadcasts it.
242///
243/// Ordered: a later phase never goes back to an earlier one.
244#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord)]
245pub(crate) enum Phase {
246    /// The command's own process has not exited.
247    Running,
248    /// Its own process has exited and is about to be reaped, so its process group is no longer
249    /// signalled. Its output may still be draining.
250    LeaderExited,
251    /// The completion is recorded: exit code, status and the log's trailer.
252    Finished,
253}
254
255/// What `background-command` reports a command's state as.
256#[derive(Debug, Clone, Copy, PartialEq, Eq)]
257pub(crate) enum CommandState {
258    Running,
259    /// Finished, with no `stop` having reached it.
260    Exited,
261    /// Finished after a `stop` signalled it.
262    Stopped,
263}
264
265impl CommandState {
266    pub(crate) fn as_str(self) -> &'static str {
267        match self {
268            Self::Running => "running",
269            Self::Exited => "exited",
270            Self::Stopped => "stopped",
271        }
272    }
273}
274
275/// How a finished command's completion reached the agent. Claimed once per work id, by whichever
276/// path gets there first, and that path writes the work id's one `shell_completed`.
277#[derive(Debug, Clone, Copy, PartialEq, Eq)]
278pub(crate) enum Delivery {
279    /// A `background-command` call returned the finished state.
280    BackgroundCommand,
281    /// The task loop queued the completion as a `completion`-origin task.
282    Task,
283}
284
285impl Delivery {
286    /// `shell_completed.delivered_via`.
287    pub(crate) fn as_str(self) -> &'static str {
288        match self {
289            Self::BackgroundCommand => "background_command",
290            Self::Task => "task",
291        }
292    }
293}
294
295/// The output section of a demoted command's log, written as its pipes are read.
296///
297/// The log is `Command: <binary> <args…>`, a blank line, the output section, and the
298/// `Exit code: <n>` trailer appended once the command has exited. The output section is
299/// whatever either pipe yielded, in the order the two reader threads appended whole chunks
300/// under this struct's lock; the bytes read before demotion come first, stdout's then stderr's.
301///
302/// The last [`crate::shell::MAX_SHELL_OUTPUT_BYTES`] bytes of the section are also kept here, so
303/// a status read never opens the file.
304pub(crate) struct LiveOutput {
305    /// `None` once a write failed, or when the log could not be opened.
306    file: Option<std::fs::File>,
307    tail: VecDeque<u8>,
308    /// Bytes appended to the output section, counted whether or not they reached the file.
309    section_bytes: u64,
310    /// The first failure to open or write the log.
311    write_error: Option<String>,
312}
313
314impl LiveOutput {
315    /// Opens `relative` in `records_root` for appending and writes the `Command:` header.
316    ///
317    /// A failure is kept, not returned: the command keeps running, its tail is still kept, and
318    /// the failure becomes its completion's [`DetachedCompletion::error`].
319    pub(crate) fn open(
320        records_root: &crate::workdir_fs::WorkdirRoot,
321        relative: &str,
322        command_line: &str,
323    ) -> Self {
324        let mut live = Self {
325            file: None,
326            tail: VecDeque::new(),
327            section_bytes: 0,
328            write_error: None,
329        };
330        match records_root.open_append(relative, crate::workdir_fs::DEFAULT_FILE_MODE) {
331            Ok(file) => {
332                live.file = Some(file);
333                live.write(format!("Command: {command_line}\n\n").as_bytes());
334            }
335            Err(error) => live.write_error = Some(format!("failed to write shell log: {error}")),
336        }
337        live
338    }
339
340    fn write(&mut self, bytes: &[u8]) {
341        let Some(file) = self.file.as_mut() else {
342            return;
343        };
344        if let Err(error) = file.write_all(bytes) {
345            self.file = None;
346            self.write_error
347                .get_or_insert_with(|| format!("failed to write shell log: {error}"));
348        }
349    }
350
351    /// Appends `bytes` to the output section and to the kept tail.
352    pub(crate) fn append(&mut self, bytes: &[u8]) {
353        self.write(bytes);
354        self.section_bytes = self.section_bytes.saturating_add(bytes.len() as u64);
355        let keep = crate::shell::MAX_SHELL_OUTPUT_BYTES;
356        if bytes.len() >= keep {
357            self.tail.clear();
358            self.tail.extend(&bytes[bytes.len() - keep..]);
359        } else {
360            let excess = (self.tail.len() + bytes.len()).saturating_sub(keep);
361            self.tail.drain(..excess);
362            self.tail.extend(bytes);
363        }
364    }
365
366    /// Appends the `Exit code:` trailer and closes the log. Returns the first write failure, if
367    /// any write to this log failed.
368    pub(crate) fn finish(&mut self, exit_code: i32) -> Option<String> {
369        self.write(format!("\n\nExit code: {exit_code}\n").as_bytes());
370        self.file = None;
371        self.write_error.clone()
372    }
373}
374
375/// One demoted command as the registry holds it for the rest of the session.
376struct DetachedEntry {
377    work: DetachedWork,
378    started: Instant,
379    /// The command's process group: its own pid, since every shell command leads its group.
380    pgid: i32,
381    /// The log's absolute path, as [`OutputLog::path`].
382    output_path: String,
383    output: Arc<Mutex<LiveOutput>>,
384    /// Whether the command's own process is unreaped. Its group is signalled only while this is
385    /// set, and only under the registry lock, because the demoted thread clears it under that
386    /// lock before it reaps: a reaped pid can name an unrelated process group.
387    leader_running: bool,
388    /// Set when `stop` signalled the command, which makes a finished command `stopped`.
389    stop_requested: bool,
390    /// Signals sent to the group by `stop` and `kill_running`.
391    signals_sent: u32,
392    finished: Option<DetachedCompletion>,
393    /// How the completion reached the agent, once one path has claimed it. Only a finished entry
394    /// is claimed.
395    delivery: Option<Delivery>,
396    phase: watch::Sender<Phase>,
397}
398
399/// A demoted command's state at one moment, as `background-command` renders it.
400#[derive(Debug, Clone)]
401pub(crate) struct CommandSnapshot {
402    pub work_id: String,
403    pub state: CommandState,
404    /// From spawn to now, or to the end of its completion for a finished command.
405    pub elapsed_ms: u64,
406    /// The completion, for a finished command.
407    pub finished: Option<DetachedCompletion>,
408    pub output_path: String,
409    /// Bytes in the log's output section.
410    pub output_bytes: u64,
411    /// The last [`crate::shell::MAX_SHELL_OUTPUT_BYTES`] bytes of the output section, or all of
412    /// it when it is shorter.
413    pub tail: Vec<u8>,
414    /// Whether this read claimed the completion for [`Delivery::BackgroundCommand`], which makes
415    /// its caller the writer of the work id's `shell_completed`.
416    pub delivered_now: bool,
417}
418
419/// How a `wait` ended.
420#[derive(Debug, Clone, Copy, PartialEq, Eq)]
421pub(crate) enum WaitEnd {
422    Finished,
423    TimedOut,
424    Canceled,
425    /// The work id names no command in this session.
426    Unknown,
427}
428
429/// The demoted commands of one session, and the channel their completions arrive on.
430///
431/// Shared between the agent loop (which registers work and answers `background-command`) and
432/// each demoted command's own thread (which completes it). Entries are never removed, so a work
433/// id stays valid for the rest of the session.
434pub(crate) struct DetachedRegistry {
435    entries: Mutex<BTreeMap<String, DetachedEntry>>,
436    /// Every report the task loop turns into a `completion`-origin task, not only a demoted
437    /// command's. A delegation that outran its deadline arrives here too, so one channel feeds one
438    /// enqueue path and the admission rule cannot differ between them.
439    reports: UnboundedSender<DetachedReport>,
440}
441
442impl DetachedRegistry {
443    pub(crate) fn new() -> (Arc<Self>, UnboundedReceiver<DetachedReport>) {
444        let (reports, receiver) = unbounded_channel();
445        (
446            Arc::new(Self {
447                entries: Mutex::new(BTreeMap::new()),
448                reports,
449            }),
450            receiver,
451        )
452    }
453
454    fn lock(&self) -> std::sync::MutexGuard<'_, BTreeMap<String, DetachedEntry>> {
455        self.entries.lock().expect("detached registry mutex")
456    }
457
458    /// Hand the task loop one report. A send that fails means the loop is gone.
459    pub(crate) fn report(&self, report: DetachedReport) {
460        let _ = self.reports.send(report);
461    }
462
463    /// Record a demoted command spawned at `started`, whose process group is `pgid`, whose log is
464    /// at `output_path` and whose output is being written through `output`. Called before the
465    /// dispatch returns its handle, so the session-end sweep cannot miss work registered after it
466    /// looked.
467    pub(crate) fn register(
468        &self,
469        work: DetachedWork,
470        started: Instant,
471        pgid: i32,
472        output_path: String,
473        output: Arc<Mutex<LiveOutput>>,
474    ) {
475        let (phase, _) = watch::channel(Phase::Running);
476        self.lock().insert(
477            work.work_id.clone(),
478            DetachedEntry {
479                work,
480                started,
481                pgid,
482                output_path,
483                output,
484                leader_running: true,
485                stop_requested: false,
486                signals_sent: 0,
487                finished: None,
488                delivery: None,
489                phase,
490            },
491        );
492    }
493
494    /// The command's own process has exited and is about to be reaped: from here on its group is
495    /// never signalled. Called by the demoted thread after `waitid(WNOWAIT)` and before
496    /// `Child::wait`.
497    pub(crate) fn leader_exited(&self, work_id: &str) {
498        if let Some(entry) = self.lock().get_mut(work_id) {
499            entry.leader_running = false;
500            entry.phase.send_replace(Phase::LeaderExited);
501        }
502    }
503
504    /// Records the completion on its entry and sends it to the task loop.
505    ///
506    /// A command a `stop` reached has no resource limit attributed: the stop is why it ended.
507    ///
508    /// The channel is unbounded, so the blocking thread that calls this never waits and needs no
509    /// async context. A send that fails means the task loop is gone — the session is ending, and
510    /// the result has nowhere to be delivered.
511    pub(crate) fn complete(&self, mut completion: DetachedCompletion) {
512        {
513            let mut entries = self.lock();
514            if let Some(entry) = entries.get_mut(&completion.work_id) {
515                if entry.stop_requested {
516                    completion.resource_limit = None;
517                }
518                entry.leader_running = false;
519                entry.finished = Some(completion.clone());
520                entry.phase.send_replace(Phase::Finished);
521            }
522        }
523        self.report(DetachedReport::Completed(completion));
524    }
525
526    /// Every command demoted and not yet finished, oldest work id first.
527    pub(crate) fn outstanding(&self) -> Vec<DetachedWork> {
528        self.lock()
529            .values()
530            .filter(|entry| entry.finished.is_none())
531            .map(|entry| entry.work.clone())
532            .collect()
533    }
534
535    /// `work_id`'s state now, or `None` for a work id this session never issued.
536    ///
537    /// A finished state read here counts as the agent having read the exit: an unclaimed entry is
538    /// claimed for [`Delivery::BackgroundCommand`], so its completion is not also enqueued as a
539    /// task, and [`CommandSnapshot::delivered_now`] says this read made the claim. A running
540    /// entry, and one already claimed either way, claims nothing.
541    pub(crate) fn read(&self, work_id: &str) -> Option<CommandSnapshot> {
542        let mut entries = self.lock();
543        let entry = entries.get_mut(work_id)?;
544        let delivered_now = entry.finished.is_some() && entry.delivery.is_none();
545        if delivered_now {
546            entry.delivery = Some(Delivery::BackgroundCommand);
547        }
548        let state = match (&entry.finished, entry.stop_requested) {
549            (None, _) => CommandState::Running,
550            (Some(_), false) => CommandState::Exited,
551            (Some(_), true) => CommandState::Stopped,
552        };
553        let elapsed_ms = match &entry.finished {
554            Some(completion) => completion.duration_ms,
555            None => millis(entry.started.elapsed()),
556        };
557        let (output_bytes, tail) = {
558            let output = entry
559                .output
560                .lock()
561                .unwrap_or_else(std::sync::PoisonError::into_inner);
562            (output.section_bytes, output.tail.iter().copied().collect())
563        };
564        Some(CommandSnapshot {
565            work_id: entry.work.work_id.clone(),
566            state,
567            elapsed_ms,
568            finished: entry.finished.clone(),
569            output_path: entry.output_path.clone(),
570            output_bytes,
571            tail,
572            delivered_now,
573        })
574    }
575
576    /// Claims `work_id`'s completion for [`Delivery::Task`], under the same lock [`Self::read`]
577    /// claims under. `false` when a read already claimed it, so the task loop enqueues nothing and
578    /// writes nothing. A work id this registry does not hold has nothing to race and is `true`.
579    pub(crate) fn claim_for_task(&self, work_id: &str) -> bool {
580        let mut entries = self.lock();
581        let Some(entry) = entries.get_mut(work_id) else {
582            return true;
583        };
584        if entry.delivery.is_some() {
585            return false;
586        }
587        entry.delivery = Some(Delivery::Task);
588        true
589    }
590
591    /// Whether `background-command` has returned `work_id`'s finished state: its completion was
592    /// claimed for [`Delivery::BackgroundCommand`].
593    pub(crate) fn exit_reported(&self, work_id: &str) -> bool {
594        self.lock()
595            .get(work_id)
596            .is_some_and(|entry| entry.delivery == Some(Delivery::BackgroundCommand))
597    }
598
599    fn phase(&self, work_id: &str) -> Option<watch::Receiver<Phase>> {
600        self.lock()
601            .get(work_id)
602            .map(|entry| entry.phase.subscribe())
603    }
604
605    /// Sends `stop`'s `signal` to `work_id`'s process group if its leader is unreaped, and marks
606    /// the entry stop-requested. `true` when sent.
607    fn signal_stop(&self, work_id: &str, signal: libc::c_int) -> bool {
608        let mut entries = self.lock();
609        let Some(entry) = entries
610            .get_mut(work_id)
611            .filter(|entry| entry.leader_running)
612        else {
613            return false;
614        };
615        let sent = crate::formation_launch::signal_group(i64::from(entry.pgid), signal);
616        if sent {
617            entry.signals_sent += 1;
618            entry.stop_requested = true;
619        }
620        sent
621    }
622
623    /// `SIGKILL` to the process group of every command whose leader is unreaped. The session's
624    /// end calls this, so no demoted command outlives its session on a host with no cgroup
625    /// scope.
626    pub(crate) fn kill_running(&self) {
627        for entry in self.lock().values_mut() {
628            if entry.leader_running
629                && crate::formation_launch::signal_group(i64::from(entry.pgid), libc::SIGKILL)
630            {
631                entry.signals_sent += 1;
632            }
633        }
634    }
635
636    /// Waits until `work_id` finishes, `bound` passes or `cancel` is raised, whichever is first.
637    ///
638    /// Holds no thread while it waits, and dropping the future leaves nothing behind.
639    pub(crate) async fn wait(
640        &self,
641        work_id: &str,
642        bound: Duration,
643        cancel: Option<&crate::cancel::CancelSignal>,
644    ) -> WaitEnd {
645        let Some(mut phase) = self.phase(work_id) else {
646            return WaitEnd::Unknown;
647        };
648        let canceled = async {
649            match cancel {
650                Some(signal) => signal.canceled().await,
651                None => std::future::pending().await,
652            }
653        };
654        tokio::select! {
655            finished = phase.wait_for(|phase| *phase == Phase::Finished) => {
656                // The sender lives in the entry, which is never removed, so the wait cannot see
657                // a closed channel; a `false` here would mean the registry itself was dropped.
658                if finished.is_ok() { WaitEnd::Finished } else { WaitEnd::TimedOut }
659            }
660            () = tokio::time::sleep(bound) => WaitEnd::TimedOut,
661            () = canceled => WaitEnd::Canceled,
662        }
663    }
664
665    /// Stops `work_id`: `SIGTERM` to its process group, then `SIGKILL` if its leader has not
666    /// exited [`crate::background_command::STOP_TERM_GRACE`] later, then up to
667    /// [`crate::background_command::STOP_KILL_WAIT`] more for the completion. Returns once the
668    /// command has finished or that time is up, whichever is first; a command already finished
669    /// is sent nothing.
670    ///
671    /// `false` for a work id this session never issued.
672    pub(crate) async fn stop(&self, work_id: &str) -> bool {
673        let Some(mut phase) = self.phase(work_id) else {
674            return false;
675        };
676        if self.signal_stop(work_id, libc::SIGTERM) {
677            let exited = tokio::time::timeout(
678                crate::background_command::STOP_TERM_GRACE,
679                phase.wait_for(|phase| *phase >= Phase::LeaderExited),
680            )
681            .await;
682            if !matches!(exited, Ok(Ok(_))) {
683                self.signal_stop(work_id, libc::SIGKILL);
684            }
685        }
686        let _ = tokio::time::timeout(
687            crate::background_command::STOP_KILL_WAIT,
688            phase.wait_for(|phase| *phase == Phase::Finished),
689        )
690        .await;
691        true
692    }
693
694    /// Signals sent to `work_id`'s process group so far.
695    #[cfg(test)]
696    pub(crate) fn signals_sent(&self, work_id: &str) -> u32 {
697        self.lock()
698            .get(work_id)
699            .map_or(0, |entry| entry.signals_sent)
700    }
701}
702
703fn millis(duration: Duration) -> u64 {
704    duration.as_millis().try_into().unwrap_or(u64::MAX)
705}
706
707/// Kills the process group of every command the registry still runs when dropped, so a failing
708/// test leaves nothing behind.
709#[cfg(test)]
710pub(crate) struct KillRunningOnDrop(pub(crate) Arc<DetachedRegistry>);
711
712#[cfg(test)]
713impl Drop for KillRunningOnDrop {
714    fn drop(&mut self) {
715        self.0.kill_running();
716    }
717}
718
719/// Supplied by a dispatch that is allowed to demote.
720///
721/// `None` at a call site means the command runs to completion in the foreground. That is what
722/// keeps `plan.rs` and the script-capsule store state foreground-only: neither runs a task loop,
723/// so neither has anywhere to deliver a completion.
724pub(crate) struct DetachPolicy {
725    /// How long the command runs in the foreground before it is demoted: the declared
726    /// `lifecycle.shell_grace_secs`. `None` sets no deadline, so the command stays in the
727    /// foreground until it exits unless `abandoned` or `canceled` demotes it.
728    pub grace: Option<Duration>,
729    /// Whether the completion reaches the model as a later task, which only `task_acceptance:
730    /// queue` with `after_task: sleep` does. Decides what [`demotion_tool_result`] tells it.
731    pub delivered: bool,
732    pub registry: Arc<DetachedRegistry>,
733    /// The command text as the model wrote it, without the binary name — the same string a
734    /// foreground `shell` trace record carries. `run_shell` only sees the argv it was handed, so
735    /// the caller that knows what was asked for supplies it here.
736    pub command: String,
737    pub context_id: String,
738    /// The provenance of the task that started the command. The completion is stamped
739    /// `TaskProvenance::derive(TaskOrigin::Completion, Some(that trust))`, so untrust survives
740    /// the round trip instead of being reset by the runtime enqueuing its own task.
741    pub provenance: Option<TaskProvenance>,
742    /// Raised when whoever was waiting for the foreground result has gone away. The command is
743    /// then demoted at once, whether or not `grace` is set. `None` for every caller that
744    /// cannot go away mid-call; the process-transport tool bridge is the one that can.
745    pub abandoned: Option<AbandonSignal>,
746    /// The cancel of the task whose turn made the call. Raised before the spawn, the command is
747    /// not run; raised while it runs in the foreground, it is demoted at once, as `abandoned`
748    /// demotes it, and the cancel is claimed for [`crate::cancel::PHASE_SHELL`]. `None` for a
749    /// caller whose own wait answers the cancel: a plan step, and the process-transport bridge.
750    pub canceled: Option<CancelSignal>,
751}
752
753/// Set once by a caller that stopped waiting for a call's result.
754///
755/// Clones share one flag. Raising it never stops anything already running: a shell command still
756/// in the foreground reads it and demotes, which is the only effect it has.
757#[derive(Debug, Clone, Default)]
758pub(crate) struct AbandonSignal(Arc<AtomicBool>);
759
760impl AbandonSignal {
761    pub(crate) fn new() -> Self {
762        Self::default()
763    }
764
765    pub(crate) fn raise(&self) {
766        self.0.store(true, Ordering::SeqCst);
767    }
768
769    pub(crate) fn is_raised(&self) -> bool {
770        self.0.load(Ordering::SeqCst)
771    }
772}
773
774impl DetachPolicy {
775    /// The provenance the completion task carries.
776    pub(crate) fn completion_provenance(&self) -> TaskProvenance {
777        TaskProvenance::derive(
778            TaskOrigin::Completion,
779            self.provenance.map(|task| task.trust()),
780        )
781    }
782}
783
784// -- Work a clean exit discarded ---------------------------------------------
785
786/// What the teardown sweep knows about one discarded command.
787///
788/// The two arms are the two places a command can be caught by the sweep, and they are told apart
789/// because what is known differs: a command still running has nothing on disk and never will,
790/// while one that finished between the task loop's last read and the sweep has an exit code and a
791/// written output log that no task will ever carry back.
792#[derive(Debug, Clone)]
793pub(crate) enum AbandonedDisposition {
794    /// Running when the session ended, and killed with it. No exit code reaches any task. Its
795    /// log holds what it printed up to the kill; whether the `Exit code:` trailer lands depends
796    /// on its runtime thread reaping it before the process exits.
797    StillRunning {
798        /// From spawn to the sweep, foreground portion included.
799        running_ms: u64,
800    },
801    /// Finished during teardown, after the task loop stopped reading completions. Everything a
802    /// `shell_completed` would have carried exists; only the task that would have carried it does
803    /// not.
804    FinishedTooLate {
805        exit_code: i32,
806        /// From spawn to exit, foreground portion included.
807        duration_ms: u64,
808        /// As [`DetachedCompletion::output_path`], and on disk by the time this arm is built.
809        output_path: String,
810        output_bytes: u64,
811        resource_limit: Option<String>,
812        /// Set only when the wait itself failed, as on [`DetachedCompletion::error`]. Without it a
813        /// report can read `status: error` with an exit code of `0` and no reason for either.
814        wait_error: Option<String>,
815        /// [`DetachedCompletion::status`] of the completion this was built from.
816        status: &'static str,
817    },
818}
819
820/// One discarded command, as the operator report and the `shell_abandoned` record both read it.
821#[derive(Debug, Clone)]
822pub(crate) struct AbandonedWork {
823    pub work_id: String,
824    /// As [`DetachedWork::binary`].
825    pub binary: String,
826    /// As [`DetachedWork::command`] — the text the model wrote, which the operator needs to know
827    /// what was actually left running.
828    pub command: String,
829    pub disposition: AbandonedDisposition,
830}
831
832impl AbandonedWork {
833    /// How long the command ran, whichever arm it was caught in — the `running_ms` of its
834    /// `shell_abandoned` line.
835    pub(crate) fn running_ms(&self) -> u64 {
836        match &self.disposition {
837            AbandonedDisposition::StillRunning { running_ms } => *running_ms,
838            AbandonedDisposition::FinishedTooLate { duration_ms, .. } => *duration_ms,
839        }
840    }
841
842    /// The exit code, output path and byte count, or `None` for a command still running.
843    ///
844    /// The three travel together because they exist together: a command with an exit code has a
845    /// written log, and one without has neither.
846    pub(crate) fn recovered(&self) -> Option<(i32, &str, u64)> {
847        match &self.disposition {
848            AbandonedDisposition::StillRunning { .. } => None,
849            AbandonedDisposition::FinishedTooLate {
850                exit_code,
851                output_path,
852                output_bytes,
853                ..
854            } => Some((*exit_code, output_path.as_str(), *output_bytes)),
855        }
856    }
857}
858
859/// The grouped operator report for every command one session discarded, as it lands on stderr and
860/// in the records directory's `logs/bootstrap.log`. `records_root` is the session's records
861/// directory, which a still-running command's log path is named in.
862///
863/// One block for the whole session rather than a line per command: a session that discarded ten
864/// commands must state the condition once and then enumerate, or the condition is lost in the
865/// enumeration. Deliberately **not** [`LostReport::message_text`] — that text asserts no exit
866/// code was recorded and that whether the command finished is unknown, which is false here: this
867/// session's registry was alive, so the running time is known, and a command that finished during
868/// teardown has its exit code on disk.
869pub(crate) fn abandonment_report_text(
870    session_id: &str,
871    records_root: &crate::workdir_fs::WorkdirRoot,
872    abandoned: &[AbandonedWork],
873) -> String {
874    let count = abandoned.len();
875    let plural = if count == 1 { "command" } else { "commands" };
876    let mut text = format!(
877        "[capsule-runtime] {count} background shell {plural} discarded at session end.\n\n\
878         Session {session_id} ended while {count} demoted shell {plural} {} unaccounted for. \
879         Every process the session started was killed when it ended; what is known about each \
880         command is below.\n",
881        if count == 1 { "was" } else { "were" }
882    );
883    for work in abandoned {
884        text.push_str(&format!(
885            "\nwork_id: {}\nbinary: {}\ncommand: {}\n",
886            work.work_id, work.binary, work.command
887        ));
888        match &work.disposition {
889            AbandonedDisposition::StillRunning { running_ms } => {
890                text.push_str(&format!(
891                    "state: killed at session end after {running_ms} ms\n\
892                     result: none — it was killed before it finished, so no task carries an exit \
893                     code. What it printed before the kill is in {}.\n",
894                    output_path_for(records_root, &work.work_id).path
895                ));
896            }
897            AbandonedDisposition::FinishedTooLate {
898                exit_code,
899                duration_ms,
900                output_path,
901                output_bytes,
902                resource_limit,
903                wait_error,
904                status,
905            } => {
906                text.push_str(&format!(
907                    "state: finished during teardown after {duration_ms} ms\n\
908                     status: {status}\n\
909                     exit_code: {exit_code}\n"
910                ));
911                if let Some(limit) = resource_limit {
912                    text.push_str(&format!("resource_limit: {limit}\n"));
913                }
914                if let Some(error) = wait_error {
915                    text.push_str(&format!("wait_error: {error}\n"));
916                }
917                text.push_str(&format!(
918                    "output: {output_path} ({output_bytes} bytes)\n\
919                     result: on disk — it finished too late for any task to carry it back to the \
920                     agent.\n"
921                ));
922            }
923        }
924    }
925    text.push_str(
926        "\nA session's end kills every command it demoted and every process its shell calls \
927         started in the background. Declare lifecycle.task_acceptance: queue with \
928         lifecycle.after_task: sleep for a session that outlives its task and can be told the \
929         result instead.",
930    );
931    text
932}
933
934// -- Work a dead session left unaccounted ------------------------------------
935
936/// A demoted command whose session died before anything could be recorded about it.
937///
938/// Reconstructed from the prior session's `shell_detached` line, which is the only trace of it
939/// that survives: [`DetachedRegistry`] lives in process memory, and the `Exit code:` trailer of
940/// the output log is written by a runtime thread after the command exits, so a runtime killed
941/// with `SIGKILL` leaves a log with no exit code even for a command that ran to a clean exit.
942#[derive(Debug, Clone)]
943pub(crate) struct LostWork {
944    pub work_id: String,
945    /// As [`DetachedWork::binary`].
946    pub binary: String,
947    /// As [`DetachedWork::command`].
948    pub command: String,
949    /// The `shell_detached` line's own timestamp — the demotion instant.
950    pub detached_at_ms: u64,
951}
952
953/// Every unaccounted command of one prior session, reported as one task.
954///
955/// One report per resume rather than one per work id: enqueuing raises `pending_count` and so
956/// counts against `lifecycle.queue_depth`, and a session that lost ten commands must not cost ten
957/// pending slots to say so.
958#[derive(Debug, Clone)]
959pub(crate) struct LostReport {
960    /// The session that started the work, and whose `trace.jsonl` holds both the unmatched
961    /// `shell_detached` lines and the `shell_lost` lines that account for them.
962    pub started_in_session: String,
963    /// Non-empty by construction: a report with nothing in it is never built.
964    pub lost: Vec<LostWork>,
965    /// The conversation the resume runs under, so the report joins that thread.
966    pub context_id: String,
967    /// [`TaskOrigin::Completion`] carrying the lowest trust across [`Self::lost`] — one untrusted
968    /// command makes the whole report untrusted.
969    pub provenance: TaskProvenance,
970    /// The task this report is enqueued as. Minted before the `shell_lost` markers are appended,
971    /// because each marker names it as `reconciled_task_id`.
972    pub task_id: String,
973}
974
975impl LostReport {
976    /// The `IncomingTask.message_text` the agent reads: the work id and the demotion instant of
977    /// each lost command, and the statement that no exit code was recorded. The work id names the
978    /// command, which the tool call that started it holds.
979    ///
980    /// Shares no opening line with [`DetachedCompletion::message_text`]. A model that cannot tell
981    /// "it failed" from "nobody knows" retries, and the retry is the cost demotion exists to
982    /// remove. Names no output path, quotes no byte count and asserts no exit code: no exit code
983    /// exists, and the log the earlier session wrote stops wherever that session died.
984    pub(crate) fn message_text(&self) -> String {
985        let mut text = format!(
986            "Background shell commands from an earlier session were never accounted for.\n\
987             \n\
988             Session {} ended without recording what became of the commands below; they were \
989             running in the background at the time. No exit code was recorded for any of them, \
990             and whether each command finished at all is unknown.\n",
991            self.started_in_session
992        );
993        for work in &self.lost {
994            text.push_str(&format!(
995                "\nwork_id: {}\ndetached_at_ms: {}\n",
996                work.work_id, work.detached_at_ms
997            ));
998        }
999        text.push_str(
1000            "\nNone of these is known to have succeeded and none is known to have failed. Treat \
1001             each as unknown, and start the work again only if it still matters.",
1002        );
1003        text
1004    }
1005}
1006
1007/// What the task loop turns into a `completion`-origin task.
1008///
1009/// One enum rather than two enqueue paths: an authority reporting on work it started is the same
1010/// shape whether the work finished under this runtime or was left unaccounted by one that died.
1011#[derive(Debug, Clone)]
1012pub(crate) enum DetachedReport {
1013    Completed(DetachedCompletion),
1014    Lost(LostReport),
1015}
1016
1017#[cfg(test)]
1018mod tests {
1019    use super::*;
1020
1021    use std::{
1022        path::{Path, PathBuf},
1023        time::{Duration, Instant},
1024    };
1025
1026    use crate::{
1027        origin::TrustClass,
1028        sandbox::ShellEnforcement,
1029        shell::{
1030            run_shell,
1031            test_support::{process_dead_within, read_pid, KillPidFileOnDrop},
1032            ShellOutcome,
1033        },
1034        types::CapabilityPolicy,
1035    };
1036
1037    fn bash_policy() -> CapabilityPolicy {
1038        CapabilityPolicy {
1039            shell_allow: vec!["bash".to_string()],
1040            ..Default::default()
1041        }
1042    }
1043
1044    /// The records directory [`crate::sandbox::test_runtime_dir`] creates under `base`.
1045    fn records_dir(base: &Path) -> PathBuf {
1046        base.join(crate::records_dir::RECORDS_DIR_NAME)
1047    }
1048
1049    /// `run_shell` against `bash -c <script>` with a grace period, returning the outcome and the
1050    /// registry the completion (if any) will arrive on. The session's runtime directory roots,
1051    /// its records directory among them, are created under `runtime_base`.
1052    fn detached_run(
1053        workdir: &Path,
1054        runtime_base: &Path,
1055        script: &str,
1056        grace: impl Into<Option<Duration>>,
1057    ) -> (
1058        ShellOutcome,
1059        Arc<DetachedRegistry>,
1060        UnboundedReceiver<DetachedReport>,
1061    ) {
1062        detached_run_with(
1063            workdir,
1064            &ShellEnforcement::environment_only()
1065                .with_runtime_dir(crate::sandbox::test_runtime_dir(runtime_base), None),
1066            script,
1067            grace,
1068        )
1069    }
1070
1071    /// [`detached_run`] under `enforcement`.
1072    fn detached_run_with(
1073        workdir: &Path,
1074        enforcement: &ShellEnforcement,
1075        script: &str,
1076        grace: impl Into<Option<Duration>>,
1077    ) -> (
1078        ShellOutcome,
1079        Arc<DetachedRegistry>,
1080        UnboundedReceiver<DetachedReport>,
1081    ) {
1082        let (registry, receiver) = DetachedRegistry::new();
1083        let outcome = run_shell(
1084            "bash",
1085            &["-c", script],
1086            &[],
1087            &crate::workdir_fs::WorkdirRoot::open(workdir).unwrap(),
1088            &bash_policy(),
1089            enforcement,
1090            Some(DetachPolicy {
1091                grace: grace.into(),
1092                delivered: true,
1093                registry: Arc::clone(&registry),
1094                command: script.to_string(),
1095                context_id: "ctx_detached_tests".to_string(),
1096                provenance: Some(TaskProvenance::derive(TaskOrigin::User, None)),
1097                abandoned: None,
1098                canceled: None,
1099            }),
1100        )
1101        .expect("a declared binary runs");
1102        (outcome, registry, receiver)
1103    }
1104
1105    /// Block until the completion lands, so the test fails with a timeout rather than hanging.
1106    ///
1107    /// The channel carries every report the task loop enqueues, so a shell command's completion is
1108    /// taken off it by variant: anything else on this receiver means a delegation report reached a
1109    /// test that started no delegation.
1110    fn await_completion(receiver: &mut UnboundedReceiver<DetachedReport>) -> DetachedCompletion {
1111        let deadline = Instant::now() + Duration::from_secs(30);
1112        loop {
1113            match receiver.try_recv() {
1114                Ok(DetachedReport::Completed(completion)) => return completion,
1115                Ok(other) => panic!("a shell command's completion was expected; got {other:?}"),
1116                Err(tokio::sync::mpsc::error::TryRecvError::Empty) => {
1117                    assert!(
1118                        Instant::now() < deadline,
1119                        "timed out waiting for the detached completion"
1120                    );
1121                    std::thread::sleep(Duration::from_millis(25));
1122                }
1123                Err(error) => panic!("the completion channel closed early: {error}"),
1124            }
1125        }
1126    }
1127
1128    fn completion_provenance() -> TaskProvenance {
1129        TaskProvenance::derive(TaskOrigin::Completion, Some(TrustClass::Untrusted))
1130    }
1131
1132    /// Every completion an agent can be handed opens with a line no other one opens with, so a
1133    /// model can tell a delegation's outcome from a demoted command's without reading further.
1134    #[test]
1135    fn no_two_completions_share_an_opening_line() {
1136        let outcome = crate::delegation::DelegationOutcome {
1137            delegation_id: "dlg_0001".to_string(),
1138            capsule_name: "worker".to_string(),
1139            capsule_version: "0.1.0".to_string(),
1140            session_id: "ses_child".to_string(),
1141            status: crate::delegation::DelegationStatus::Ok,
1142            result_path: None,
1143            workdir: "/tmp/child".to_string(),
1144            duration_ms: 1,
1145            detail: None,
1146            reported_by: crate::delegation::Reporter::Launcher,
1147            delivered: true,
1148            delivery_error: None,
1149        };
1150        let completion = DetachedCompletion {
1151            work_id: "wrk_0001".to_string(),
1152            binary: "bash".to_string(),
1153            command: "sleep 3".to_string(),
1154            exit_code: 0,
1155            duration_ms: 3_000,
1156            exited_at_ms: 1_000,
1157            output_path: "/home/test/.murmur/records/work/ses_1/logs/wrk_0001.log".to_string(),
1158            output_bytes: 0,
1159            resource_limit: None,
1160            output_holders: crate::shell::OutputHolders::Closed,
1161            context_id: "ctx_1".to_string(),
1162            provenance: completion_provenance(),
1163            error: None,
1164        };
1165        let texts = [
1166            ("delegation outcome", outcome.message_text()),
1167            ("detached shell completion", completion.message_text()),
1168        ];
1169        for (index, (name, text)) in texts.iter().enumerate() {
1170            let opening = text.lines().next().unwrap_or_default();
1171            assert!(!opening.is_empty(), "{name} opens with nothing");
1172            for (other_name, other) in texts.iter().skip(index + 1) {
1173                assert_ne!(
1174                    opening,
1175                    other.lines().next().unwrap_or_default(),
1176                    "{name} and {other_name} open with the same line"
1177                );
1178            }
1179        }
1180    }
1181
1182    /// A demoted command's limit reaches the model in the same words a foreground call's does,
1183    /// without displacing the opening line or the closing pointer at the output file.
1184    #[test]
1185    fn a_completion_names_its_limit_in_the_shared_wording() {
1186        let completion = DetachedCompletion {
1187            work_id: "wrk_0001".to_string(),
1188            binary: "bash".to_string(),
1189            command: "make -j64".to_string(),
1190            exit_code: 1,
1191            duration_ms: 3_000,
1192            exited_at_ms: 1_000,
1193            output_path: "/home/test/.murmur/records/work/ses_1/logs/wrk_0001.log".to_string(),
1194            output_bytes: 0,
1195            resource_limit: Some("cgroup_pids_max".into()),
1196            output_holders: crate::shell::OutputHolders::Closed,
1197            context_id: "ctx_1".to_string(),
1198            provenance: completion_provenance(),
1199            error: None,
1200        };
1201        let text = completion.message_text();
1202        let expected = crate::resources::resource_limit_line("cgroup_pids_max");
1203
1204        assert!(
1205            text.lines().any(|line| line == expected),
1206            "no limit line in:\n{text}"
1207        );
1208        assert_eq!(
1209            text.lines().next(),
1210            Some("Background shell command finished.")
1211        );
1212        assert_eq!(completion.status(), "error");
1213        assert!(text.ends_with("are not reproduced here."), "{text}");
1214    }
1215
1216    /// A completion names its command by the work id alone: the tool call that started it holds
1217    /// the command, and the trace's `shell_completed` line keeps it.
1218    #[test]
1219    fn a_completion_names_the_work_id_and_not_the_command() {
1220        let completion = DetachedCompletion {
1221            work_id: "wrk_0001".to_string(),
1222            binary: "/usr/bin/bash".to_string(),
1223            command: "make -j64".to_string(),
1224            exit_code: 0,
1225            duration_ms: 3_000,
1226            exited_at_ms: 1_000,
1227            output_path: "/home/test/.murmur/records/work/ses_1/logs/wrk_0001.log".to_string(),
1228            output_bytes: 12,
1229            resource_limit: None,
1230            output_holders: crate::shell::OutputHolders::Closed,
1231            context_id: "ctx_1".to_string(),
1232            provenance: completion_provenance(),
1233            error: Some("the wait failed".to_string()),
1234        };
1235        assert_eq!(
1236            completion.message_text(),
1237            "Background shell command finished.\n\
1238             work_id: wrk_0001\n\
1239             status: error\n\
1240             exit_code: 0\n\
1241             duration_ms: 3000\n\
1242             output: /home/test/.murmur/records/work/ses_1/logs/wrk_0001.log (12 bytes)\n\
1243             wait_error: the wait failed\n\
1244             \n\
1245             The full stdout and stderr are in that file and are not reproduced here."
1246        );
1247    }
1248
1249    /// A lost-work report names each command by its work id and demotion instant; the binary
1250    /// and the command text stay in the `shell_detached` and `shell_lost` trace lines.
1251    #[test]
1252    fn a_lost_report_names_each_work_id_and_not_the_command() {
1253        let lost = |work_id: &str, command: &str, detached_at_ms| LostWork {
1254            work_id: work_id.to_string(),
1255            binary: "/usr/bin/bash".to_string(),
1256            command: command.to_string(),
1257            detached_at_ms,
1258        };
1259        let report = LostReport {
1260            started_in_session: "ses_prior".to_string(),
1261            lost: vec![
1262                lost("wrk_one", "sleep 60", 1750),
1263                lost("wrk_two", "make test", 2500),
1264            ],
1265            context_id: "ctx_1".to_string(),
1266            provenance: completion_provenance(),
1267            task_id: "tsk_1".to_string(),
1268        };
1269        let text = report.message_text();
1270        assert!(
1271            text.contains(
1272                "\nwork_id: wrk_one\ndetached_at_ms: 1750\n\nwork_id: wrk_two\ndetached_at_ms: 2500\n"
1273            ),
1274            "{text}"
1275        );
1276        assert!(text.starts_with(
1277            "Background shell commands from an earlier session were never accounted for.\n\n\
1278             Session ses_prior ended without recording what became of the commands below;"
1279        ));
1280        assert!(
1281            text.ends_with("start the work again only if it still matters."),
1282            "{text}"
1283        );
1284        for absent in [
1285            "binary:",
1286            "command:",
1287            "/usr/bin/bash",
1288            "sleep 60",
1289            "make test",
1290        ] {
1291            assert!(!text.contains(absent), "{absent} in:\n{text}");
1292        }
1293    }
1294
1295    /// A demoted command that exits while a process it started still holds its output completes
1296    /// anyway: the holder is killed, the completion says so, and the log has what was printed.
1297    #[test]
1298    fn a_demoted_command_completes_when_its_background_holders_are_killed() {
1299        let workdir = tempfile::tempdir().unwrap();
1300        let runtime = tempfile::tempdir().unwrap();
1301        let _sleeper = KillPidFileOnDrop(workdir.path().join("sleeper.pid"));
1302        let (outcome, _registry, mut receiver) = detached_run(
1303            workdir.path(),
1304            runtime.path(),
1305            "sleep 2; sleep 300 & echo $! > sleeper.pid; echo started",
1306            Duration::from_secs(1),
1307        );
1308        let ShellOutcome::Detached(info) = outcome else {
1309            panic!("a two-second command must not finish inside a one-second grace: {outcome:?}");
1310        };
1311
1312        let waiting = Instant::now();
1313        let completion = await_completion(&mut receiver);
1314        let waited = waiting.elapsed();
1315        assert!(
1316            waited < Duration::from_secs(15),
1317            "the completion took {waited:?}"
1318        );
1319        assert_eq!(completion.work_id, info.work_id);
1320        assert_eq!(completion.exit_code, 0);
1321        assert_eq!(
1322            completion.output_holders,
1323            crate::shell::OutputHolders::Killed
1324        );
1325        let note = crate::shell::OutputHolders::Killed.note().unwrap();
1326        let text = completion.message_text();
1327        assert!(text.lines().any(|line| line == note), "{text}");
1328        assert!(text.ends_with("are not reproduced here."), "{text}");
1329        let log = std::fs::read_to_string(&completion.output_path).unwrap();
1330        assert!(log.contains("started"), "{log}");
1331
1332        let sleeper = read_pid(&workdir.path().join("sleeper.pid"));
1333        assert!(
1334            process_dead_within(sleeper, Duration::from_secs(2)),
1335            "the background sleeper {sleeper} is still running"
1336        );
1337    }
1338
1339    /// The whole argument of demotion: the call returns long before the command does, and the
1340    /// result turns up afterwards with the output on disk rather than in hand.
1341    #[test]
1342    fn a_command_outrunning_the_grace_period_is_demoted() {
1343        let workdir = tempfile::tempdir().unwrap();
1344        let runtime = tempfile::tempdir().unwrap();
1345        let started = Instant::now();
1346        // The output word is spelled nowhere in the command, so finding it in the completion
1347        // can only mean the output leaked into the turn.
1348        let (outcome, registry, mut receiver) = detached_run(
1349            workdir.path(),
1350            runtime.path(),
1351            "sleep 3; printf 'fin%s' 'ished-marker'",
1352            Duration::from_secs(1),
1353        );
1354
1355        let info = match outcome {
1356            ShellOutcome::Detached(info) => info,
1357            ShellOutcome::Finished(result) => {
1358                panic!(
1359                    "a three-second command must not finish inside a one-second grace: {result:?}"
1360                )
1361            }
1362        };
1363        assert!(
1364            started.elapsed() < Duration::from_secs(3),
1365            "the call returned only after the command did"
1366        );
1367        assert!(
1368            info.work_id.starts_with(WORK_ID_PREFIX)
1369                && info.work_id[WORK_ID_PREFIX.len()..]
1370                    .chars()
1371                    .all(|c| c.is_ascii_hexdigit() && !c.is_ascii_uppercase()),
1372            "work id {} must match ^wrk_[0-9a-f]+$",
1373            info.work_id
1374        );
1375        assert_eq!(info.grace_ms, Some(1_000));
1376        assert_eq!(
1377            registry
1378                .outstanding()
1379                .iter()
1380                .map(|work| work.work_id.clone())
1381                .collect::<Vec<_>>(),
1382            vec![info.work_id.clone()],
1383            "the work is registered before the handle is returned"
1384        );
1385
1386        let completion = await_completion(&mut receiver);
1387        assert_eq!(completion.work_id, info.work_id);
1388        assert_eq!(completion.exit_code, 0);
1389        assert_eq!(completion.status(), "ok");
1390        let expected_path = records_dir(runtime.path())
1391            .join("logs")
1392            .join(format!("{}.log", info.work_id));
1393        assert!(expected_path.is_absolute());
1394        assert_eq!(
1395            completion.output_path,
1396            expected_path.to_string_lossy(),
1397            "the completion names <records dir>/logs/<work_id>.log by its absolute path"
1398        );
1399        assert_eq!(completion.provenance.origin(), TaskOrigin::Completion);
1400        assert_eq!(completion.provenance.trust(), TrustClass::Trusted);
1401        assert_eq!(completion.context_id, "ctx_detached_tests");
1402        assert!(
1403            registry.outstanding().is_empty(),
1404            "a completed command is no longer outstanding"
1405        );
1406
1407        let log = std::fs::read_to_string(&completion.output_path)
1408            .expect("the completion's output file exists");
1409        assert!(
1410            log.contains("finished-marker"),
1411            "the output is in the log: {log}"
1412        );
1413        assert_eq!(completion.output_bytes, log.len() as u64);
1414        let text = completion.message_text();
1415        assert!(
1416            !text.contains("finished-marker"),
1417            "the output never reaches the agent: {text}"
1418        );
1419        assert!(
1420            text.contains(&format!(
1421                "output: {} ({} bytes)",
1422                completion.output_path, completion.output_bytes
1423            )),
1424            "{text}"
1425        );
1426        assert!(!text.contains("in the capsule workdir"), "{text}");
1427        assert!(
1428            !workdir.path().join("logs").exists(),
1429            "nothing is written into the accessible workdir"
1430        );
1431    }
1432
1433    /// With no records directory there is nowhere to keep a demoted command's output, so a
1434    /// command that outruns its grace period runs to completion in the foreground instead.
1435    #[test]
1436    fn with_no_records_directory_a_slow_command_is_not_demoted() {
1437        let workdir = tempfile::tempdir().unwrap();
1438        let base = tempfile::tempdir().unwrap();
1439        let started = Instant::now();
1440        let (outcome, registry, mut receiver) = detached_run_with(
1441            workdir.path(),
1442            &ShellEnforcement::environment_only().with_runtime_dir(
1443                crate::runtime_dir::RuntimeDirRoots {
1444                    records: None,
1445                    ..crate::sandbox::test_runtime_dir(base.path())
1446                },
1447                None,
1448            ),
1449            "sleep 2; echo done",
1450            Duration::from_millis(200),
1451        );
1452
1453        let result = match outcome {
1454            ShellOutcome::Finished(result) => result,
1455            ShellOutcome::Detached(info) => {
1456                panic!(
1457                    "no records directory, yet the command was demoted as {}",
1458                    info.work_id
1459                )
1460            }
1461        };
1462        assert!(started.elapsed() >= Duration::from_secs(2));
1463        assert_eq!(result.stdout.trim(), "done");
1464        assert!(registry.outstanding().is_empty());
1465        assert!(matches!(
1466            receiver.try_recv(),
1467            Err(tokio::sync::mpsc::error::TryRecvError::Empty)
1468        ));
1469        assert!(!workdir.path().join("logs").exists());
1470    }
1471
1472    /// With no grace there is no clock: a command that runs for seconds stays in the foreground
1473    /// and returns its output to the call, and nothing is registered.
1474    #[test]
1475    fn with_no_grace_a_slow_command_finishes_in_the_foreground() {
1476        let workdir = tempfile::tempdir().unwrap();
1477        let runtime = tempfile::tempdir().unwrap();
1478        let started = Instant::now();
1479        let (outcome, registry, mut receiver) = detached_run(
1480            workdir.path(),
1481            runtime.path(),
1482            "sleep 3; echo finished",
1483            None,
1484        );
1485
1486        let result = match outcome {
1487            ShellOutcome::Finished(result) => result,
1488            ShellOutcome::Detached(info) => {
1489                panic!("no grace, yet the command was demoted as {}", info.work_id)
1490            }
1491        };
1492        assert!(started.elapsed() >= Duration::from_secs(3));
1493        assert_eq!(result.stdout.trim(), "finished");
1494        assert_eq!(result.exit_code, 0);
1495        assert!(registry.outstanding().is_empty());
1496        assert!(matches!(
1497            receiver.try_recv(),
1498            Err(tokio::sync::mpsc::error::TryRecvError::Empty)
1499        ));
1500    }
1501
1502    /// A grace of zero demotes at the first poll after the spawn.
1503    #[test]
1504    fn a_zero_grace_demotes_at_the_first_poll() {
1505        let workdir = tempfile::tempdir().unwrap();
1506        let runtime = tempfile::tempdir().unwrap();
1507        let started = Instant::now();
1508        let (outcome, registry, _receiver) = detached_run(
1509            workdir.path(),
1510            runtime.path(),
1511            "sleep 5",
1512            Some(Duration::ZERO),
1513        );
1514
1515        let ShellOutcome::Detached(info) = outcome else {
1516            panic!("a zero grace must demote a five-second command: {outcome:?}");
1517        };
1518        assert!(
1519            started.elapsed() < Duration::from_secs(1),
1520            "demotion took {:?}",
1521            started.elapsed()
1522        );
1523        assert_eq!(info.grace_ms, Some(0));
1524        registry.kill_running();
1525    }
1526
1527    /// A command that beats the grace period returns its result to the turn and registers nothing.
1528    #[test]
1529    fn a_fast_command_finishes_in_the_foreground() {
1530        let workdir = tempfile::tempdir().unwrap();
1531        let runtime = tempfile::tempdir().unwrap();
1532        let (outcome, registry, mut receiver) = detached_run(
1533            workdir.path(),
1534            runtime.path(),
1535            "echo hi",
1536            Duration::from_secs(10),
1537        );
1538
1539        let result = match outcome {
1540            ShellOutcome::Finished(result) => result,
1541            ShellOutcome::Detached(info) => {
1542                panic!("`echo hi` must not be demoted: {}", info.work_id)
1543            }
1544        };
1545        assert_eq!(result.stdout.trim(), "hi");
1546        assert_eq!(result.exit_code, 0);
1547        assert!(!result.truncated);
1548        assert!(result.full_output_path.is_none());
1549        assert!(registry.outstanding().is_empty());
1550        assert!(
1551            matches!(
1552                receiver.try_recv(),
1553                Err(tokio::sync::mpsc::error::TryRecvError::Empty)
1554            ),
1555            "a foreground command produces no completion"
1556        );
1557    }
1558
1559    /// A failure is a completion, told apart from success by a field.
1560    #[test]
1561    fn a_failing_detached_command_completes_with_its_exit_code() {
1562        let workdir = tempfile::tempdir().unwrap();
1563        let runtime = tempfile::tempdir().unwrap();
1564        let (outcome, _registry, mut receiver) = detached_run(
1565            workdir.path(),
1566            runtime.path(),
1567            "sleep 3; echo to-stderr >&2; exit 7",
1568            Duration::from_secs(1),
1569        );
1570        assert!(matches!(outcome, ShellOutcome::Detached(_)));
1571
1572        let completion = await_completion(&mut receiver);
1573        assert_eq!(completion.exit_code, 7);
1574        assert_eq!(completion.status(), "error");
1575        assert!(
1576            completion.message_text().contains("exit_code: 7"),
1577            "the message names the exit code: {}",
1578            completion.message_text()
1579        );
1580
1581        let log = std::fs::read_to_string(&completion.output_path).unwrap();
1582        assert!(log.starts_with("Command: bash -c "), "{log}");
1583        assert!(
1584            log.contains("\n\nto-stderr\n"),
1585            "stderr is in the output section: {log}"
1586        );
1587        assert!(log.ends_with("\n\nExit code: 7\n"), "{log}");
1588
1589        let (outcome, _registry, mut receiver) = detached_run(
1590            workdir.path(),
1591            runtime.path(),
1592            "sleep 3; exit 0",
1593            Duration::from_secs(1),
1594        );
1595        assert!(matches!(outcome, ShellOutcome::Detached(_)));
1596        assert_eq!(await_completion(&mut receiver).status(), "ok");
1597    }
1598
1599    /// The demotion text names the work id, names the tool that takes it only when the session
1600    /// offers that tool, says what becomes of the command at session end, and stays small for
1601    /// either lifecycle; only a lifecycle that delivers completions mentions the separate task.
1602    #[test]
1603    fn the_demotion_result_names_the_tool_and_stays_small() {
1604        for (delivered, tool_offered) in
1605            [(true, true), (false, true), (true, false), (false, false)]
1606        {
1607            let result = demotion_tool_result("wrk_0a1b", delivered, tool_offered);
1608            let data = result.data.as_deref().unwrap();
1609            assert!(data.len() < 400, "{} bytes: {data}", data.len());
1610            assert!(data.contains("wrk_0a1b"), "{data}");
1611            assert_eq!(data.contains("background-command"), tool_offered, "{data}");
1612            assert_eq!(data.contains(" tool"), tool_offered, "{data}");
1613            assert!(data.contains("is killed"), "{data}");
1614            for retired in [concat!("nothing to ", "poll"), concat!("no way ", "to ask")] {
1615                assert!(!data.contains(retired), "{retired}: {data}");
1616            }
1617            assert_eq!(data.contains("separate task"), delivered, "{data}");
1618            assert_eq!(
1619                result.summary.as_deref(),
1620                Some("Command still running in the background as wrk_0a1b.")
1621            );
1622            assert_eq!(
1623                result.metadata,
1624                vec![("work_id".to_string(), "wrk_0a1b".to_string())]
1625            );
1626        }
1627        assert_eq!(
1628            demotion_tool_result("wrk_1", false, true).data.as_deref(),
1629            Some(
1630                "The command is still running and was moved to the background as wrk_1. The \
1631                 background-command tool reports on it, waits for it or stops it by that id. A \
1632                 command still running when the session ends is killed."
1633            )
1634        );
1635        assert_eq!(
1636            demotion_tool_result("wrk_1", true, true).data.as_deref(),
1637            Some(
1638                "The command is still running and was moved to the background as wrk_1. The \
1639                 background-command tool reports on it, waits for it or stops it by that id. A \
1640                 command still running when the session ends is killed. If it exits before \
1641                 background-command has reported its exit, its result also arrives later as a \
1642                 separate task."
1643            )
1644        );
1645        assert_eq!(
1646            demotion_tool_result("wrk_1", false, false).data.as_deref(),
1647            Some(
1648                "The command is still running and was moved to the background as wrk_1. A \
1649                 command still running when the session ends is killed."
1650            )
1651        );
1652        assert_eq!(
1653            demotion_tool_result("wrk_1", true, false).data.as_deref(),
1654            Some(
1655                "The command is still running and was moved to the background as wrk_1. A \
1656                 command still running when the session ends is killed. When it exits, its \
1657                 result arrives later as a separate task."
1658            )
1659        );
1660    }
1661
1662    // ── background-command: status, wait, stop ──────────────────────────────
1663
1664    fn demoted(outcome: ShellOutcome) -> DetachedDispatchInfo {
1665        match outcome {
1666            ShellOutcome::Detached(info) => info,
1667            ShellOutcome::Finished(result) => {
1668                panic!("the command finished inside its grace period: {result:?}")
1669            }
1670        }
1671    }
1672
1673    /// The command's state now, and the text `background-command` renders for it.
1674    fn read_text(
1675        registry: &DetachedRegistry,
1676        work_id: &str,
1677        waited: Option<Duration>,
1678    ) -> (CommandSnapshot, ToolResult) {
1679        let snapshot = registry.read(work_id).expect("the work id was issued");
1680        let (result, _) = crate::background_command::render(&snapshot, waited);
1681        (snapshot, result)
1682    }
1683
1684    fn log_of(snapshot: &CommandSnapshot) -> String {
1685        std::fs::read_to_string(&snapshot.output_path).expect("the log exists while it runs")
1686    }
1687
1688    /// Output printed after demotion, on both streams, is in the status and already in the log
1689    /// while the command runs; the trailer lands once it ends.
1690    #[tokio::test]
1691    async fn status_shows_output_so_far_while_the_command_runs() {
1692        let workdir = tempfile::tempdir().unwrap();
1693        let runtime = tempfile::tempdir().unwrap();
1694        let started = Instant::now();
1695        let (outcome, registry, _receiver) = detached_run(
1696            workdir.path(),
1697            runtime.path(),
1698            "echo first; sleep 2; echo second >&2; sleep 30",
1699            Duration::from_secs(1),
1700        );
1701        let _guard = KillRunningOnDrop(Arc::clone(&registry));
1702        let info = demoted(outcome);
1703
1704        tokio::time::sleep(Duration::from_millis(2_500).saturating_sub(started.elapsed())).await;
1705        let (snapshot, result) = read_text(&registry, &info.work_id, None);
1706        let data = result.data.unwrap();
1707        assert_eq!(snapshot.state, CommandState::Running, "{data}");
1708        assert!(data.contains("state: running\n"), "{data}");
1709        assert!(data.contains("output_shown: all\n"), "{data}");
1710        assert!(data.ends_with("\n\nfirst\nsecond\n"), "{data}");
1711        let log = log_of(&snapshot);
1712        assert!(log.contains("first") && log.contains("second"), "{log}");
1713        assert!(!log.contains("Exit code:"), "{log}");
1714
1715        assert!(registry.stop(&info.work_id).await);
1716        let (snapshot, _) = read_text(&registry, &info.work_id, None);
1717        assert_eq!(snapshot.state, CommandState::Stopped);
1718        let log = log_of(&snapshot);
1719        assert!(log.contains("\n\nExit code: "), "{log}");
1720    }
1721
1722    /// Past 16 KiB the status shows exactly the last 16384 output bytes and says so, while the
1723    /// log holds every byte.
1724    #[tokio::test]
1725    async fn status_shows_the_last_16_kib_and_the_log_holds_everything() {
1726        let workdir = tempfile::tempdir().unwrap();
1727        let runtime = tempfile::tempdir().unwrap();
1728        let (outcome, registry, _receiver) = detached_run(
1729            workdir.path(),
1730            runtime.path(),
1731            "sleep 1.5; head -c 50000 /dev/zero | tr '\\0' a; echo; echo TAILMARK; sleep 30",
1732            Duration::from_secs(1),
1733        );
1734        let _guard = KillRunningOnDrop(Arc::clone(&registry));
1735        let info = demoted(outcome);
1736
1737        let expected_bytes = 50_000 + "\nTAILMARK\n".len() as u64;
1738        let deadline = Instant::now() + Duration::from_secs(15);
1739        let (snapshot, result) = loop {
1740            let (snapshot, result) = read_text(&registry, &info.work_id, None);
1741            if snapshot.output_bytes >= expected_bytes {
1742                break (snapshot, result);
1743            }
1744            assert!(
1745                Instant::now() < deadline,
1746                "only {} bytes",
1747                snapshot.output_bytes
1748            );
1749            tokio::time::sleep(Duration::from_millis(50)).await;
1750        };
1751        assert_eq!(snapshot.output_bytes, expected_bytes);
1752        assert!(result.truncated);
1753        let data = result.data.unwrap();
1754        assert!(data.contains("output_bytes: 50010\n"), "{}", &data[..300]);
1755        assert!(
1756            data.contains("output_shown: last 16384 bytes\n\n"),
1757            "{}",
1758            &data[..300]
1759        );
1760        let shown = data.split_once("\n\n").unwrap().1;
1761        let mut expected = "a".repeat(16_384 - "\nTAILMARK\n".len());
1762        expected.push_str("\nTAILMARK\n");
1763        assert_eq!(shown.len(), 16_384);
1764        assert_eq!(shown, expected);
1765        let log = log_of(&snapshot);
1766        assert!(
1767            log.contains(&format!("\n\n{}\nTAILMARK\n", "a".repeat(50_000))),
1768            "the log holds all 50000 bytes"
1769        );
1770
1771        assert!(registry.stop(&info.work_id).await);
1772        let log = log_of(&registry.read(&info.work_id).unwrap());
1773        assert!(
1774            log.contains("TAILMARK\n\n\nExit code: "),
1775            "{}",
1776            &log[log.len() - 40..]
1777        );
1778    }
1779
1780    #[tokio::test]
1781    async fn wait_returns_when_the_command_exits() {
1782        let workdir = tempfile::tempdir().unwrap();
1783        let runtime = tempfile::tempdir().unwrap();
1784        let (outcome, registry, _receiver) = detached_run(
1785            workdir.path(),
1786            runtime.path(),
1787            "sleep 3; echo done; exit 7",
1788            Duration::from_secs(1),
1789        );
1790        let _guard = KillRunningOnDrop(Arc::clone(&registry));
1791        let info = demoted(outcome);
1792
1793        let waiting = Instant::now();
1794        let end = registry
1795            .wait(
1796                &info.work_id,
1797                crate::background_command::effective_wait(Some(30)),
1798                None,
1799            )
1800            .await;
1801        let waited = waiting.elapsed();
1802        assert_eq!(end, WaitEnd::Finished);
1803        assert!(waited < Duration::from_secs(6), "the wait took {waited:?}");
1804        let (snapshot, result) = read_text(&registry, &info.work_id, Some(waited));
1805        let data = result.data.unwrap();
1806        assert_eq!(snapshot.state, CommandState::Exited);
1807        for line in ["state: exited\n", "exit_code: 7\n", "status: error\n"] {
1808            assert!(data.contains(line), "{line}: {data}");
1809        }
1810        assert!(data.ends_with("\n\ndone\n"), "{data}");
1811        assert!(registry.exit_reported(&info.work_id));
1812    }
1813
1814    // ── delivery: one claim per completion ─────────────────────────────────────
1815
1816    /// A registry holding `work_id`, registered with no process behind it: these cases complete it
1817    /// by hand and never signal its group.
1818    fn registry_holding(work_id: &str) -> Arc<DetachedRegistry> {
1819        let (registry, _receiver) = DetachedRegistry::new();
1820        registry.register(
1821            DetachedWork {
1822                work_id: work_id.to_string(),
1823                binary: "/usr/bin/bash".to_string(),
1824                command: "sleep 3".to_string(),
1825                started_at_ms: 1_000,
1826            },
1827            Instant::now(),
1828            0,
1829            format!("/records/logs/{work_id}.log"),
1830            Arc::new(Mutex::new(LiveOutput {
1831                file: None,
1832                tail: VecDeque::new(),
1833                section_bytes: 0,
1834                write_error: None,
1835            })),
1836        );
1837        registry
1838    }
1839
1840    fn completion_of(work_id: &str) -> DetachedCompletion {
1841        DetachedCompletion {
1842            work_id: work_id.to_string(),
1843            binary: "/usr/bin/bash".to_string(),
1844            command: "sleep 3".to_string(),
1845            exit_code: 0,
1846            duration_ms: 3_000,
1847            exited_at_ms: 4_000,
1848            output_path: format!("/records/logs/{work_id}.log"),
1849            output_bytes: 0,
1850            resource_limit: None,
1851            output_holders: crate::shell::OutputHolders::Closed,
1852            context_id: "ctx_1".to_string(),
1853            provenance: completion_provenance(),
1854            error: None,
1855        }
1856    }
1857
1858    /// The first read of a finished command claims it for `background-command`: that read alone
1859    /// says so, and the task loop's later claim fails, so the completion is neither enqueued nor
1860    /// recorded twice.
1861    #[test]
1862    fn a_read_claims_a_finished_command_before_the_task_loop_does() {
1863        let registry = registry_holding("wrk_read");
1864        registry.complete(completion_of("wrk_read"));
1865
1866        let first = registry.read("wrk_read").unwrap();
1867        assert_eq!(first.state, CommandState::Exited);
1868        assert!(first.delivered_now, "the first read of the exit claims it");
1869        assert!(
1870            !registry.read("wrk_read").unwrap().delivered_now,
1871            "a second read claims nothing"
1872        );
1873        assert!(registry.exit_reported("wrk_read"));
1874        assert!(
1875            !registry.claim_for_task("wrk_read"),
1876            "the task loop finds the completion already delivered"
1877        );
1878    }
1879
1880    /// The task loop claiming first leaves nothing for a later read to deliver.
1881    #[test]
1882    fn the_task_loop_claims_a_completion_no_read_has_delivered() {
1883        let registry = registry_holding("wrk_task");
1884        registry.complete(completion_of("wrk_task"));
1885
1886        assert!(registry.claim_for_task("wrk_task"));
1887        assert!(!registry.claim_for_task("wrk_task"), "claimed once");
1888        let read = registry.read("wrk_task").unwrap();
1889        assert_eq!(read.state, CommandState::Exited);
1890        assert!(
1891            !read.delivered_now,
1892            "the queued task delivers it, not the read"
1893        );
1894        assert!(
1895            !registry.exit_reported("wrk_task"),
1896            "a task delivery is not a background-command one"
1897        );
1898    }
1899
1900    /// A running command has no completion to claim, so reading it leaves both paths open.
1901    #[test]
1902    fn a_read_of_a_running_command_claims_nothing() {
1903        let registry = registry_holding("wrk_running");
1904        let read = registry.read("wrk_running").unwrap();
1905        assert_eq!(read.state, CommandState::Running);
1906        assert!(!read.delivered_now);
1907        assert!(!registry.exit_reported("wrk_running"));
1908
1909        registry.complete(completion_of("wrk_running"));
1910        assert!(registry.read("wrk_running").unwrap().delivered_now);
1911    }
1912
1913    /// `exited_at_ms` is when the command's wait returned, stamped by its own thread before the
1914    /// completion is sent, not when anything later read it.
1915    #[test]
1916    fn exited_at_ms_is_stamped_at_the_exit_not_at_the_read() {
1917        let workdir = tempfile::tempdir().unwrap();
1918        let runtime = tempfile::tempdir().unwrap();
1919        let before = crate::trace::timestamp_ms();
1920        let (outcome, registry, mut receiver) = detached_run(
1921            workdir.path(),
1922            runtime.path(),
1923            "sleep 2; exit 3",
1924            Duration::from_millis(500),
1925        );
1926        let _guard = KillRunningOnDrop(Arc::clone(&registry));
1927        let info = demoted(outcome);
1928
1929        let completion = await_completion(&mut receiver);
1930        let received = crate::trace::timestamp_ms();
1931        assert!(
1932            completion.exited_at_ms >= before + 2_000 && completion.exited_at_ms <= received,
1933            "exited at {} for a command started after {before} and received at {received}",
1934            completion.exited_at_ms
1935        );
1936
1937        std::thread::sleep(Duration::from_millis(400));
1938        let read = registry.read(&info.work_id).unwrap();
1939        assert!(read.delivered_now);
1940        assert_eq!(
1941            read.finished.unwrap().exited_at_ms,
1942            completion.exited_at_ms,
1943            "the read hands back the exit time the command's thread stamped"
1944        );
1945    }
1946
1947    #[tokio::test]
1948    async fn wait_returns_at_its_bound_with_the_command_still_running() {
1949        let workdir = tempfile::tempdir().unwrap();
1950        let runtime = tempfile::tempdir().unwrap();
1951        let (outcome, registry, _receiver) = detached_run(
1952            workdir.path(),
1953            runtime.path(),
1954            "sleep 60",
1955            Duration::from_secs(1),
1956        );
1957        let _guard = KillRunningOnDrop(Arc::clone(&registry));
1958        let info = demoted(outcome);
1959
1960        let waiting = Instant::now();
1961        let end = registry
1962            .wait(
1963                &info.work_id,
1964                crate::background_command::effective_wait(Some(1)),
1965                None,
1966            )
1967            .await;
1968        let waited = waiting.elapsed();
1969        assert_eq!(end, WaitEnd::TimedOut);
1970        assert!(
1971            waited >= Duration::from_secs(1) && waited < Duration::from_secs(3),
1972            "the wait took {waited:?}"
1973        );
1974        let (snapshot, result) = read_text(&registry, &info.work_id, Some(waited));
1975        let data = result.data.unwrap();
1976        assert_eq!(snapshot.state, CommandState::Running);
1977        assert!(data.contains("waited_secs: 1\n"), "{data}");
1978        assert!(!data.contains("exit_code"), "{data}");
1979        assert!(!registry.exit_reported(&info.work_id));
1980    }
1981
1982    /// `stop` takes the command and the process it started in its group, and the command reads
1983    /// `stopped` with the exit code the signal gave it.
1984    #[tokio::test]
1985    async fn stop_ends_the_command_and_its_children() {
1986        let workdir = tempfile::tempdir().unwrap();
1987        let runtime = tempfile::tempdir().unwrap();
1988        let _leader = KillPidFileOnDrop(workdir.path().join("leader.pid"));
1989        let _child = KillPidFileOnDrop(workdir.path().join("child.pid"));
1990        let (outcome, registry, _receiver) = detached_run(
1991            workdir.path(),
1992            runtime.path(),
1993            "echo $$ > leader.pid; sleep 300 > /dev/null 2>&1 & echo $! > child.pid; sleep 300",
1994            Duration::from_secs(1),
1995        );
1996        let _guard = KillRunningOnDrop(Arc::clone(&registry));
1997        let info = demoted(outcome);
1998
1999        let stopping = Instant::now();
2000        assert!(registry.stop(&info.work_id).await);
2001        let took = stopping.elapsed();
2002        assert!(took < Duration::from_secs(5), "the stop took {took:?}");
2003        let (snapshot, result) = read_text(&registry, &info.work_id, None);
2004        let data = result.data.unwrap();
2005        assert_eq!(snapshot.state, CommandState::Stopped, "{data}");
2006        let exit_code = snapshot.finished.as_ref().unwrap().exit_code;
2007        assert!([143, 137].contains(&exit_code), "{data}");
2008        assert!(data.contains("state: stopped\n"), "{data}");
2009        assert_eq!(snapshot.finished.unwrap().resource_limit, None);
2010        for file in ["leader.pid", "child.pid"] {
2011            let pid = read_pid(&workdir.path().join(file));
2012            assert!(
2013                process_dead_within(pid, Duration::from_secs(2)),
2014                "{file}'s process {pid} is still running"
2015            );
2016        }
2017    }
2018
2019    /// A command that ignores `SIGTERM` is killed with `SIGKILL` once the grace has passed.
2020    #[tokio::test]
2021    async fn stop_escalates_to_sigkill_when_sigterm_is_ignored() {
2022        let workdir = tempfile::tempdir().unwrap();
2023        let runtime = tempfile::tempdir().unwrap();
2024        let _leader = KillPidFileOnDrop(workdir.path().join("leader.pid"));
2025        let (outcome, registry, _receiver) = detached_run(
2026            workdir.path(),
2027            runtime.path(),
2028            "echo $$ > leader.pid; trap '' TERM; while :; do sleep 1; done",
2029            Duration::from_secs(1),
2030        );
2031        let _guard = KillRunningOnDrop(Arc::clone(&registry));
2032        let info = demoted(outcome);
2033
2034        let stopping = Instant::now();
2035        assert!(registry.stop(&info.work_id).await);
2036        let took = stopping.elapsed();
2037        assert!(took < Duration::from_secs(5), "the stop took {took:?}");
2038        assert!(
2039            took >= crate::background_command::STOP_TERM_GRACE,
2040            "{took:?}"
2041        );
2042        let (snapshot, result) = read_text(&registry, &info.work_id, None);
2043        assert_eq!(snapshot.state, CommandState::Stopped, "{:?}", result.data);
2044        assert_eq!(snapshot.finished.unwrap().exit_code, 137);
2045        assert_eq!(registry.signals_sent(&info.work_id), 2);
2046        let pid = read_pid(&workdir.path().join("leader.pid"));
2047        assert!(
2048            process_dead_within(pid, Duration::from_secs(2)),
2049            "{pid} still runs"
2050        );
2051    }
2052
2053    /// A command that already exited is reported as it is, and nothing is signalled.
2054    #[tokio::test]
2055    async fn stop_on_a_finished_command_reports_it_unchanged() {
2056        let workdir = tempfile::tempdir().unwrap();
2057        let runtime = tempfile::tempdir().unwrap();
2058        let (outcome, registry, mut receiver) = detached_run(
2059            workdir.path(),
2060            runtime.path(),
2061            "sleep 1.5; exit 0",
2062            Duration::from_secs(1),
2063        );
2064        let info = demoted(outcome);
2065        await_completion(&mut receiver);
2066
2067        assert!(registry.stop(&info.work_id).await);
2068        let (snapshot, result) = read_text(&registry, &info.work_id, None);
2069        let data = result.data.unwrap();
2070        assert_eq!(snapshot.state, CommandState::Exited, "{data}");
2071        assert!(data.contains("exit_code: 0\nstatus: ok\n"), "{data}");
2072        assert_eq!(registry.signals_sent(&info.work_id), 0);
2073        assert!(
2074            !registry.stop(&new_work_id()).await,
2075            "an unknown id is not stopped"
2076        );
2077    }
2078
2079    /// With no cgroup scope, the registry's own kill is what ends a demoted command at session
2080    /// end, the process it started in its group included.
2081    #[test]
2082    fn kill_running_leaves_nothing_without_a_cgroup_scope() {
2083        let workdir = tempfile::tempdir().unwrap();
2084        let runtime = tempfile::tempdir().unwrap();
2085        let _leader = KillPidFileOnDrop(workdir.path().join("leader.pid"));
2086        let _child = KillPidFileOnDrop(workdir.path().join("child.pid"));
2087        let enforcement = ShellEnforcement::environment_only()
2088            .with_runtime_dir(crate::sandbox::test_runtime_dir(runtime.path()), None);
2089        assert!(enforcement.cgroup_scope.is_none());
2090        let (outcome, registry, _receiver) = detached_run_with(
2091            workdir.path(),
2092            &enforcement,
2093            "echo $$ > leader.pid; sleep 300 > /dev/null 2>&1 & echo $! > child.pid; sleep 300",
2094            Duration::from_secs(1),
2095        );
2096        let info = demoted(outcome);
2097        assert_eq!(registry.outstanding().len(), 1);
2098
2099        registry.kill_running();
2100        for file in ["leader.pid", "child.pid"] {
2101            let pid = read_pid(&workdir.path().join(file));
2102            assert!(
2103                process_dead_within(pid, Duration::from_secs(2)),
2104                "{file}'s process {pid} outlived kill_running"
2105            );
2106        }
2107        assert_eq!(registry.signals_sent(&info.work_id), 1);
2108    }
2109
2110    /// No input can make the demotion text grow: two work ids of equal length cost the same, and
2111    /// the cost is small.
2112    #[test]
2113    fn the_demotion_result_is_a_constant_size() {
2114        for delivered in [true, false] {
2115            for tool_offered in [true, false] {
2116                the_demotion_result_is_a_constant_size_when(delivered, tool_offered);
2117            }
2118        }
2119    }
2120
2121    fn the_demotion_result_is_a_constant_size_when(delivered: bool, tool_offered: bool) {
2122        let reduce = |work_id: &str| {
2123            let result = demotion_tool_result(work_id, delivered, tool_offered);
2124            result
2125                .data
2126                .or(result.summary)
2127                .unwrap_or_else(|| "tool returned no data".to_string())
2128        };
2129        let first = reduce(&new_work_id());
2130        let second = reduce(&new_work_id());
2131
2132        assert_eq!(
2133            first.len(),
2134            second.len(),
2135            "two work ids of equal length must produce texts of equal size"
2136        );
2137        // Not token equality: `cl100k_base` splits one random hex id into a different number of
2138        // pieces than another of the same length, which says nothing about this text. The claim
2139        // that matters is that the cost is bounded and no input moves it.
2140        for text in [&first, &second] {
2141            let tokens = crate::agent::count_tokens(text);
2142            assert!(
2143                tokens < 120,
2144                "the demotion result costs {tokens} tokens, over the 120-token ceiling"
2145            );
2146        }
2147        assert!(
2148            !first.contains("logs/"),
2149            "the demotion result names no path: {first}"
2150        );
2151    }
2152
2153    // ── The operator's abandonment report ────────────────────────────────────
2154
2155    fn still_running(work_id: &str, running_ms: u64) -> AbandonedWork {
2156        AbandonedWork {
2157            work_id: work_id.to_string(),
2158            binary: "/usr/bin/bash".to_string(),
2159            command: "sleep 45; echo done".to_string(),
2160            disposition: AbandonedDisposition::StillRunning { running_ms },
2161        }
2162    }
2163
2164    /// A records directory for the report tests, which name paths in it and write nothing.
2165    fn report_records() -> (tempfile::TempDir, crate::workdir_fs::WorkdirRoot) {
2166        let dir = tempfile::tempdir().unwrap();
2167        let root = crate::workdir_fs::WorkdirRoot::open(dir.path()).unwrap();
2168        (dir, root)
2169    }
2170
2171    fn finished_too_late(
2172        records_root: &crate::workdir_fs::WorkdirRoot,
2173        work_id: &str,
2174    ) -> AbandonedWork {
2175        AbandonedWork {
2176            work_id: work_id.to_string(),
2177            binary: "/usr/bin/bash".to_string(),
2178            command: "sleep 2; echo done".to_string(),
2179            disposition: AbandonedDisposition::FinishedTooLate {
2180                exit_code: 0,
2181                duration_ms: 2_014,
2182                output_path: output_path_for(records_root, work_id).path,
2183                output_bytes: 91,
2184                resource_limit: None,
2185                wait_error: None,
2186                status: "ok",
2187            },
2188        }
2189    }
2190
2191    /// A command still running is reported with the four things that are known about it and as
2192    /// killed, which the session's end did to it, and the report names the log that holds what
2193    /// it printed.
2194    #[test]
2195    fn a_still_running_command_is_reported_as_killed_with_what_is_known() {
2196        let (records, records_root) = report_records();
2197        let text = abandonment_report_text(
2198            "ses_abc",
2199            &records_root,
2200            &[still_running("wrk_0a1b", 45_012)],
2201        );
2202
2203        assert!(
2204            text.contains("1 background shell command discarded"),
2205            "{text}"
2206        );
2207        assert!(text.contains("Session ses_abc"), "{text}");
2208        assert!(text.contains("work_id: wrk_0a1b"), "{text}");
2209        assert!(text.contains("binary: /usr/bin/bash"), "{text}");
2210        assert!(text.contains("command: sleep 45; echo done"), "{text}");
2211        assert!(
2212            text.contains("state: killed at session end after 45012 ms"),
2213            "{text}"
2214        );
2215        let path = records.path().join("logs/wrk_0a1b.log");
2216        assert!(
2217            text.contains(&format!("before the kill is in {}.", path.display())),
2218            "the report names the log by its absolute path: {text}"
2219        );
2220        assert!(!text.contains("exit_code:"), "no exit code exists: {text}");
2221        for retired in [
2222            "nothing was killed",
2223            "Nothing was waited for",
2224            "keeps running",
2225        ] {
2226            assert!(
2227                !text.contains(retired),
2228                "the session's end kills what it started, so the report must not say {retired:?}: \
2229                 {text}"
2230            );
2231        }
2232    }
2233
2234    /// The `FinishedTooLate` arm names the exit code, the status, the duration and the real
2235    /// output file, rather than being flattened into "still running, result lost". This is the
2236    /// fidelity a clean exit has and a killed runtime does not.
2237    #[test]
2238    fn a_command_that_finished_during_teardown_is_reported_with_its_result() {
2239        let (records, records_root) = report_records();
2240        let text = abandonment_report_text(
2241            "ses_abc",
2242            &records_root,
2243            &[finished_too_late(&records_root, "wrk_0c2d")],
2244        );
2245
2246        assert!(
2247            text.contains("state: finished during teardown after 2014 ms"),
2248            "{text}"
2249        );
2250        assert!(text.contains("status: ok"), "{text}");
2251        assert!(text.contains("exit_code: 0"), "{text}");
2252        let path = records.path().join("logs/wrk_0c2d.log");
2253        assert!(
2254            text.contains(&format!("output: {} (91 bytes)\n", path.display())),
2255            "{text}"
2256        );
2257        assert!(!text.contains("in the capsule workdir"), "{text}");
2258        assert!(!text.contains("killed at session end"), "{text}");
2259    }
2260
2261    /// One block for the session, then one entry per command: a session that discarded several
2262    /// states the condition once and enumerates below it.
2263    #[test]
2264    fn the_report_states_the_condition_once_and_enumerates_every_command() {
2265        let (_records, records_root) = report_records();
2266        let text = abandonment_report_text(
2267            "ses_abc",
2268            &records_root,
2269            &[
2270                still_running("wrk_0a1b", 12),
2271                finished_too_late(&records_root, "wrk_0c2d"),
2272            ],
2273        );
2274
2275        assert_eq!(
2276            text.matches("2 background shell commands discarded")
2277                .count(),
2278            1
2279        );
2280        assert_eq!(text.matches("work_id: ").count(), 2);
2281        assert!(text.contains("wrk_0a1b"), "{text}");
2282        assert!(text.contains("wrk_0c2d"), "{text}");
2283    }
2284
2285    /// An attributed resource limit rides along, on the same terms
2286    /// [`DetachedCompletion::message_text`] carries it.
2287    #[test]
2288    fn an_attributed_resource_limit_is_named_in_the_report() {
2289        let (_records, records_root) = report_records();
2290        let mut work = finished_too_late(&records_root, "wrk_0c2d");
2291        if let AbandonedDisposition::FinishedTooLate {
2292            resource_limit,
2293            exit_code,
2294            status,
2295            ..
2296        } = &mut work.disposition
2297        {
2298            *resource_limit = Some("memory".to_string());
2299            *exit_code = 137;
2300            *status = "error";
2301        }
2302        let text = abandonment_report_text("ses_abc", &records_root, &[work]);
2303
2304        assert!(text.contains("resource_limit: memory"), "{text}");
2305        assert!(text.contains("status: error"), "{text}");
2306        assert!(text.contains("exit_code: 137"), "{text}");
2307    }
2308
2309    /// `running_ms` and `recovered` are what the `shell_abandoned` line is written from, so the
2310    /// two arms must disagree on `recovered` and agree on carrying a duration.
2311    #[test]
2312    fn only_a_command_that_finished_carries_a_recovered_result() {
2313        assert_eq!(still_running("wrk_0a1b", 45_012).running_ms(), 45_012);
2314        assert!(still_running("wrk_0a1b", 45_012).recovered().is_none());
2315
2316        let (records, records_root) = report_records();
2317        let finished = finished_too_late(&records_root, "wrk_0c2d");
2318        let path = records.path().join("logs/wrk_0c2d.log");
2319        assert_eq!(finished.running_ms(), 2_014);
2320        assert_eq!(
2321            finished.recovered(),
2322            Some((0, path.to_str().unwrap(), 91)),
2323            "the exit code, the output path and its byte count travel together"
2324        );
2325    }
2326
2327    /// A wait that itself failed is named. It is what turns `status` to `"error"` on a command
2328    /// that exited zero, so a report carrying the status without the reason states a failure and
2329    /// withholds the only thing that explains it.
2330    #[test]
2331    fn a_failed_wait_is_named_beside_the_status_it_explains() {
2332        let (_records, records_root) = report_records();
2333        let mut work = finished_too_late(&records_root, "wrk_0c2d");
2334        if let AbandonedDisposition::FinishedTooLate {
2335            wait_error, status, ..
2336        } = &mut work.disposition
2337        {
2338            *wait_error = Some("no child processes".to_string());
2339            *status = "error";
2340        }
2341        let text = abandonment_report_text("ses_abc", &records_root, &[work]);
2342
2343        assert!(text.contains("status: error"), "{text}");
2344        assert!(text.contains("wait_error: no child processes"), "{text}");
2345    }
2346
2347    /// The clean-exit report must not read like [`LostReport::message_text`]: that text asserts
2348    /// no exit code was recorded, which is false here.
2349    #[test]
2350    fn the_report_does_not_claim_nothing_is_recoverable() {
2351        let (_records, records_root) = report_records();
2352        let text =
2353            abandonment_report_text("ses_abc", &records_root, &[still_running("wrk_0a1b", 12)]);
2354        assert!(
2355            !text.contains("No exit code was recorded"),
2356            "the clean-exit report is not the crash report: {text}"
2357        );
2358    }
2359}