Skip to main content

capsule_runtime/
detached.rs

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