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

start_command/
execution_recovery.rs
