Skip to main content

start_command/
docker_snapshot_resume.rs

1//! Steps around the `docker commit` of a snapshot resume (issue #224):
2//!
3//! - `--snapshot-prepare <command>` runs in the stopped original before the
4//!   commit: `docker start`, `docker exec ... sh -c <command>`, and always a
5//!   `docker kill` afterwards. Starting the original runs its own command
6//!   again, so this is only for containers whose start is known to be safe.
7//! - Progress lines while `docker commit` runs, which prints nothing itself.
8//! - `--remove-original-after <seconds>`: remove the stopped original only if
9//!   the replacement is still running after the delay.
10
11use crate::docker_cleanup::docker_command;
12use crate::execution_control::{CommandRunOutput, CommandRunner};
13use crate::isolation::isolation_log::append_log_file;
14use std::path::PathBuf;
15use std::sync::mpsc;
16use std::time::{Duration, Instant};
17
18const DEFAULT_PROGRESS_INTERVAL_SECONDS: f64 = 60.0;
19/// Upper bound for one `--snapshot-prepare`; the original is killed after.
20const DEFAULT_PREPARE_TIMEOUT_SECONDS: f64 = 600.0;
21
22/// Format a duration the way the progress lines print it: "45s", "12 min".
23pub fn format_elapsed(seconds: f64) -> String {
24    let whole = seconds.max(0.0).floor() as u64;
25    if whole < 60 {
26        return format!("{}s", whole);
27    }
28    match whole % 60 {
29        0 => format!("{} min", whole / 60),
30        rest => format!("{} min {}s", whole / 60, rest),
31    }
32}
33
34fn positive_seconds(value: Option<String>, fallback: f64) -> f64 {
35    value
36        .and_then(|value| value.trim().parse::<f64>().ok())
37        .filter(|seconds| seconds.is_finite() && *seconds > 0.0)
38        .unwrap_or(fallback)
39}
40
41pub fn progress_interval_seconds() -> f64 {
42    positive_seconds(
43        std::env::var("START_SNAPSHOT_PROGRESS_INTERVAL").ok(),
44        DEFAULT_PROGRESS_INTERVAL_SECONDS,
45    )
46}
47
48/// Where the snapshot steps report: the execution log and `notify`.
49pub struct SnapshotReporter<'a> {
50    pub log_path: &'a str,
51    pub notify: &'a (dyn Fn(&str) + Sync),
52}
53
54impl SnapshotReporter<'_> {
55    pub fn log(&self, line: &str) {
56        if !self.log_path.is_empty() {
57            append_log_file(&PathBuf::from(self.log_path), &format!("{}\n", line));
58        }
59    }
60
61    pub fn report(&self, line: &str) {
62        self.log(line);
63        (self.notify)(line);
64    }
65}
66
67/// Run `docker commit` and report the elapsed time every interval.
68pub fn commit_with_progress<R: CommandRunner + ?Sized>(
69    runner: &R,
70    command: &str,
71    args: &[String],
72    session_name: &str,
73    reporter: &SnapshotReporter,
74    interval_seconds: f64,
75) -> CommandRunOutput {
76    let started = Instant::now();
77    let interval = Duration::from_secs_f64(interval_seconds.max(0.001));
78    let (done, finished) = mpsc::channel::<()>();
79    let result = std::thread::scope(|scope| {
80        scope.spawn(move || {
81            while let Err(mpsc::RecvTimeoutError::Timeout) = finished.recv_timeout(interval) {
82                reporter.report(&format!(
83                    "[Resume] snapshotting {}: {} elapsed (docker commit reports no progress)",
84                    session_name,
85                    format_elapsed(started.elapsed().as_secs_f64())
86                ));
87            }
88        });
89        let result = runner.run(command, args);
90        let _ = done.send(());
91        result
92    });
93    if result.success {
94        reporter.report(&format!(
95            "[Resume] snapshot of {} committed after {}",
96            session_name,
97            format_elapsed(started.elapsed().as_secs_f64())
98        ));
99    }
100    result
101}
102
103fn detail(result: &CommandRunOutput, fallback: &str) -> String {
104    let stderr = result.stderr.trim();
105    if !stderr.is_empty() {
106        return stderr.to_string();
107    }
108    if let Some(error) = &result.error {
109        return error.clone();
110    }
111    match result.status {
112        Some(code) => format!("exit code {}", code),
113        None => fallback.to_string(),
114    }
115}
116
117/// Run `--snapshot-prepare` in the stopped original. A failure is reported and
118/// the snapshot continues with the files as they are.
119pub fn run_snapshot_prepare<R: CommandRunner + ?Sized>(
120    session_name: &str,
121    prepare: &str,
122    runner: &R,
123    reporter: &SnapshotReporter,
124) -> (bool, String) {
125    let docker = docker_command().to_string_lossy().to_string();
126    let started = runner.run(&docker, &["start".into(), session_name.into()]);
127    if !started.success {
128        let message = format!(
129            "[Resume] snapshot prepare skipped: could not start {}: {}",
130            session_name,
131            detail(&started, "docker start failed")
132        );
133        reporter.report(&message);
134        return (false, message);
135    }
136    let timeout = positive_seconds(
137        std::env::var("START_SNAPSHOT_PREPARE_TIMEOUT").ok(),
138        DEFAULT_PREPARE_TIMEOUT_SECONDS,
139    );
140    let result = runner.run_with_timeout(
141        &docker,
142        &[
143            "exec".into(),
144            session_name.into(),
145            "sh".into(),
146            "-c".into(),
147            prepare.into(),
148        ],
149        Duration::from_secs_f64(timeout),
150    );
151    // Never commit a running original, and never leave it running.
152    runner.run(&docker, &["kill".into(), session_name.into()]);
153    runner.run(&docker, &["wait".into(), session_name.into()]);
154    let message = if result.success {
155        format!("[Resume] snapshot prepare finished in {}", session_name)
156    } else {
157        format!(
158            "[Resume] snapshot prepare failed in {} ({}); snapshotting the files as they are",
159            session_name,
160            detail(&result, "docker exec failed")
161        )
162    };
163    reporter.report(&message);
164    (result.success, message)
165}
166
167/// Remove the stopped original once the replacement has survived the delay.
168/// Returns the note describing what happened.
169pub fn remove_original_after<R: CommandRunner + ?Sized>(
170    original: &str,
171    replacement: &str,
172    delay_seconds: f64,
173    runner: &R,
174    reporter: &SnapshotReporter,
175    sleep: &dyn Fn(Duration),
176) -> String {
177    reporter.report(&format!(
178        "[Resume] Checking {} again in {} before removing {}",
179        replacement,
180        format_elapsed(delay_seconds),
181        original
182    ));
183    sleep(Duration::from_secs_f64(delay_seconds.max(0.0)));
184    let docker = docker_command().to_string_lossy().to_string();
185    let running = runner.run(
186        &docker,
187        &[
188            "inspect".into(),
189            "-f".into(),
190            "{{.State.Running}}".into(),
191            replacement.into(),
192        ],
193    );
194    let note = if running.success && running.stdout.trim() == "true" {
195        let removed = runner.run(&docker, &["rm".into(), original.into()]);
196        if removed.success {
197            format!("Stopped original container removed: {}", original)
198        } else {
199            format!(
200                "Original container retained: {}",
201                detail(&removed, "docker rm failed")
202            )
203        }
204    } else {
205        format!(
206            "Original container retained: the snapshot container is not running {} after launch.",
207            format_elapsed(delay_seconds)
208        )
209    };
210    reporter.log(&note);
211    note
212}
213
214#[cfg(test)]
215mod tests {
216    use super::*;
217
218    #[test]
219    fn formats_elapsed_like_the_js_edition() {
220        assert_eq!(format_elapsed(45.9), "45s");
221        assert_eq!(format_elapsed(60.0), "1 min");
222        assert_eq!(format_elapsed(125.0), "2 min 5s");
223        assert_eq!(format_elapsed(-3.0), "0s");
224    }
225}