start_command/
status_probe.rs

1//! Live probing of a detached execution's backend.
2//!
3//! Split out of `status_formatter` so that "what is this session doing right
4//! now" (a `docker inspect`, a `screen -ls`, a `/proc` lookup) stays separate
5//! from "how do we render a record". Both halves are needed by `--status`, and
6//! together they no longer fit in one file under the repository's 1000-line
7//! budget.
8
9use crate::detached_finalize::{
10    END_TIME_SOURCE_DOCKER_FINISHED_AT, END_TIME_SOURCE_LOG_FOOTER, END_TIME_SOURCE_OBSERVED_AT,
11};
12use crate::docker_cleanup::docker_command;
13use crate::docker_post_mortem::normalize_docker_timestamp;
14use crate::execution_attempt::read_attempt_log_tail;
15use crate::execution_store::{ExecutionRecord, ExecutionStatus};
16use crate::isolation::isolation_log::FATAL_MARKER_TAIL_BYTES;
17use crate::status_footer::parse_footer_from_tail;
18use crate::status_footer::LogFooter;
19use chrono::Utc;
20use std::process::Command;
21
22/// Live state of a detached docker container by name.
23#[derive(Clone, Default)]
24pub struct DockerState {
25    pub running: bool,
26    exit_code: Option<i32>,
27    oom_killed: Option<bool>,
28    /// `.State.StartedAt`, normalized (issue #171.1).
29    started_at: Option<String>,
30    /// `.State.FinishedAt`, normalized — the authoritative finish time of a
31    /// detached container, and the reason `--status` no longer has to invent
32    /// one (issue #170.2).
33    finished_at: Option<String>,
34}
35
36impl DockerState {
37    /// Exit evidence for a stopped `137` container whose watcher never logged
38    /// any (issue #241).
39    pub fn lost_watcher_evidence(&self, record: &ExecutionRecord) -> Option<serde_json::Value> {
40        if self.running || self.exit_code != Some(137) {
41            return None;
42        }
43        crate::exit_evidence::collect_lost_watcher_evidence(
44            record,
45            self.finished_at.as_deref()?,
46            self.oom_killed,
47            &crate::execution_control::SystemCommandRunner,
48        )
49    }
50}
51
52/// Inspect the live state of a detached docker container by name.
53///
54/// Distinguishes "running", "stopped (with a real exit code)", and "cannot be
55/// inspected at all". The last case matters on slow Docker-in-Docker hosts
56/// (issue #136): right after `docker run -d` returns, `docker inspect <name>`
57/// can transiently fail because the container is not visible yet. A failed
58/// inspect must NOT be read as "stopped"; it means "unknown", so callers can
59/// keep the session running instead of fabricating a terminal `-1` result.
60///
61/// Returns None when the container cannot be inspected (not found yet, removed,
62/// or docker error).
63pub(crate) fn inspect_docker_state(session_name: &str) -> Option<DockerState> {
64    let format = concat!(
65        "{{.State.Running}} {{.State.ExitCode}} {{.State.OOMKilled}} ",
66        "{{.State.StartedAt}} {{.State.FinishedAt}}"
67    );
68    // Answered by the query's batched inspect when it has one (issue #243).
69    let stdout = match crate::docker_inspect_batch::prefetched_inspect(format, session_name) {
70        Some(answer) if answer.success => answer.stdout,
71        Some(_) => return None,
72        None => {
73            let output = Command::new(docker_command())
74                .args(["inspect", "-f", format, session_name])
75                .output()
76                .ok()?;
77            if !output.status.success() {
78                return None;
79            }
80            String::from_utf8_lossy(&output.stdout).to_string()
81        }
82    };
83    let trimmed = stdout.trim();
84    if trimmed.is_empty() {
85        return None;
86    }
87    let mut parts = trimmed.split_whitespace();
88    let running = parts.next() == Some("true");
89    let exit_code = parts.next().and_then(|value| value.parse::<i32>().ok());
90    let oom_killed = parts.next().and_then(|value| match value {
91        "true" => Some(true),
92        "false" => Some(false),
93        _ => None,
94    });
95    let started_at = normalize_docker_timestamp(parts.next());
96    let finished_at = normalize_docker_timestamp(parts.next());
97    Some(DockerState {
98        running,
99        exit_code,
100        oom_killed,
101        started_at,
102        finished_at,
103    })
104}
105
106pub(crate) fn is_detached_docker_record(record: &ExecutionRecord) -> bool {
107    record.options.get("isolated").and_then(|v| v.as_str()) == Some("docker")
108        && record.options.get("isolationMode").and_then(|v| v.as_str()) == Some("detached")
109        && record
110            .options
111            .get("sessionName")
112            .and_then(|v| v.as_str())
113            .is_some()
114}
115
116pub(crate) fn read_docker_state(record: &ExecutionRecord) -> Option<DockerState> {
117    if record.options.get("isolated")?.as_str()? != "docker" {
118        return None;
119    }
120    let session_name = record.options.get("sessionName")?.as_str()?;
121    if record.container_state.as_deref() == Some(crate::container_removal::CONTAINER_STATE_REMOVED)
122    {
123        // A removed container stays removed: a relaunch clears the marker, so
124        // there is nothing left to ask Docker (issue #243).
125        return None;
126    }
127    let state = inspect_docker_state(session_name)?;
128    if let Some(attempt) = &record.attempt {
129        let older = state
130            .started_at
131            .as_deref()
132            .and_then(|s| chrono::DateTime::parse_from_rfc3339(s).ok())
133            .zip(chrono::DateTime::parse_from_rfc3339(&attempt.started_at).ok())
134            .is_some_and(|(started, since)| started < since);
135        if older {
136            return None;
137        }
138    }
139    Some(state)
140}
141
142/// Best-effort terminal exit code reported by the isolation backend itself
143/// (currently docker via `docker inspect .State.ExitCode`). Returns None when
144/// the backend cannot provide a real code, so callers never surface the `-1`
145/// sentinel for a session whose real exit code is simply not available yet.
146/// A running container has no terminal exit code (docker reports `0` for it),
147/// so only a stopped container contributes one.
148pub(crate) fn backend_exit_code(docker_state: Option<&DockerState>) -> Option<i32> {
149    let state = docker_state?;
150    if state.running {
151        None
152    } else {
153        state.exit_code
154    }
155}
156
157/// Reconcile the OOM observation from the stored record and from `docker inspect`.
158///
159/// `State.OOMKilled` is a container-cgroup flag: the kernel sets it when ANY
160/// process in the cgroup is OOM-killed and it is never cleared for the life of
161/// the container (moby/moby#47618). It is therefore an *observation*, never a
162/// verdict about the session (issue #151) — a container that lost one child
163/// process keeps running and can still exit `0`. Once observed, the flag stays
164/// `true` for the record.
165pub(crate) fn resolve_oom_observation(
166    record: &ExecutionRecord,
167    docker_state: Option<&DockerState>,
168) -> Option<bool> {
169    let inspected = docker_state.and_then(|state| state.oom_killed);
170    if record.oom_killed == Some(true) || inspected == Some(true) {
171        return Some(true);
172    }
173    if record.oom_killed == Some(false) || inspected == Some(false) {
174        return Some(false);
175    }
176    None
177}
178
179/// Check if a detached isolation session is still running
180/// Returns Some(true) if running, Some(false) if not, None if unable to determine
181pub fn is_detached_session_alive(record: &ExecutionRecord) -> Option<bool> {
182    let session_name = record.options.get("sessionName")?.as_str()?;
183    let isolation_mode = record.options.get("isolationMode")?.as_str()?;
184    let isolated = record.options.get("isolated")?.as_str()?;
185
186    if isolation_mode != "detached" {
187        return None;
188    }
189
190    match isolated {
191        "screen" => {
192            let output = Command::new("screen").args(["-ls"]).output().ok()?;
193            let stdout = String::from_utf8_lossy(&output.stdout);
194            Some(stdout.contains(session_name))
195        }
196        "tmux" => {
197            let status = Command::new("tmux")
198                .args(["has-session", "-t", session_name])
199                .output()
200                .ok()?;
201            Some(status.status.success())
202        }
203        "docker" => {
204            // A failed inspect means the container is not visible yet (still
205            // being created on a slow DinD host) or already removed — not
206            // "stopped". Return None (unknown) so the session is not falsely
207            // marked finished (issue #136).
208            inspect_docker_state(session_name).map(|state| state.running)
209        }
210        "ssh" => {
211            // For SSH, check if the local wrapper PID is still running
212            #[cfg(unix)]
213            {
214                if let Some(pid) = record.pid {
215                    let result = unsafe { libc::kill(pid as i32, 0) };
216                    Some(result == 0)
217                } else {
218                    None
219                }
220            }
221            #[cfg(not(unix))]
222            {
223                let _ = record.pid;
224                None
225            }
226        }
227        _ => None,
228    }
229}
230
231/// Set `end_time` on a record that just became terminal, and record where the
232/// timestamp came from (issue #170.2).
233///
234/// Precedence: the container's own `State.FinishedAt`, then the anchored
235/// `Finished:` footer `start` wrote, and only then the time the end was
236/// *observed* — which is marked as such instead of masquerading as a finish
237/// time, the way an unconditional `Utc::now()` used to.
238pub(crate) fn apply_end_time(
239    record: &mut ExecutionRecord,
240    docker_state: Option<&DockerState>,
241    footer: &LogFooter,
242) {
243    if let Some(started_at) = docker_state.and_then(|state| state.started_at.clone()) {
244        record.container_started_at = Some(started_at);
245    }
246    if record.end_time.is_some() {
247        return;
248    }
249    if let Some(finished_at) = docker_state.and_then(|state| state.finished_at.clone()) {
250        record.end_time = Some(finished_at);
251        record.end_time_source = Some(END_TIME_SOURCE_DOCKER_FINISHED_AT.to_string());
252        return;
253    }
254    if let Some(finished_at) = footer.finished_at.clone() {
255        record.end_time = Some(finished_at);
256        record.end_time_source = Some(END_TIME_SOURCE_LOG_FOOTER.to_string());
257        return;
258    }
259    let now = Utc::now().to_rfc3339();
260    record.end_time = Some(now.clone());
261    record.end_time_source = Some(END_TIME_SOURCE_OBSERVED_AT.to_string());
262    record.observed_at = Some(now);
263}
264
265/// Reconcile the stored status of a detached execution with its live session.
266/// If a record shows "executing" but the detached session has actually ended,
267/// returns an updated copy with status "executed". If it shows "executed" but
268/// the session is still running, returns a copy with status "executing".
269pub(crate) fn resolve_detached_status(record: &ExecutionRecord) -> ExecutionRecord {
270    if crate::launch_owner::has_active_launch(record) {
271        return record.clone();
272    }
273    let tail = read_attempt_log_tail(record, FATAL_MARKER_TAIL_BYTES);
274    let footer = parse_footer_from_tail(tail.as_deref().unwrap_or(""));
275    let footer_exit = footer.exit_code;
276    let is_detached_docker = is_detached_docker_record(record);
277    let docker_state = if is_detached_docker {
278        read_docker_state(record)
279    } else {
280        None
281    };
282
283    // `oomKilled` is exposed alongside the status, but never decides it (#151).
284    let oom_killed = resolve_oom_observation(record, docker_state.as_ref());
285    let clone_record = || {
286        let mut enriched = record.clone();
287        if oom_killed.is_some() {
288            enriched.oom_killed = oom_killed;
289        }
290        enriched
291    };
292
293    let alive = if is_detached_docker {
294        docker_state.as_ref().map(|state| state.running)
295    } else {
296        is_detached_session_alive(record)
297    };
298
299    let alive = match alive {
300        Some(value) => value,
301        None => {
302            // Liveness is unknown: the backend could not be probed (e.g. a
303            // detached docker container that is not visible yet on a slow
304            // Docker-in-Docker host, or one that has already been removed).
305            // Honor a terminal `Exit Code:` footer if the command wrote one;
306            // otherwise leave the record untouched (still executing) rather than
307            // fabricating a `-1` terminal result that orchestrators misread as a
308            // finished/failed run (issue #136).
309            let is_detached =
310                record.options.get("isolationMode").and_then(|v| v.as_str()) == Some("detached");
311            if is_detached && record.status == ExecutionStatus::Executing {
312                if footer_exit.is_some() {
313                    let mut enriched = clone_record();
314                    enriched.status = ExecutionStatus::Executed;
315                    enriched.exit_code = footer_exit;
316                    apply_end_time(&mut enriched, docker_state.as_ref(), &footer);
317                    return enriched;
318                }
319                if oom_killed == Some(true) {
320                    // The container is gone and wrote no footer, so the OOM
321                    // observation is the only evidence left: report the session
322                    // as finished with the conventional SIGKILL code (issue
323                    // #148). While the container is still inspectable this
324                    // branch is never taken — a live container keeps the session
325                    // `executing` no matter what the cgroup flag says (#151).
326                    let mut enriched = clone_record();
327                    enriched.status = ExecutionStatus::Executed;
328                    enriched.exit_code = Some(137);
329                    apply_end_time(&mut enriched, docker_state.as_ref(), &footer);
330                    return enriched;
331                }
332            }
333            return clone_record();
334        }
335    };
336
337    let mut enriched = clone_record();
338
339    if alive && enriched.status == ExecutionStatus::Executed {
340        // A live `screen -ls` (or `tmux`/`docker`) session does NOT mean the command
341        // is still running: a lingering shell can outlive a killed command (e.g. the
342        // OOM killer sends SIGKILL, exit 137, but the login shell stays up for a
343        // window after `start` already wrote the terminal footer). The footer/recorded
344        // exit code is authoritative. Only flip back to "executing" when there is NO
345        // recorded terminal exit code AND no `Exit Code:` footer in the log.
346        if enriched.exit_code.is_none() && footer_exit.is_none() {
347            // Session still running and no terminal record - correct it
348            enriched.status = ExecutionStatus::Executing;
349            enriched.exit_code = None;
350            enriched.end_time = None;
351            enriched.end_time_source = None;
352        }
353        // Otherwise keep the recorded/footer exit code - the command has finished.
354    } else if !alive && enriched.status == ExecutionStatus::Executing {
355        // Session ended but record says executing - correct it. Resolve a real
356        // exit code: prefer the backend's own record (e.g. `docker inspect
357        // .State.ExitCode`, which is authoritative and cannot be spoofed by
358        // command output — issue #150), then the anchored log footer, then
359        // `137` when the only evidence left is the OOM observation, and only
360        // fall back to the `-1` sentinel as a last resort when no real code can
361        // be obtained (issues #136, #151).
362        enriched.status = ExecutionStatus::Executed;
363        if enriched.exit_code.is_none() {
364            enriched.exit_code = Some(
365                backend_exit_code(docker_state.as_ref())
366                    .or(footer_exit)
367                    .or(if oom_killed == Some(true) {
368                        Some(137)
369                    } else {
370                        None
371                    })
372                    .unwrap_or(-1),
373            );
374        }
375        apply_end_time(&mut enriched, docker_state.as_ref(), &footer);
376        crate::exit_evidence::add_lost_watcher_evidence(
377            &mut enriched,
378            record,
379            docker_state.as_ref(),
380            tail.as_deref(),
381        );
382    }
383
384    enriched
385}
start_command/status_probe.rs

start_command/
status_probe.rs
