use std::{
collections::BTreeMap,
sync::{
atomic::{AtomicBool, Ordering},
Arc, Mutex,
},
time::Duration,
};
use tokio::sync::mpsc::{unbounded_channel, UnboundedReceiver, UnboundedSender};
use crate::{
bindings::host::murmur::tool::run::{Status, ToolResult},
origin::{TaskOrigin, TaskProvenance},
};
pub const WORK_ID_PREFIX: &str = "wrk_";
pub fn new_work_id() -> String {
format!("{WORK_ID_PREFIX}{}", uuid::Uuid::now_v7().simple())
}
pub(crate) fn output_path_for(work_id: &str) -> String {
format!("logs/{work_id}.log")
}
#[derive(Debug, Clone)]
pub(crate) struct DetachedWork {
pub work_id: String,
pub binary: String,
pub command: String,
pub started_at_ms: u64,
}
#[derive(Debug, Clone)]
pub(crate) struct DetachedCompletion {
pub work_id: String,
pub binary: String,
pub command: String,
pub exit_code: i32,
pub duration_ms: u64,
pub output_path: String,
pub output_bytes: u64,
pub resource_limit: Option<String>,
pub context_id: String,
pub provenance: TaskProvenance,
pub error: Option<String>,
}
impl DetachedCompletion {
pub(crate) fn message_text(&self) -> String {
let mut text = format!(
"Background shell command finished.\n\
work_id: {}\n\
binary: {}\n\
command: {}\n\
status: {}\n\
exit_code: {}\n\
duration_ms: {}\n\
output: {} ({} bytes, in the capsule workdir)",
self.work_id,
self.binary,
self.command,
self.status(),
self.exit_code,
self.duration_ms,
self.output_path,
self.output_bytes,
);
if let Some(limit) = &self.resource_limit {
text.push('\n');
text.push_str(&crate::resources::resource_limit_line(limit));
}
if let Some(error) = &self.error {
text.push_str(&format!("\nwait_error: {error}"));
}
text.push_str(
"\n\nThe full stdout and stderr are in that file and are not reproduced here.",
);
text
}
pub(crate) fn status(&self) -> &'static str {
if self.exit_code == 0 && self.error.is_none() && self.resource_limit.is_none() {
"ok"
} else {
"error"
}
}
}
#[derive(Debug, Clone)]
pub(crate) struct DetachedDispatchInfo {
pub work_id: String,
pub binary: String,
pub command: String,
pub grace_ms: u64,
}
pub(crate) fn demotion_tool_result(work_id: &str) -> ToolResult {
ToolResult {
status: Status::Passed,
summary: Some(format!(
"Command still running in the background as {work_id}."
)),
data: Some(format!(
"The command did not finish in time and is now running in the background as {work_id}. \
Its result will arrive later as a separate task; there is nothing to poll and no way \
to ask about it. Continue with other work."
)),
data_path: None,
truncated: false,
metadata: vec![("work_id".to_string(), work_id.to_string())],
}
}
pub(crate) struct DetachedRegistry {
outstanding: Mutex<BTreeMap<String, DetachedWork>>,
reports: UnboundedSender<DetachedReport>,
}
impl DetachedRegistry {
pub(crate) fn new() -> (Arc<Self>, UnboundedReceiver<DetachedReport>) {
let (reports, receiver) = unbounded_channel();
(
Arc::new(Self {
outstanding: Mutex::new(BTreeMap::new()),
reports,
}),
receiver,
)
}
pub(crate) fn report(&self, report: DetachedReport) {
let _ = self.reports.send(report);
}
pub(crate) fn register(&self, work: DetachedWork) {
self.outstanding
.lock()
.expect("detached registry mutex")
.insert(work.work_id.clone(), work);
}
pub(crate) fn complete(&self, completion: DetachedCompletion) {
self.outstanding
.lock()
.expect("detached registry mutex")
.remove(&completion.work_id);
self.report(DetachedReport::Completed(completion));
}
pub(crate) fn outstanding(&self) -> Vec<DetachedWork> {
self.outstanding
.lock()
.expect("detached registry mutex")
.values()
.cloned()
.collect()
}
}
pub(crate) struct DetachPolicy {
pub grace: Duration,
pub registry: Arc<DetachedRegistry>,
pub command: String,
pub context_id: String,
pub provenance: Option<TaskProvenance>,
pub abandoned: Option<AbandonSignal>,
}
#[derive(Debug, Clone, Default)]
pub(crate) struct AbandonSignal(Arc<AtomicBool>);
impl AbandonSignal {
pub(crate) fn new() -> Self {
Self::default()
}
pub(crate) fn raise(&self) {
self.0.store(true, Ordering::SeqCst);
}
pub(crate) fn is_raised(&self) -> bool {
self.0.load(Ordering::SeqCst)
}
}
impl DetachPolicy {
pub(crate) fn completion_provenance(&self) -> TaskProvenance {
TaskProvenance::derive(
TaskOrigin::Completion,
self.provenance.map(|task| task.trust()),
)
}
}
#[derive(Debug, Clone)]
pub(crate) enum AbandonedDisposition {
StillRunning {
running_ms: u64,
},
FinishedTooLate {
exit_code: i32,
duration_ms: u64,
output_path: String,
output_bytes: u64,
resource_limit: Option<String>,
wait_error: Option<String>,
status: &'static str,
},
}
#[derive(Debug, Clone)]
pub(crate) struct AbandonedWork {
pub work_id: String,
pub binary: String,
pub command: String,
pub disposition: AbandonedDisposition,
}
impl AbandonedWork {
pub(crate) fn running_ms(&self) -> u64 {
match &self.disposition {
AbandonedDisposition::StillRunning { running_ms } => *running_ms,
AbandonedDisposition::FinishedTooLate { duration_ms, .. } => *duration_ms,
}
}
pub(crate) fn recovered(&self) -> Option<(i32, &str, u64)> {
match &self.disposition {
AbandonedDisposition::StillRunning { .. } => None,
AbandonedDisposition::FinishedTooLate {
exit_code,
output_path,
output_bytes,
..
} => Some((*exit_code, output_path.as_str(), *output_bytes)),
}
}
}
pub(crate) fn abandonment_report_text(session_id: &str, abandoned: &[AbandonedWork]) -> String {
let count = abandoned.len();
let plural = if count == 1 { "command" } else { "commands" };
let mut text = format!(
"[capsule-runtime] {count} background shell {plural} discarded at session end.\n\n\
Session {session_id} ended while {count} demoted shell {plural} {} unaccounted for. \
Nothing was waited for and nothing was killed; what is known about each is below.\n",
if count == 1 { "was" } else { "were" }
);
for work in abandoned {
text.push_str(&format!(
"\nwork_id: {}\nbinary: {}\ncommand: {}\n",
work.work_id, work.binary, work.command
));
match &work.disposition {
AbandonedDisposition::StillRunning { running_ms } => {
text.push_str(&format!(
"state: still running after {running_ms} ms\n\
result: none — no exit code, and no {} will be written, because the thread \
that writes it ended with this session.\n",
output_path_for(&work.work_id)
));
}
AbandonedDisposition::FinishedTooLate {
exit_code,
duration_ms,
output_path,
output_bytes,
resource_limit,
wait_error,
status,
} => {
text.push_str(&format!(
"state: finished during teardown after {duration_ms} ms\n\
status: {status}\n\
exit_code: {exit_code}\n"
));
if let Some(limit) = resource_limit {
text.push_str(&format!("resource_limit: {limit}\n"));
}
if let Some(error) = wait_error {
text.push_str(&format!("wait_error: {error}\n"));
}
text.push_str(&format!(
"output: {output_path} ({output_bytes} bytes, in the capsule workdir)\n\
result: on disk — it finished too late for any task to carry it back to the \
agent.\n"
));
}
}
}
text.push_str(
"\nA command still running keeps running, detached from this session, with nothing \
reading its output. Declare lifecycle.task_acceptance: queue with lifecycle.after_task: \
sleep for a session that outlives its task and can be told the result instead.",
);
text
}
#[derive(Debug, Clone)]
pub(crate) struct LostWork {
pub work_id: String,
pub binary: String,
pub command: String,
pub detached_at_ms: u64,
}
#[derive(Debug, Clone)]
pub(crate) struct LostReport {
pub started_in_session: String,
pub lost: Vec<LostWork>,
pub context_id: String,
pub provenance: TaskProvenance,
pub task_id: String,
}
impl LostReport {
pub(crate) fn message_text(&self) -> String {
let mut text = format!(
"Background shell commands from an earlier session were never accounted for.\n\
\n\
Session {} ended without recording what became of the commands below; they were \
running in the background at the time. Nothing about them was recovered and nothing \
can be: no exit code, no output and no log file exists for any of them, and whether \
each command finished at all is unknown.\n",
self.started_in_session
);
for work in &self.lost {
text.push_str(&format!(
"\nwork_id: {}\nbinary: {}\ncommand: {}\ndetached_at_ms: {}\n",
work.work_id, work.binary, work.command, work.detached_at_ms
));
}
text.push_str(
"\nNone of these is known to have succeeded and none is known to have failed. Treat \
each as unknown, and start the work again only if it still matters.",
);
text
}
}
#[derive(Debug, Clone)]
pub(crate) enum DetachedReport {
Completed(DetachedCompletion),
Lost(LostReport),
}
#[cfg(test)]
mod tests {
use super::*;
use std::{
path::Path,
time::{Duration, Instant},
};
use crate::{
origin::TrustClass,
sandbox::ShellEnforcement,
shell::{run_shell, ShellOutcome},
types::CapabilityPolicy,
};
fn bash_policy() -> CapabilityPolicy {
CapabilityPolicy {
shell_allow: vec!["bash".to_string()],
..Default::default()
}
}
fn detached_run(
workdir: &Path,
script: &str,
grace: Duration,
) -> (
ShellOutcome,
Arc<DetachedRegistry>,
UnboundedReceiver<DetachedReport>,
) {
let (registry, receiver) = DetachedRegistry::new();
let outcome = run_shell(
"bash",
&["-c", script],
&[],
workdir,
workdir,
&bash_policy(),
&ShellEnforcement::environment_only(),
Some(DetachPolicy {
grace,
registry: Arc::clone(®istry),
command: script.to_string(),
context_id: "ctx_detached_tests".to_string(),
provenance: Some(TaskProvenance::derive(TaskOrigin::User, None)),
abandoned: None,
}),
)
.expect("a declared binary runs");
(outcome, registry, receiver)
}
fn await_completion(receiver: &mut UnboundedReceiver<DetachedReport>) -> DetachedCompletion {
let deadline = Instant::now() + Duration::from_secs(30);
loop {
match receiver.try_recv() {
Ok(DetachedReport::Completed(completion)) => return completion,
Ok(other) => panic!("a shell command's completion was expected; got {other:?}"),
Err(tokio::sync::mpsc::error::TryRecvError::Empty) => {
assert!(
Instant::now() < deadline,
"timed out waiting for the detached completion"
);
std::thread::sleep(Duration::from_millis(25));
}
Err(error) => panic!("the completion channel closed early: {error}"),
}
}
}
fn completion_provenance() -> TaskProvenance {
TaskProvenance::derive(TaskOrigin::Completion, Some(TrustClass::Untrusted))
}
#[test]
fn no_two_completions_share_an_opening_line() {
let outcome = crate::delegation::DelegationOutcome {
delegation_id: "dlg_0001".to_string(),
capsule_name: "worker".to_string(),
capsule_version: "0.1.0".to_string(),
session_id: "ses_child".to_string(),
status: crate::delegation::DelegationStatus::Ok,
result_path: None,
workdir: "/tmp/child".to_string(),
duration_ms: 1,
detail: None,
reported_by: crate::delegation::Reporter::Launcher,
delivered: true,
delivery_error: None,
};
let completion = DetachedCompletion {
work_id: "wrk_0001".to_string(),
binary: "bash".to_string(),
command: "sleep 3".to_string(),
exit_code: 0,
duration_ms: 3_000,
output_path: "logs/wrk_0001.log".to_string(),
output_bytes: 0,
resource_limit: None,
context_id: "ctx_1".to_string(),
provenance: completion_provenance(),
error: None,
};
let texts = [
("delegation outcome", outcome.message_text()),
("detached shell completion", completion.message_text()),
];
for (index, (name, text)) in texts.iter().enumerate() {
let opening = text.lines().next().unwrap_or_default();
assert!(!opening.is_empty(), "{name} opens with nothing");
for (other_name, other) in texts.iter().skip(index + 1) {
assert_ne!(
opening,
other.lines().next().unwrap_or_default(),
"{name} and {other_name} open with the same line"
);
}
}
}
#[test]
fn a_completion_names_its_limit_in_the_shared_wording() {
let completion = DetachedCompletion {
work_id: "wrk_0001".to_string(),
binary: "bash".to_string(),
command: "make -j64".to_string(),
exit_code: 1,
duration_ms: 3_000,
output_path: "logs/wrk_0001.log".to_string(),
output_bytes: 0,
resource_limit: Some("cgroup_pids_max".into()),
context_id: "ctx_1".to_string(),
provenance: completion_provenance(),
error: None,
};
let text = completion.message_text();
let expected = crate::resources::resource_limit_line("cgroup_pids_max");
assert!(
text.lines().any(|line| line == expected),
"no limit line in:\n{text}"
);
assert_eq!(
text.lines().next(),
Some("Background shell command finished.")
);
assert_eq!(completion.status(), "error");
assert!(text.ends_with("are not reproduced here."), "{text}");
}
#[test]
fn a_command_outrunning_the_grace_period_is_demoted() {
let workdir = tempfile::tempdir().unwrap();
let started = Instant::now();
let (outcome, registry, mut receiver) = detached_run(
workdir.path(),
"sleep 3; printf 'fin%s' 'ished-marker'",
Duration::from_secs(1),
);
let info = match outcome {
ShellOutcome::Detached(info) => info,
ShellOutcome::Finished(result) => {
panic!(
"a three-second command must not finish inside a one-second grace: {result:?}"
)
}
};
assert!(
started.elapsed() < Duration::from_secs(3),
"the call returned only after the command did"
);
assert!(
info.work_id.starts_with(WORK_ID_PREFIX)
&& info.work_id[WORK_ID_PREFIX.len()..]
.chars()
.all(|c| c.is_ascii_hexdigit() && !c.is_ascii_uppercase()),
"work id {} must match ^wrk_[0-9a-f]+$",
info.work_id
);
assert_eq!(info.grace_ms, 1_000);
assert_eq!(
registry
.outstanding()
.iter()
.map(|work| work.work_id.clone())
.collect::<Vec<_>>(),
vec![info.work_id.clone()],
"the work is registered before the handle is returned"
);
let completion = await_completion(&mut receiver);
assert_eq!(completion.work_id, info.work_id);
assert_eq!(completion.exit_code, 0);
assert_eq!(completion.status(), "ok");
assert_eq!(
completion.output_path,
format!("logs/{}.log", info.work_id),
"the completion names logs/<work_id>.log"
);
assert_eq!(completion.provenance.origin(), TaskOrigin::Completion);
assert_eq!(completion.provenance.trust(), TrustClass::Trusted);
assert_eq!(completion.context_id, "ctx_detached_tests");
assert!(
registry.outstanding().is_empty(),
"a completed command is no longer outstanding"
);
let log = std::fs::read_to_string(workdir.path().join(&completion.output_path))
.expect("the completion's output file exists");
assert!(
log.contains("finished-marker"),
"the output is in the log: {log}"
);
assert!(
!completion.message_text().contains("finished-marker"),
"the output never reaches the agent: {}",
completion.message_text()
);
}
#[test]
fn a_fast_command_finishes_in_the_foreground() {
let workdir = tempfile::tempdir().unwrap();
let (outcome, registry, mut receiver) =
detached_run(workdir.path(), "echo hi", Duration::from_secs(10));
let result = match outcome {
ShellOutcome::Finished(result) => result,
ShellOutcome::Detached(info) => {
panic!("`echo hi` must not be demoted: {}", info.work_id)
}
};
assert_eq!(result.stdout.trim(), "hi");
assert_eq!(result.exit_code, 0);
assert!(!result.truncated);
assert!(result.full_output_path.is_none());
assert!(registry.outstanding().is_empty());
assert!(
matches!(
receiver.try_recv(),
Err(tokio::sync::mpsc::error::TryRecvError::Empty)
),
"a foreground command produces no completion"
);
}
#[test]
fn a_failing_detached_command_completes_with_its_exit_code() {
let workdir = tempfile::tempdir().unwrap();
let (outcome, _registry, mut receiver) = detached_run(
workdir.path(),
"sleep 3; echo to-stderr >&2; exit 7",
Duration::from_secs(1),
);
assert!(matches!(outcome, ShellOutcome::Detached(_)));
let completion = await_completion(&mut receiver);
assert_eq!(completion.exit_code, 7);
assert_eq!(completion.status(), "error");
assert!(
completion.message_text().contains("exit_code: 7"),
"the message names the exit code: {}",
completion.message_text()
);
let log = std::fs::read_to_string(workdir.path().join(&completion.output_path)).unwrap();
let stderr_section = log
.split("Stderr:")
.nth(1)
.expect("the log has a stderr section");
assert!(
stderr_section.contains("to-stderr"),
"stderr is in the log's Stderr section: {log}"
);
let (outcome, _registry, mut receiver) =
detached_run(workdir.path(), "sleep 3; exit 0", Duration::from_secs(1));
assert!(matches!(outcome, ShellOutcome::Detached(_)));
assert_eq!(await_completion(&mut receiver).status(), "ok");
}
#[test]
fn the_demotion_result_is_a_constant_size() {
let reduce = |work_id: &str| {
let result = demotion_tool_result(work_id);
result
.data
.or(result.summary)
.unwrap_or_else(|| "tool returned no data".to_string())
};
let first = reduce(&new_work_id());
let second = reduce(&new_work_id());
assert_eq!(
first.len(),
second.len(),
"two work ids of equal length must produce texts of equal size"
);
for text in [&first, &second] {
let tokens = crate::agent::count_tokens(text);
assert!(
tokens < 120,
"the demotion result costs {tokens} tokens, over the 120-token ceiling"
);
}
assert!(
!first.contains("logs/"),
"the demotion result names no path: {first}"
);
}
#[test]
fn no_surface_takes_a_work_id() {
const RULE: &str = "a demoted command is learned about through its completion and no \
other way: nothing the model or a host embedder can reach may take a \
work id as an argument";
let work_id = concat!("work", "_id");
let parameter = format!("{work_id}:");
let json_key = format!(".get(\"{work_id}\")");
let schema = concat!("input", "_schema");
let sources = crate::source_scan::crate_sources();
let mut offences = Vec::new();
for (path, source) in &sources {
for (number, line) in source.lines().enumerate() {
let line = line.trim();
let at = format!("{path}:{}", number + 1);
if (line.starts_with("pub fn ") || line.starts_with("pub async fn "))
&& line.contains(¶meter)
{
offences.push(format!("{at}: public function takes a work id — {line}"));
}
if line.contains(&json_key) {
offences.push(format!("{at}: tool input is parsed for a work id — {line}"));
}
if line.contains(schema) && line.contains(work_id) {
offences.push(format!("{at}: a tool schema declares a work id — {line}"));
}
}
}
let inventory = sources
.iter()
.find(|(path, _)| path.ends_with("inventory.rs"))
.map(|(_, source)| source)
.expect("agent/inventory.rs is part of this crate");
if inventory.contains(work_id) || inventory.contains(WORK_ID_PREFIX) {
offences.push("agent/inventory.rs: the tool inventory mentions a work id".to_string());
}
assert!(offences.is_empty(), "{RULE}\n{}", offences.join("\n"));
}
fn still_running(work_id: &str, running_ms: u64) -> AbandonedWork {
AbandonedWork {
work_id: work_id.to_string(),
binary: "/usr/bin/bash".to_string(),
command: "sleep 45; echo done".to_string(),
disposition: AbandonedDisposition::StillRunning { running_ms },
}
}
fn finished_too_late(work_id: &str) -> AbandonedWork {
AbandonedWork {
work_id: work_id.to_string(),
binary: "/usr/bin/bash".to_string(),
command: "sleep 2; echo done".to_string(),
disposition: AbandonedDisposition::FinishedTooLate {
exit_code: 0,
duration_ms: 2_014,
output_path: output_path_for(work_id),
output_bytes: 91,
resource_limit: None,
wait_error: None,
status: "ok",
},
}
}
#[test]
fn a_still_running_command_is_reported_with_what_is_known_and_promises_no_file() {
let text = abandonment_report_text("ses_abc", &[still_running("wrk_0a1b", 45_012)]);
assert!(
text.contains("1 background shell command discarded"),
"{text}"
);
assert!(text.contains("Session ses_abc"), "{text}");
assert!(text.contains("work_id: wrk_0a1b"), "{text}");
assert!(text.contains("binary: /usr/bin/bash"), "{text}");
assert!(text.contains("command: sleep 45; echo done"), "{text}");
assert!(
text.contains("state: still running after 45012 ms"),
"{text}"
);
assert!(
text.contains("no logs/wrk_0a1b.log will be written"),
"{text}"
);
assert!(!text.contains("exit_code:"), "no exit code exists: {text}");
}
#[test]
fn a_command_that_finished_during_teardown_is_reported_with_its_result() {
let text = abandonment_report_text("ses_abc", &[finished_too_late("wrk_0c2d")]);
assert!(
text.contains("state: finished during teardown after 2014 ms"),
"{text}"
);
assert!(text.contains("status: ok"), "{text}");
assert!(text.contains("exit_code: 0"), "{text}");
assert!(
text.contains("output: logs/wrk_0c2d.log (91 bytes, in the capsule workdir)"),
"{text}"
);
assert!(!text.contains("still running after"), "{text}");
}
#[test]
fn the_report_states_the_condition_once_and_enumerates_every_command() {
let text = abandonment_report_text(
"ses_abc",
&[still_running("wrk_0a1b", 12), finished_too_late("wrk_0c2d")],
);
assert_eq!(
text.matches("2 background shell commands discarded")
.count(),
1
);
assert_eq!(text.matches("work_id: ").count(), 2);
assert!(text.contains("wrk_0a1b"), "{text}");
assert!(text.contains("wrk_0c2d"), "{text}");
}
#[test]
fn an_attributed_resource_limit_is_named_in_the_report() {
let mut work = finished_too_late("wrk_0c2d");
if let AbandonedDisposition::FinishedTooLate {
resource_limit,
exit_code,
status,
..
} = &mut work.disposition
{
*resource_limit = Some("memory".to_string());
*exit_code = 137;
*status = "error";
}
let text = abandonment_report_text("ses_abc", &[work]);
assert!(text.contains("resource_limit: memory"), "{text}");
assert!(text.contains("status: error"), "{text}");
assert!(text.contains("exit_code: 137"), "{text}");
}
#[test]
fn only_a_command_that_finished_carries_a_recovered_result() {
assert_eq!(still_running("wrk_0a1b", 45_012).running_ms(), 45_012);
assert!(still_running("wrk_0a1b", 45_012).recovered().is_none());
let finished = finished_too_late("wrk_0c2d");
assert_eq!(finished.running_ms(), 2_014);
assert_eq!(
finished.recovered(),
Some((0, "logs/wrk_0c2d.log", 91)),
"the exit code, the output path and its byte count travel together"
);
}
#[test]
fn a_failed_wait_is_named_beside_the_status_it_explains() {
let mut work = finished_too_late("wrk_0c2d");
if let AbandonedDisposition::FinishedTooLate {
wait_error, status, ..
} = &mut work.disposition
{
*wait_error = Some("no child processes".to_string());
*status = "error";
}
let text = abandonment_report_text("ses_abc", &[work]);
assert!(text.contains("status: error"), "{text}");
assert!(text.contains("wait_error: no child processes"), "{text}");
}
#[test]
fn the_report_does_not_claim_nothing_is_recoverable() {
let text = abandonment_report_text("ses_abc", &[still_running("wrk_0a1b", 12)]);
assert!(
!text.contains("Nothing about them was recovered"),
"the clean-exit report is not the crash report: {text}"
);
}
}