1use 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
36pub const WORK_ID_PREFIX: &str = "wrk_";
39
40pub fn new_work_id() -> String {
45 format!("{WORK_ID_PREFIX}{}", uuid::Uuid::now_v7().simple())
46}
47
48#[derive(Debug, Clone, PartialEq, Eq)]
50pub(crate) struct OutputLog {
51 pub relative: String,
54 pub path: String,
57}
58
59pub(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#[derive(Debug, Clone)]
80pub(crate) struct DetachedWork {
81 pub work_id: String,
82 pub binary: String,
84 pub command: String,
86 pub started_at_ms: u64,
89}
90
91#[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 pub output_path: String,
105 pub output_bytes: u64,
107 pub resource_limit: Option<String>,
108 pub output_holders: crate::shell::OutputHolders,
111 pub context_id: String,
114 pub provenance: TaskProvenance,
116 pub error: Option<String>,
118}
119
120impl DetachedCompletion {
121 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(¬e);
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 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#[derive(Debug, Clone)]
179pub(crate) struct DetachedDispatchInfo {
180 pub work_id: String,
181 pub binary: String,
182 pub command: String,
183 pub grace_ms: u64,
187}
188
189pub(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#[derive(Debug, Clone, Copy, PartialEq, Eq, PartialOrd, Ord)]
225pub(crate) enum Phase {
226 Running,
228 LeaderExited,
231 Finished,
233}
234
235#[derive(Debug, Clone, Copy, PartialEq, Eq)]
237pub(crate) enum CommandState {
238 Running,
239 Exited,
241 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
255pub(crate) struct LiveOutput {
265 file: Option<std::fs::File>,
267 tail: VecDeque<u8>,
268 section_bytes: u64,
270 write_error: Option<String>,
272}
273
274impl LiveOutput {
275 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 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 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
335struct DetachedEntry {
337 work: DetachedWork,
338 started: Instant,
339 pgid: i32,
341 output_path: String,
343 output: Arc<Mutex<LiveOutput>>,
344 leader_running: bool,
348 stop_requested: bool,
350 signals_sent: u32,
352 finished: Option<DetachedCompletion>,
353 exit_reported: bool,
356 phase: watch::Sender<Phase>,
357}
358
359#[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 pub elapsed_ms: u64,
368 pub finished: Option<DetachedCompletion>,
370 pub output_path: String,
371 pub output_bytes: u64,
373 pub tail: Vec<u8>,
376}
377
378#[derive(Debug, Clone, Copy, PartialEq, Eq)]
380pub(crate) enum WaitEnd {
381 Finished,
382 TimedOut,
383 Canceled,
384 Unknown,
386}
387
388pub(crate) struct DetachedRegistry {
394 entries: Mutex<BTreeMap<String, DetachedEntry>>,
395 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 pub(crate) fn report(&self, report: DetachedReport) {
419 let _ = self.reports.send(report);
420 }
421
422 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 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 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 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 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 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 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 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 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 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 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 #[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#[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
660pub(crate) struct DetachPolicy {
666 pub grace: Duration,
667 pub delivered: bool,
670 pub registry: Arc<DetachedRegistry>,
671 pub command: String,
675 pub context_id: String,
676 pub provenance: Option<TaskProvenance>,
680 pub abandoned: Option<AbandonSignal>,
684 pub canceled: Option<CancelSignal>,
689}
690
691#[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 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#[derive(Debug, Clone)]
731pub(crate) enum AbandonedDisposition {
732 StillRunning {
736 running_ms: u64,
738 },
739 FinishedTooLate {
743 exit_code: i32,
744 duration_ms: u64,
746 output_path: String,
748 output_bytes: u64,
749 resource_limit: Option<String>,
750 wait_error: Option<String>,
753 status: &'static str,
755 },
756}
757
758#[derive(Debug, Clone)]
760pub(crate) struct AbandonedWork {
761 pub work_id: String,
762 pub binary: String,
764 pub command: String,
767 pub disposition: AbandonedDisposition,
768}
769
770impl AbandonedWork {
771 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 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
797pub(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#[derive(Debug, Clone)]
881pub(crate) struct LostWork {
882 pub work_id: String,
883 pub binary: String,
885 pub command: String,
887 pub detached_at_ms: u64,
890}
891
892#[derive(Debug, Clone)]
898pub(crate) struct LostReport {
899 pub started_in_session: String,
902 pub lost: Vec<LostWork>,
904 pub context_id: String,
906 pub provenance: TaskProvenance,
909 pub task_id: String,
912}
913
914impl LostReport {
915 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#[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 fn records_dir(base: &Path) -> PathBuf {
984 base.join(crate::records_dir::RECORDS_DIR_NAME)
985 }
986
987 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 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(®istry),
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 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 #[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 #[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 #[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 #[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 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 #[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 #[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 #[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 #[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 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 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 #[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(®istry));
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(®istry, &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(®istry, &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 #[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(®istry));
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(®istry, &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(®istry.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(®istry));
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(®istry, &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(®istry));
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(®istry, &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 #[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(®istry));
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(®istry, &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 #[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(®istry));
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(®istry, &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 #[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(®istry, &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 #[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 #[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 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 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 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 #[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 #[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 #[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 #[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 #[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 #[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 #[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}