start_command/
detached_finalize.rs

1//! Detached completion finalizer (issue #170).
2//!
3//! A detached Docker session outlives the CLI process that started it: the
4//! foreground `start` invocation returns as soon as the container is up, so
5//! nobody is left to write the terminal state back into the execution store.
6//! The record therefore stayed `executing` forever, with `exitCode: null` and
7//! `endTime: null`, and every `--status` query had to re-derive the outcome from
8//! scratch — fabricating `endTime` with the current time in the process.
9//!
10//! The detached completion watcher (see `docker_cleanup`) now re-invokes the
11//! `start` binary with a hidden flag once the container is gone, handing over
12//! the facts it already read out of a single `docker inspect`. The finalizer is
13//! deliberately silent and infallible: it is a short-lived child process on a
14//! host whose CLI invocation is long gone, so a bookkeeping failure must never
15//! surface as an error in a log the user is reading for the command's output.
16
17use std::path::PathBuf;
18
19use chrono::Utc;
20use serde_json::Value;
21
22use crate::docker_post_mortem::{normalize_docker_timestamp, shell_vars};
23use crate::execution_store::{
24    ExecutionRecord, ExecutionStatus, ExecutionStore, ExecutionStoreOptions,
25};
26use crate::exit_reason::{describe_exit_code_str, resolve_exit_reason};
27use crate::isolation::isolation_log::{read_log_tail, shell_quote, FATAL_MARKER_TAIL_BYTES};
28
29/// Hidden argument the detached watcher re-invokes this binary with.
30/// Not part of the public CLI surface: it is an implementation detail of the
31/// watcher, and `--help` stays free of it.
32pub const INTERNAL_FINALIZE_FLAG: &str = "--internal-finalize-detached-docker";
33
34/// `end_time` came from `docker inspect .State.FinishedAt` — the container's
35/// own clock, the only real finish time available.
36pub const END_TIME_SOURCE_DOCKER_FINISHED_AT: &str = "docker-finished-at";
37/// `end_time` came from the anchored `Finished:` line `start` itself wrote.
38pub const END_TIME_SOURCE_LOG_FOOTER: &str = "log-footer";
39/// No real finish time exists: this is when the end was *observed*.
40pub const END_TIME_SOURCE_OBSERVED_AT: &str = "observed-at";
41
42/// The docker facts the watcher hands over.
43#[derive(Debug, Clone, Default)]
44pub struct DetachedFinalizeFacts {
45    pub exit_code: String,
46    pub oom_killed: String,
47    pub started_at: String,
48    pub finished_at: String,
49    pub container_error: String,
50}
51
52/// Outcome of a finalization attempt. `updated` is false when there was
53/// nothing to correct (or nothing to correct it on).
54#[derive(Debug, Clone, PartialEq, Eq)]
55pub struct FinalizeOutcome {
56    pub updated: bool,
57    pub reason: String,
58}
59
60fn normalize_bool(value: &str) -> Option<bool> {
61    match value.trim() {
62        "true" => Some(true),
63        "false" => Some(false),
64        _ => None,
65    }
66}
67
68fn normalize_container_error(value: &str) -> Option<String> {
69    let trimmed = value.trim();
70    if trimmed.is_empty() || trimmed == "<no value>" || trimmed == "(none)" {
71        None
72    } else {
73        Some(trimmed.to_string())
74    }
75}
76
77/// Persist the terminal state of a detached execution.
78///
79/// Purely additive with respect to the observation-vs-verdict discipline of
80/// issues #148/#151/#162: `oom_killed` and `exit_reason` are recorded as facts
81/// next to the exit code, never as a substitute for it.
82pub fn finalize_detached_execution(
83    store: &ExecutionStore,
84    execution_id: &str,
85    facts: &DetachedFinalizeFacts,
86) -> FinalizeOutcome {
87    if execution_id.is_empty() {
88        return FinalizeOutcome {
89            updated: false,
90            reason: "missing-arguments".to_string(),
91        };
92    }
93    let mut record = match store.get(execution_id) {
94        Some(record) => record,
95        None => {
96            return FinalizeOutcome {
97                updated: false,
98                reason: "record-not-found".to_string(),
99            }
100        }
101    };
102    if record.status == ExecutionStatus::Executed && record.end_time.is_some() {
103        // Already finalized (e.g. a `--status` query got there first, or the
104        // watcher ran twice after a resume). Nothing to correct.
105        return FinalizeOutcome {
106            updated: false,
107            reason: "already-final".to_string(),
108        };
109    }
110
111    let described = describe_exit_code_str(&facts.exit_code);
112    record.status = ExecutionStatus::Executed;
113    match described.code {
114        Some(code) => record.exit_code = Some(code),
115        None => {
116            if record.exit_code.is_none() {
117                record.exit_code = Some(-1);
118            }
119        }
120    }
121
122    match normalize_docker_timestamp(Some(&facts.finished_at)) {
123        Some(finished_at) => {
124            record.end_time = Some(finished_at);
125            record.end_time_source = Some(END_TIME_SOURCE_DOCKER_FINISHED_AT.to_string());
126        }
127        None => {
128            // Docker has no finish time for this container (it never started, or
129            // it was removed before we could look). Record *when we noticed*,
130            // and say so, rather than passing observation time off as a finish
131            // time (issue #170.2).
132            let now = Utc::now().to_rfc3339();
133            record.end_time = Some(now.clone());
134            record.end_time_source = Some(END_TIME_SOURCE_OBSERVED_AT.to_string());
135            record.observed_at = Some(now);
136        }
137    }
138
139    if let Some(started_at) = normalize_docker_timestamp(Some(&facts.started_at)) {
140        record.container_started_at = Some(started_at);
141    }
142    if let Some(oom_killed) = normalize_bool(&facts.oom_killed) {
143        record.oom_killed = Some(oom_killed);
144    }
145    if let Some(reason) = resolve_reason(&record) {
146        record.exit_reason = Some(reason);
147    }
148    if let Some(error) = normalize_container_error(&facts.container_error) {
149        record
150            .options
151            .insert("containerError".to_string(), Value::String(error));
152    }
153
154    match store.save(&record) {
155        Ok(()) => FinalizeOutcome {
156            updated: true,
157            reason: "finalized".to_string(),
158        },
159        Err(error) => FinalizeOutcome {
160            updated: false,
161            reason: format!("save-failed: {}", error),
162        },
163    }
164}
165
166/// Derive the `exit_reason` hint from the same evidence `--status` would use.
167fn resolve_reason(record: &ExecutionRecord) -> Option<String> {
168    let tail = if record.log_path.is_empty() {
169        None
170    } else {
171        read_log_tail(&record.log_path, FATAL_MARKER_TAIL_BYTES)
172    };
173    resolve_exit_reason(record.exit_code, tail.as_deref(), record.oom_killed)
174}
175
176/// Reconcile an in-memory record with one the detached watcher already
177/// finalized.
178///
179/// A container that exits almost immediately can be finalized by the watcher
180/// before the foreground `start` invocation writes its own last update. Saving
181/// the stale in-memory copy would resurrect `status: executing` and throw the
182/// terminal facts away, so the stored record wins and only the fields the
183/// foreground process learned (its `options`, e.g. `containerId`) are merged in.
184pub fn reconcile_finalized_record(
185    store: &ExecutionStore,
186    record: &ExecutionRecord,
187) -> ExecutionRecord {
188    let stored = match store.get(&record.uuid) {
189        Some(stored) => stored,
190        None => return record.clone(),
191    };
192    if stored.status != ExecutionStatus::Executed || stored.end_time.is_none() {
193        return record.clone();
194    }
195    let mut merged = stored;
196    for (key, value) in &record.options {
197        merged.options.insert(key.clone(), value.clone());
198    }
199    merged
200}
201
202/// Shell fragment that hands the inspected docker facts to this finalizer.
203///
204/// Runs the same binary that started the session and is suffixed with
205/// `|| true`, so a finalization failure can never abort the watcher's remaining
206/// cleanup work.
207pub fn build_detached_finalize_snippet(execution_id: &str) -> String {
208    let executable = std::env::current_exe()
209        .map(|path| path.to_string_lossy().to_string())
210        .unwrap_or_else(|_| "start".to_string());
211    format!(
212        "{} {} {} \"${}\" \"${}\" \"${}\" \"${}\" \"${}\" >/dev/null 2>&1 || true",
213        shell_quote(&executable),
214        INTERNAL_FINALIZE_FLAG,
215        shell_quote(execution_id),
216        shell_vars::EXIT,
217        shell_vars::OOM,
218        shell_vars::STARTED,
219        shell_vars::FINISHED,
220        shell_vars::ERROR,
221    )
222}
223
224/// Entry point for `--internal-finalize-detached-docker <uuid> <exit> <oom>
225/// <started> <finished> <error>`. Always succeeds: see the module docs.
226pub fn run_internal_finalize(args: &[String]) {
227    let execution_id = match args.first() {
228        Some(value) if !value.is_empty() => value.clone(),
229        _ => return,
230    };
231    if std::env::var("START_DISABLE_TRACKING").as_deref() == Ok("true") {
232        return;
233    }
234    let field = |index: usize| args.get(index).cloned().unwrap_or_default();
235    let store = ExecutionStore::with_options(ExecutionStoreOptions {
236        app_folder: std::env::var("START_APP_FOLDER").ok().map(PathBuf::from),
237        ..ExecutionStoreOptions::default()
238    });
239    finalize_detached_execution(
240        &store,
241        &execution_id,
242        &DetachedFinalizeFacts {
243            exit_code: field(1),
244            oom_killed: field(2),
245            started_at: field(3),
246            finished_at: field(4),
247            container_error: field(5),
248        },
249    );
250}
start_command/detached_finalize.rs

start_command/
detached_finalize.rs
