start_command/
execution_recovery.rs

1//! Launch-time recovery for killed detached docker sessions (issue #176).
2//!
3//! `$ --isolated docker --detached --on-kill-resume 3 --recovery-command B -- A`
4//! runs `A`; when the main process is killed (exit 137, or `OOMKilled` with no
5//! exit status of its own), the detached completion watcher hands the inspected
6//! facts to this module, which restarts the *same* container so `B` continues
7//! on the same filesystem, with the same resource limits (they live in the
8//! container's HostConfig), under the same execution UUID and appending to the
9//! same log file.
10//!
11//! How `B` replaces `A` inside the same container: a container launched with a
12//! recovery command runs a tiny selector as its command. The selector runs `A`
13//! normally, but runs `B` when the marker file exists. Before `docker start`,
14//! the marker (holding the attempt number) is copied into the stopped
15//! container with `docker cp`. Without a recovery command the original command
16//! is simply started again.
17//!
18//! Like `detached_finalize`, the entry point runs as a short-lived child of the
19//! watcher on a host whose CLI invocation is long gone, so it never panics on
20//! bad input and never prints anything.
21
22use std::fs;
23use std::io::Write;
24use std::path::PathBuf;
25
26use chrono::{SecondsFormat, Utc};
27use serde_json::{json, Value};
28
29use crate::detached_finalize::{normalize_bool, normalize_container_error};
30use crate::docker_cleanup::{
31    docker_command, get_docker_container_cleanup_policy,
32    start_detached_docker_completion_watcher_with, DockerWatcherOptions,
33};
34use crate::docker_post_mortem::{format_container_post_mortem, shell_vars, ContainerPostMortem};
35use crate::docker_resource_limits::{
36    build_resource_limits_status_line, read_docker_resource_limits,
37};
38use crate::execution_control::{CommandRunOutput, CommandRunner, SystemCommandRunner};
39use crate::execution_resume::build_launch_options;
40use crate::execution_store::{
41    ExecutionRecord, ExecutionStatus, ExecutionStore, ExecutionStoreOptions,
42};
43use crate::exit_reason::describe_exit_code_str;
44use crate::isolation::isolation_log::shell_quote;
45
46/// Hidden argument the detached watcher re-invokes this binary with.
47pub const INTERNAL_RECOVER_FLAG: &str = "--internal-recover-detached-docker";
48
49/// File whose presence makes the selector run the recovery command.
50pub const RECOVERY_MARKER_PATH: &str = "/.start-command-recovery";
51
52/// Environment variable carrying the attempt number into the recovery command.
53pub const RECOVERY_ATTEMPT_ENV: &str = "START_COMMAND_RECOVERY_ATTEMPT";
54
55/// Exit code of a process killed with SIGKILL (the OOM killer's signal).
56pub const KILLED_EXIT_CODE: i32 = 137;
57
58/// POSIX selector run as the container command when a recovery command is set:
59/// `sh -c SELECTOR start-command <shell> <flag> <recovery> <main argv...>`.
60pub fn recovery_selector() -> String {
61    format!(
62        "s=$1; f=$2; r=$3; shift 3; if [ -e {marker} ]; then {env}=$(cat {marker} 2>/dev/null); export {env}; if [ -n \"$f\" ]; then exec \"$s\" \"$f\" -c \"$r\"; fi; exec \"$s\" -c \"$r\"; fi; exec \"$@\"",
63        marker = RECOVERY_MARKER_PATH,
64        env = RECOVERY_ATTEMPT_ENV
65    )
66}
67
68/// Wrap the container command so a later `docker start` can switch to the
69/// recovery command.
70pub fn build_recovery_selector_args(
71    main_args: &[String],
72    shell: &str,
73    shell_flag: Option<&str>,
74    recovery_command: &str,
75) -> Vec<String> {
76    let mut args = vec![
77        "sh".to_string(),
78        "-c".to_string(),
79        recovery_selector(),
80        "start-command".to_string(),
81        if shell.is_empty() { "sh" } else { shell }.to_string(),
82        shell_flag.unwrap_or("").to_string(),
83        recovery_command.to_string(),
84    ];
85    args.extend(main_args.iter().cloned());
86    args
87}
88
89/// Whether the inspected facts describe a killed main process.
90///
91/// Exit 137 (SIGKILL, the OOM killer's signal) always counts. `OOMKilled`
92/// alone does not: Docker sets it when *any* process in the container's
93/// cgroup was OOM-killed (a compiler, a test runner, a child `node`), and it
94/// stays set until the container is started again. A main process that
95/// survived that and then exited 0-127 on its own ran to completion, so the
96/// flag only counts when there is no usable exit status (the watcher's `-1`,
97/// or nothing at all) (issue #178).
98pub fn is_killed_exit(exit_code: &str, oom_killed: &str) -> bool {
99    let code = describe_exit_code_str(exit_code).code;
100    if code == Some(KILLED_EXIT_CODE) {
101        return true;
102    }
103    normalize_bool(oom_killed) == Some(true) && code.is_none_or(|code| code < 0)
104}
105
106/// Shell condition run by the completion watcher: true when the container was
107/// killed and the recovery entry point resumed it. Mirrors `is_killed_exit`:
108/// `OOMKilled` only counts without a non-negative exit code (issue #178).
109pub fn build_recovery_snippet(execution_id: &str) -> String {
110    let executable = std::env::current_exe()
111        .map(|path| path.to_string_lossy().to_string())
112        .unwrap_or_else(|_| "start".to_string());
113    format!(
114        "{{ [ \"${exit}\" = {code} ] || {{ [ \"${oom}\" = true ] && ! [ \"${exit}\" -ge 0 ] 2>/dev/null; }}; }} && {exe} {flag} {id} \"${exit}\" \"${oom}\" \"${started}\" \"${finished}\" \"${error}\" >/dev/null 2>&1",
115        exit = shell_vars::EXIT,
116        oom = shell_vars::OOM,
117        started = shell_vars::STARTED,
118        finished = shell_vars::FINISHED,
119        error = shell_vars::ERROR,
120        code = KILLED_EXIT_CODE,
121        exe = shell_quote(&executable),
122        flag = INTERNAL_RECOVER_FLAG,
123        id = shell_quote(execution_id),
124    )
125}
126
127/// What the `[Recovery k/N]` separator reports.
128pub struct RecoverySeparator<'a> {
129    pub attempt: u64,
130    pub max_attempts: u64,
131    pub exit_code: &'a str,
132    pub oom_killed: &'a str,
133    pub container_name: &'a str,
134    pub command: Option<&'a str>,
135}
136
137/// The `[Recovery k/N]` separator written into the session log.
138pub fn format_recovery_separator(params: &RecoverySeparator) -> String {
139    let described = describe_exit_code_str(params.exit_code);
140    let code = described
141        .code
142        .map(|code| code.to_string())
143        .unwrap_or_else(|| "unknown".to_string());
144    let signal = described
145        .signal
146        .map(|name| format!(", {}", name))
147        .unwrap_or_default();
148    let what = match params.command {
149        Some(command) => format!("running recovery command: {}", command),
150        None => "running the original command again".to_string(),
151    };
152    format!(
153        "\n[Recovery {}/{}] Main process was killed (exit {}{}, oomKilled={}); resuming container {}, {}\n",
154        params.attempt,
155        params.max_attempts,
156        code,
157        signal,
158        normalize_bool(params.oom_killed) == Some(true),
159        params.container_name,
160        what
161    )
162}
163
164/// The docker facts the watcher hands over.
165#[derive(Debug, Clone, Default)]
166pub struct RecoveryFacts {
167    pub exit_code: String,
168    pub oom_killed: String,
169    pub started_at: String,
170    pub finished_at: String,
171    pub container_error: String,
172}
173
174/// Outcome of a recovery attempt; `recovered` is true only when the container
175/// was started again.
176#[derive(Debug, Clone, PartialEq, Eq)]
177pub struct RecoveryOutcome {
178    pub recovered: bool,
179    pub reason: String,
180    pub attempt: Option<u64>,
181}
182
183impl RecoveryOutcome {
184    fn not(reason: &str) -> Self {
185        RecoveryOutcome {
186            recovered: false,
187            reason: reason.to_string(),
188            attempt: None,
189        }
190    }
191}
192
193/// Starts the completion watcher that follows a resumed container.
194pub type WatcherStarter<'a> = &'a dyn Fn(&str, &ExecutionRecord, &DockerWatcherOptions);
195
196fn append_to_log(log_path: &str, text: &str) {
197    if log_path.is_empty() {
198        return;
199    }
200    // The log is best-effort here: recovery itself must still proceed.
201    if let Ok(mut file) = fs::OpenOptions::new()
202        .create(true)
203        .append(true)
204        .open(log_path)
205    {
206        let _ = file.write_all(text.as_bytes());
207    }
208}
209
210fn failure_detail(result: &CommandRunOutput) -> String {
211    let stderr = result.stderr.trim();
212    if !stderr.is_empty() {
213        return stderr.to_string();
214    }
215    result.error.clone().unwrap_or_else(|| {
216        format!(
217            "exit code {}",
218            result
219                .status
220                .map(|code| code.to_string())
221                .unwrap_or_else(|| "unknown".to_string())
222        )
223    })
224}
225
226fn write_recovery_marker<R: CommandRunner + ?Sized>(
227    container_name: &str,
228    attempt: u64,
229    runner: &R,
230) -> CommandRunOutput {
231    let dir = std::env::temp_dir().join(format!("start-recovery-{}", uuid::Uuid::new_v4()));
232    let file = dir.join("marker");
233    let written = fs::create_dir_all(&dir).and_then(|_| fs::write(&file, format!("{}\n", attempt)));
234    #[cfg(unix)]
235    {
236        use std::os::unix::fs::PermissionsExt;
237        let _ = fs::set_permissions(&file, fs::Permissions::from_mode(0o644));
238    }
239    let result = match written {
240        Ok(()) => runner.run(
241            &docker_command().to_string_lossy(),
242            &[
243                "cp".to_string(),
244                file.to_string_lossy().to_string(),
245                format!("{}:{}", container_name, RECOVERY_MARKER_PATH),
246            ],
247        ),
248        Err(err) => CommandRunOutput {
249            success: false,
250            error: Some(err.to_string()),
251            ..CommandRunOutput::default()
252        },
253    };
254    let _ = fs::remove_dir_all(&dir);
255    result
256}
257
258fn option_u64(record: &ExecutionRecord, key: &str) -> u64 {
259    match record.options.get(key) {
260        Some(Value::Number(n)) => n.as_u64().unwrap_or(0),
261        Some(Value::String(s)) => s.trim().parse().unwrap_or(0),
262        _ => 0,
263    }
264}
265
266fn option_str<'a>(record: &'a ExecutionRecord, key: &str) -> Option<&'a str> {
267    record
268        .options
269        .get(key)
270        .and_then(Value::as_str)
271        .filter(|value| !value.is_empty())
272}
273
274/// Resume a killed execution in its own container.
275pub fn recover_killed_execution<R: CommandRunner + ?Sized>(
276    store: &ExecutionStore,
277    execution_id: &str,
278    facts: &RecoveryFacts,
279    runner: &R,
280    start_watcher: WatcherStarter,
281) -> RecoveryOutcome {
282    if execution_id.is_empty() {
283        return RecoveryOutcome::not("missing-arguments");
284    }
285    let Some(mut record) = store.get(execution_id) else {
286        return RecoveryOutcome::not("record-not-found");
287    };
288    let max_attempts = option_u64(&record, "onKillResume");
289    let container_name = option_str(&record, "sessionName").map(str::to_string);
290    let Some(container_name) = container_name
291        .filter(|_| option_str(&record, "isolated") == Some("docker") && max_attempts >= 1)
292    else {
293        return RecoveryOutcome::not("not-configured");
294    };
295    if !is_killed_exit(&facts.exit_code, &facts.oom_killed) {
296        return RecoveryOutcome::not("not-killed");
297    }
298    let log_path = record.log_path.clone();
299    let log = |text: &str| append_to_log(&log_path, text);
300    if option_str(&record, "stopRequestedAt").is_some() {
301        log("\n[Recovery] Not resuming: the session was stopped on request.\n");
302        return RecoveryOutcome::not("stop-requested");
303    }
304    let used = option_u64(&record, "recoveryAttempts");
305    if used >= max_attempts {
306        log(&format!(
307            "\n[Recovery] Not resuming: all {} recovery attempt(s) used.\n",
308            max_attempts
309        ));
310        return RecoveryOutcome::not("attempts-exhausted");
311    }
312
313    let attempt = used + 1;
314    let give_up = |reason: String| {
315        log(&format!(
316            "[Recovery {}/{}] Failed: {}\n",
317            attempt, max_attempts, reason
318        ));
319        RecoveryOutcome {
320            recovered: false,
321            reason: "resume-failed".to_string(),
322            attempt: Some(attempt),
323        }
324    };
325
326    let oom_killed = normalize_bool(&facts.oom_killed);
327    log(&format!(
328        "\n{}",
329        format_container_post_mortem(&ContainerPostMortem {
330            container_name: container_name.clone(),
331            exit_code: describe_exit_code_str(&facts.exit_code).code,
332            oom_killed,
333            started_at: Some(facts.started_at.clone()),
334            finished_at: Some(facts.finished_at.clone()),
335            error: normalize_container_error(&facts.container_error),
336        })
337    ));
338    let recovery_command = option_str(&record, "recoveryCommand").map(str::to_string);
339    log(&format_recovery_separator(&RecoverySeparator {
340        attempt,
341        max_attempts,
342        exit_code: &facts.exit_code,
343        oom_killed: &facts.oom_killed,
344        container_name: &container_name,
345        command: recovery_command.as_deref(),
346    }));
347
348    // Docker keeps `docker update` limits in the HostConfig across restarts;
349    // they are read back so the log and `--status` show what the resumed run
350    // is held to, and so a later relaunch can re-apply them.
351    let resource_limits = read_docker_resource_limits(&container_name, runner).unwrap_or_default();
352    if let Some(line) = build_resource_limits_status_line(&resource_limits) {
353        log(&format!("{}\n", line));
354    }
355
356    if recovery_command.is_some() {
357        let copied = write_recovery_marker(&container_name, attempt, runner);
358        if !copied.success {
359            return give_up(format!(
360                "could not mark the container: {}",
361                failure_detail(&copied)
362            ));
363        }
364    }
365
366    let since = Utc::now().to_rfc3339_opts(SecondsFormat::Millis, true);
367    let started = runner.run(
368        &docker_command().to_string_lossy(),
369        &["start".to_string(), container_name.clone()],
370    );
371    if !started.success {
372        return give_up(format!("docker start failed: {}", failure_detail(&started)));
373    }
374
375    let described = describe_exit_code_str(&facts.exit_code);
376    let mut history = record
377        .options
378        .get("recoveryHistory")
379        .and_then(Value::as_array)
380        .cloned()
381        .unwrap_or_default();
382    history.push(json!(format!(
383        "{}: exit {}, oomKilled={}, resumed at {}",
384        attempt,
385        described
386            .code
387            .map(|code| code.to_string())
388            .unwrap_or_else(|| "unknown".to_string()),
389        oom_killed == Some(true),
390        since
391    )));
392    let options = &mut record.options;
393    options.insert("recoveryAttempts".to_string(), json!(attempt));
394    options.insert("recoveryHistory".to_string(), Value::Array(history));
395    options.insert("lastRecoveryAt".to_string(), json!(since));
396    if !resource_limits.is_empty() {
397        options.insert("resourceLimits".to_string(), json!(resource_limits));
398    }
399    record.status = ExecutionStatus::Executing;
400    record.exit_code = None;
401    record.end_time = None;
402    record.exit_reason = None;
403    record.oom_killed = None;
404    // The container is already running again; even if the save fails, the new
405    // watcher still follows it and finalizes the record when it ends.
406    let _ = store.save(&record);
407
408    start_watcher(
409        &container_name,
410        &record,
411        &DockerWatcherOptions {
412            since: Some(since),
413            recover_on_kill: true,
414        },
415    );
416    RecoveryOutcome {
417        recovered: true,
418        reason: "resumed".to_string(),
419        attempt: Some(attempt),
420    }
421}
422
423/// The real watcher: a detached shell following the resumed container.
424pub fn start_system_watcher(
425    container_name: &str,
426    record: &ExecutionRecord,
427    watcher: &DockerWatcherOptions,
428) {
429    let log_path = (!record.log_path.is_empty()).then(|| PathBuf::from(&record.log_path));
430    start_detached_docker_completion_watcher_with(
431        container_name,
432        get_docker_container_cleanup_policy(&build_launch_options(record)),
433        log_path.as_ref(),
434        Some(record.uuid.as_str()),
435        watcher,
436    );
437}
438
439/// Entry point for `--internal-recover-detached-docker <uuid> <exit> <oom>
440/// <started> <finished> <error>`. Returns 0 only when the container was
441/// resumed; any other outcome lets the watcher continue with its normal
442/// cleanup, footer and finalization.
443pub fn run_internal_recover(args: &[String]) -> i32 {
444    let execution_id = match args.first() {
445        Some(value) if !value.is_empty() => value.clone(),
446        _ => return 1,
447    };
448    if std::env::var("START_DISABLE_TRACKING").as_deref() == Ok("true") {
449        return 1;
450    }
451    let field = |index: usize| args.get(index).cloned().unwrap_or_default();
452    let store = ExecutionStore::with_options(ExecutionStoreOptions {
453        app_folder: std::env::var("START_APP_FOLDER").ok().map(PathBuf::from),
454        ..ExecutionStoreOptions::default()
455    });
456    let outcome = recover_killed_execution(
457        &store,
458        &execution_id,
459        &RecoveryFacts {
460            exit_code: field(1),
461            oom_killed: field(2),
462            started_at: field(3),
463            finished_at: field(4),
464            container_error: field(5),
465        },
466        &SystemCommandRunner,
467        &start_system_watcher,
468    );
469    if outcome.recovered {
470        0
471    } else {
472        1
473    }
474}
start_command/execution_recovery.rs

start_command/
execution_recovery.rs
