diff --git a/README.md b/README.md index df2955900..aad82c737 100644 --- a/README.md +++ b/README.md @@ -875,7 +875,11 @@ can: - Press **Ctrl-D** to detach. The log stream stops, your shell comes back, and the server keeps running. Manage it afterward with `rocm services`. -- Press **Ctrl-C** to stop the server instead. +- Press **Ctrl-C** to stop the server instead. If the stop answers that it + could not confirm the server's process exited, the command prints the same + report as `rocm services stop` on stderr and exits with an error. If the stop + itself fails, the command says why on stderr, signals the server process + directly and exits 0; if that signal fails too, it says so on stderr. `--managed` is the explicit form of the default background behavior. `--no-smoke-test` skips the post-startup inference probe. @@ -917,6 +921,16 @@ rocm services remove --yes rocm services prune [--older-than-hours | --any-age] [--dry-run] [--yes] ``` +`stop` reports a server stopped only once every recorded process is confirmed +gone. If it cannot confirm that, it prints `Local server stop not confirmed` on +stderr and exits with an error. It keeps the record, which still names the +processes, and any endpoint key, which the server may still be enforcing. It +names each process that, or a process under it, did not exit after it was +signaled; for a process it could not verify as the server's, it signals nothing +and names an operating-system command to check on it. It does not suggest +running the stop again: when only a process under the recorded one survived, a +second stop can report the server stopped while that process still runs. + `restart` starts a server again only once its stop has confirmed that every recorded process is gone; if the stop cannot confirm that, it says so, starts nothing, and leaves the stop request recorded. diff --git a/apps/rocm/src/main.rs b/apps/rocm/src/main.rs index 9b2bd7b93..b74470286 100644 --- a/apps/rocm/src/main.rs +++ b/apps/rocm/src/main.rs @@ -112,7 +112,7 @@ use crate::serve_cmd::{ServeArgs, select_serve_engine, serve}; use crate::services_text::{ load_managed_service, render_internal_status_text, render_logs_browser_text, render_logs_text, render_service_action_result, render_service_logs_text, render_services_json, - render_services_text, run_internal_sandbox_tool, validate_service_id, + render_services_text, run_internal_sandbox_tool, service_stop_unconfirmed, validate_service_id, }; use crate::uninstall::uninstall; use crate::uninstall_plan::UninstallOptions; @@ -499,7 +499,10 @@ rocm model --verbose" /// server runs as a managed background service and prints a deployment summary /// (status, endpoint, model, and smoke-test metrics); use --verbose to stream engine /// logs in this terminal instead. When streaming, press Ctrl-D to detach and leave the - /// server running, or Ctrl-C to stop it. Inspect or stop servers later with + /// server running, or Ctrl-C to stop it. If that stop answers that it could not confirm + /// the server exited, it says so on stderr and exits with an error; if the stop itself + /// fails, it says why on stderr, signals the server process directly and exits 0, + /// noting on stderr if that signal fails too. Inspect or stop servers later with /// `rocm services`. #[command(after_help = "EXAMPLES:\n \ rocm serve qwen\n \ @@ -1095,6 +1098,14 @@ enum ServicesCommand { service_id: String, }, /// Stop a local model server. + /// + /// Reports the server stopped only once every process it recorded is + /// confirmed gone. Otherwise it reports on stderr that the stop was not + /// confirmed and exits with an error, keeping the record, which still names + /// the processes, and any endpoint key, which the server may still be + /// enforcing. It names each process that did not exit, and for one it could + /// not verify it signals nothing and names an operating-system command to + /// check on it. It does not suggest running the stop again. Stop { /// Service id from `rocm services list`. service_id: String, @@ -3916,7 +3927,36 @@ fn run_approved_service_action( } let sandbox_tool = sandbox_tool_arg_from_service_tool(tool)?; let result = run_internal_sandbox_tool(paths, sandbox_tool, Some(service_id.to_owned()), true)?; - print!("{}", render_service_action_result(tool, &result)); + print!( + "{}", + finish_service_action(paths, tool, service_id, &result)? + ); + Ok(()) +} + +/// The text a completed `rocm services --yes` prints, with its audit +/// event. A stop that could not confirm every recorded process gone is an +/// error, not a success with a caveat: the same verdict `rocmd`'s MCP +/// `stop_server` reports as `isError`, and a script chaining on the exit status +/// must not move on as if the service were down. +pub(crate) fn finish_service_action( + paths: &AppPaths, + tool: &str, + service_id: &str, + result: &serde_json::Value, +) -> Result { + let rendered = render_service_action_result(tool, result); + if tool == "stop_server" && service_stop_unconfirmed(result) { + record_cli_audit_event( + paths, + "service", + tool, + "error", + format!("stop of managed service {service_id} not confirmed"), + Some(service_id), + ); + bail!("{}", rendered.trim_end()); + } record_cli_audit_event( paths, "service", @@ -3928,7 +3968,7 @@ fn run_approved_service_action( ), Some(service_id), ); - Ok(()) + Ok(rendered) } fn sandbox_tool_arg_from_service_tool(tool: &str) -> Result { diff --git a/apps/rocm/src/service_launch.rs b/apps/rocm/src/service_launch.rs index c00872ed0..db0eba06c 100644 --- a/apps/rocm/src/service_launch.rs +++ b/apps/rocm/src/service_launch.rs @@ -59,7 +59,9 @@ use crate::managed_service_status::existing_live_managed_service; use crate::service_hints; #[cfg(not(windows))] use crate::services_text::read_optional_tail_lines; -use crate::services_text::{render_service_action_result, run_internal_sandbox_tool}; +use crate::services_text::{ + render_service_action_result, run_internal_sandbox_tool, service_stop_unconfirmed, +}; use crate::{SandboxToolArg, device_policy_name, record_cli_audit_event, status_for_readiness}; pub(crate) fn validate_bind_host(host: &str, allow_public_bind: bool) -> Result<()> { @@ -976,29 +978,21 @@ pub(crate) fn run_attached_service( } AttachOutcome::Stop => { println!("stopping server..."); - match run_internal_sandbox_tool( + let stop = run_internal_sandbox_tool( &paths, SandboxToolArg::StopServer, Some(service_id.clone()), true, - ) { - Ok(result) => print!("{}", render_service_action_result("stop_server", &result)), - Err(error) => { - // Best-effort direct signal so Ctrl-C never leaves the model - // orphaned when the sandbox stop path fails. - let _ = rocm_core::terminate_process_tree(child_pid); - println!(" note: {error}"); - } - } - record_cli_audit_event( - &paths, - "service", - "serve_stop", - "info", - format!("stopped attached serve service_id={service_id}"), - Some(&service_id), ); - Ok(()) + finish_attached_stop( + &paths, + &service_id, + child_pid, + stop, + rocm_core::terminate_process_tree, + &mut io::stdout().lock(), + &mut io::stderr().lock(), + ) } AttachOutcome::ServerExited => { println!("server process exited"); @@ -1156,6 +1150,91 @@ fn stream_attached_logs_no_tty(log_path: &Path, child_pid: u32) -> Result, + signal_child: impl FnOnce(u32) -> Result<()>, + out: &mut dyn Write, + err: &mut dyn Write, +) -> Result<()> { + match stop { + Ok(result) if service_stop_unconfirmed(&result) => { + record_cli_audit_event( + paths, + "service", + "serve_stop", + "error", + format!("stop of attached serve not confirmed service_id={service_id}"), + Some(service_id), + ); + bail!( + "{}", + render_service_action_result("stop_server", &result).trim_end() + ) + } + Ok(result) => { + write!( + out, + "{}", + render_service_action_result("stop_server", &result) + )?; + record_cli_audit_event( + paths, + "service", + "serve_stop", + "info", + format!("stopped attached serve service_id={service_id}"), + Some(service_id), + ); + Ok(()) + } + Err(error) => { + let signal = signal_child(child_pid); + writeln!(err, " note: {error:#}")?; + if let Err(signal_error) = &signal { + writeln!( + err, + " note: signaling this session's server process {child_pid} directly also failed: {signal_error:#}" + )?; + } + let message = match &signal { + Ok(()) => format!( + "stop failed; signaled attached serve child {child_pid} service_id={service_id}" + ), + Err(signal_error) => format!( + "stop failed; signaling attached serve child {child_pid} also failed: {signal_error:#} service_id={service_id}" + ), + }; + record_cli_audit_event( + paths, + "service", + "serve_stop", + if signal.is_ok() { "warn" } else { "error" }, + message, + Some(service_id), + ); + Ok(()) + } + } +} + #[cfg(test)] mod tests { use super::*; @@ -1174,6 +1253,179 @@ mod tests { validate_bind_host("0.0.0.0", true).unwrap(); } + /// A `stop_server` answer whose one recorded process ended with `outcome`. + fn stop_answer(confirmed: bool, outcome: &str) -> serde_json::Value { + crate::services_text::internal_stop_server_value(serde_json::json!({ + "service_id": "svc-attached", + "status": "ready", + "signaled_pids": if outcome == "unverified" { vec![] } else { vec![4242] }, + "pid_outcomes": [{ "pid": 4242, "role": "supervisor_and_engine", "outcome": outcome }], + // An attached serve on a public bind stores a key; an unconfirmed + // stop keeps it. + "endpoint_key_kept": !confirmed, + "stopped": confirmed, + })) + } + + /// Run [`finish_attached_stop`] for `stop`, returning its result, what it + /// wrote to stdout, the PID it signalled (if any) and the audit event. + fn finish( + name: &str, + stop: Result, + ) -> (Result<()>, String, Option, serde_json::Value) { + finish_signalling(name, stop, Ok(())) + } + + /// [`finish`], with the direct signal answering `signal_result`. + fn finish_signalling( + name: &str, + stop: Result, + signal_result: Result<()>, + ) -> (Result<()>, String, Option, serde_json::Value) { + let (result, out, _err, signalled, audit) = finish_capturing(name, stop, signal_result); + (result, out, signalled, audit) + } + + /// [`finish_signalling`], also returning what was written to stderr. + fn finish_capturing( + name: &str, + stop: Result, + signal_result: Result<()>, + ) -> (Result<()>, String, String, Option, serde_json::Value) { + let (root, paths) = test_paths(name); + paths.ensure().unwrap(); + let mut out = Vec::new(); + let mut err = Vec::new(); + let mut signalled = None; + let result = finish_attached_stop( + &paths, + "svc-attached", + 777, + stop, + |pid| { + signalled = Some(pid); + signal_result + }, + &mut out, + &mut err, + ); + let audit_text = fs::read_to_string(paths.audit_events_path()).expect("audit log"); + let audit = serde_json::from_str(audit_text.lines().last().expect("an audit event")) + .expect("audit json"); + let _ = fs::remove_dir_all(root); + ( + result, + String::from_utf8(out).unwrap(), + String::from_utf8(err).unwrap(), + signalled, + audit, + ) + } + + #[test] + fn attached_ctrl_c_reports_a_confirmed_stop_on_stdout() { + let (result, out, signalled, audit) = + finish("attached-confirmed", Ok(stop_answer(true, "graceful"))); + result.expect("a confirmed stop succeeds"); + assert!(out.contains("Local server stopped"), "{out}"); + assert_eq!(signalled, None); + assert_eq!(audit["level"], "info", "{audit}"); + assert_eq!( + audit["message"], + "stopped attached serve service_id=svc-attached" + ); + } + + #[test] + fn attached_ctrl_c_fails_an_unconfirmed_stop_like_services_stop_and_signals_nothing() { + // The same report `rocm services stop` gives, as the error (stderr, + // non-zero exit), naming no retry; nothing is signalled on the stop's + // behalf and nothing reaches stdout. + let answer = stop_answer(false, "timed_out"); + let (result, out, signalled, audit) = finish("attached-timed-out", Ok(answer.clone())); + let error = format!("{:#}", result.expect_err("an unconfirmed stop fails")); + assert_eq!( + error, + render_service_action_result("stop_server", &answer).trim_end(), + "the report is `rocm services stop`'s own" + ); + assert!( + error.contains( + "process 4242 (supervisor_and_engine) or a process under it did not exit" + ), + "{error}" + ); + assert!( + error.lines().any(|line| line + == " kept: the server record, which still names its processes, and its endpoint key, which the server may still be enforcing"), + "{error}" + ); + crate::services_text::tests::assert_no_retry_line(&error); + assert!(out.is_empty(), "nothing on stdout: {out}"); + assert_eq!(signalled, None, "an unconfirmed stop signals nothing more"); + assert_eq!(audit["level"], "error", "{audit}"); + assert_eq!( + audit["message"], + "stop of attached serve not confirmed service_id=svc-attached" + ); + } + + #[test] + fn attached_ctrl_c_names_a_check_for_an_unverified_process() { + let (result, out, signalled, audit) = + finish("attached-unverified", Ok(stop_answer(false, "unverified"))); + let error = format!("{:#}", result.expect_err("an unverified stop fails")); + assert!(error.contains("not signaled: process 4242"), "{error}"); + assert!(error.contains("check: `ps -p 4242 -o pid,args`"), "{error}"); + crate::services_text::tests::assert_no_retry_line(&error); + assert!(out.is_empty(), "{out}"); + assert_eq!(signalled, None); + assert_eq!(audit["level"], "error", "{audit}"); + } + + #[test] + fn attached_ctrl_c_signals_its_own_child_when_the_stop_itself_fails() { + let (result, out, err, signalled, audit) = finish_capturing( + "attached-stop-error", + Err(anyhow::anyhow!("managed service `svc-attached` not found") + .context("failed to stop svc-attached")), + Ok(()), + ); + result.expect("a failed stop falls back and still exits cleanly, as before"); + assert_eq!(signalled, Some(777)); + assert_eq!( + err, " note: failed to stop svc-attached: managed service `svc-attached` not found\n", + "the stop's error goes to stderr, and a signal that worked adds nothing" + ); + assert!(out.is_empty(), "nothing on stdout: {out}"); + assert_eq!(audit["level"], "warn", "{audit}"); + assert_eq!( + audit["message"], + "stop failed; signaled attached serve child 777 service_id=svc-attached" + ); + + // The direct signal failing too is printed on stderr and recorded, with + // its error. + let (result, _, err, signalled, audit) = finish_capturing( + "attached-stop-error-signal-fails", + Err(anyhow::anyhow!("managed service `svc-attached` not found")), + Err(anyhow::anyhow!("no such process")), + ); + result.expect("still exits 0, as on main"); + assert_eq!( + err, + " note: managed service `svc-attached` not found\n \ + note: signaling this session's server process 777 directly also failed: no such process\n", + "both notes go to stderr" + ); + assert_eq!(signalled, Some(777)); + assert_eq!(audit["level"], "error", "{audit}"); + assert_eq!( + audit["message"], + "stop failed; signaling attached serve child 777 also failed: no such process service_id=svc-attached" + ); + } + #[test] fn detach_key_ctrl_d_detaches_ctrl_c_stops() { assert_eq!(detach_key_outcome(true, 'd'), Some(AttachOutcome::Detach)); diff --git a/apps/rocm/src/services_text.rs b/apps/rocm/src/services_text.rs index 9626aecf3..f8dba3b40 100644 --- a/apps/rocm/src/services_text.rs +++ b/apps/rocm/src/services_text.rs @@ -537,6 +537,9 @@ fn render_service_logs_text_with_options( pub(crate) fn render_service_action_result(tool: &str, value: &serde_json::Value) -> String { let output = value.get("output").unwrap_or(value); + if tool == "stop_server" && service_stop_unconfirmed(value) { + return render_unconfirmed_service_stop(output); + } let action = service_action_past_tense(tool); let service = output.get("service").or_else(|| { output @@ -573,6 +576,143 @@ pub(crate) fn render_service_action_result(tool: &str, value: &serde_json::Value text } +/// A `stop_server` answer whose stop could not confirm that every recorded +/// process is gone. The stop kept the record's processes, its stop request and +/// any endpoint key (see [`stop_internal_managed_service_confirmed_with`]), so +/// this says so instead of claiming a stop, with a line for each reason it +/// found: +/// +/// - a process that was signalled and that, or a process under it, outlived +/// the deadline (`timed_out`); +/// - a process that was not signalled because its identity could not be +/// verified (`unverified`), with how to look at it. It may have exited +/// meanwhile: the identity read can fail because the process is going away; +/// - the record changed while the stop ran, typically because a restart +/// recorded new processes, so the stop's verdict says nothing about what the +/// record names now. +/// +/// It names no command to run the stop again, like `rocmd`'s MCP answer: a +/// second stop cannot be relied on to finish the job. When the recorded +/// process is gone and only a process under it survived, the second stop finds +/// the recorded one gone and confirms without reaching the survivor. +fn render_unconfirmed_service_stop(output: &serde_json::Value) -> String { + let result = output.get("result"); + let service_id = result + .and_then(|result| result.get("service_id")) + .and_then(serde_json::Value::as_str); + let outcomes = result + .and_then(|result| result.get("pid_outcomes")) + .and_then(serde_json::Value::as_array) + .map(Vec::as_slice) + .unwrap_or_default(); + let with_outcome = |label: &str| -> Vec<(u64, &str)> { + outcomes + .iter() + .filter(|entry| entry.get("outcome").and_then(serde_json::Value::as_str) == Some(label)) + .filter_map(|entry| { + Some(( + entry.get("pid").and_then(serde_json::Value::as_u64)?, + entry + .get("role") + .and_then(serde_json::Value::as_str) + .unwrap_or("process"), + )) + }) + .collect() + }; + let timed_out = with_outcome(rocm_core::TerminationOutcome::TimedOut.as_str()); + let unverified = with_outcome(rocm_core::TerminationOutcome::Unverified.as_str()); + + let mut text = String::new(); + let _ = writeln!(text, "Local server stop not confirmed"); + if let Some(service_id) = service_id { + let _ = writeln!(text, " service: {service_id}"); + } + // No `status:` line: a record the liveness refresh already read as + // `stopped` keeps that status through a stop that confirmed nothing, so + // printing it here would contradict the header. + if let Some(count) = result + .and_then(|result| result.get("signaled_pids")) + .and_then(serde_json::Value::as_array) + .map(Vec::len) + { + let _ = writeln!(text, " signaled processes: {count}"); + } + for (pid, role) in &timed_out { + let _ = writeln!( + text, + " still running: process {pid} ({role}) or a process under it did not exit after it was signaled" + ); + } + for (pid, role) in &unverified { + let _ = writeln!( + text, + " not signaled: process {pid} ({role}) could not be verified as this server's; it may still be running" + ); + } + let record_changed = result + .and_then(|result| result.get("record_changed")) + .and_then(serde_json::Value::as_bool) + .unwrap_or(false); + if record_changed { + let _ = writeln!( + text, + " note: the record changed while the stop ran, so it may now name processes this stop did not handle" + ); + } + if result + .and_then(|result| result.get("engine_stop_unconfirmed")) + .and_then(serde_json::Value::as_bool) + .unwrap_or(false) + { + let why = result + .and_then(|result| result.pointer("/engine_stop/error")) + .and_then(serde_json::Value::as_str) + .unwrap_or("it did not answer"); + let _ = writeln!(text, " not confirmed: the engine's own stop failed: {why}"); + } + let endpoint_key_kept = result + .and_then(|result| result.get("endpoint_key_kept")) + .and_then(serde_json::Value::as_bool) + .unwrap_or(false); + if endpoint_key_kept { + let _ = writeln!( + text, + " kept: the server record, which still names its processes, and its endpoint key, which the server may still be enforcing" + ); + } else { + let _ = writeln!( + text, + " kept: the server record, which still names its processes" + ); + } + for (pid, _) in &unverified { + let _ = writeln!( + text, + " check: `{}` shows whether process {pid} is still running; stop it yourself only if it belongs to this server", + process_check_command(*pid) + ); + } + if record_changed { + let _ = writeln!( + text, + " check: `rocm services` lists what the record names now" + ); + } + text +} + +/// A stock OS command that shows whether `pid` is running, for a process a +/// stop left alone because it could not verify it. Not a `rocm` command: the +/// CLI deliberately does not act on that process, so the user decides. +/// +/// A Linux command because only Linux can produce that outcome: it needs a +/// recorded start-time that can no longer be read back, and +/// `rocm_core::process_start_ticks` records one only on Linux. +fn process_check_command(pid: u64) -> String { + format!("ps -p {pid} -o pid,args") +} + /// A managed service's record exactly as it is on disk, without the engine-state /// and liveness refresh [`load_managed_service`] applies (and may persist). fn read_managed_service_manifest( @@ -651,13 +791,7 @@ pub(crate) fn run_internal_sandbox_tool( } SandboxToolArg::StopServer => { let service_id = service_id.context("stop_server requires --service-id")?; - let result = stop_internal_managed_service(paths, &service_id)?; - serde_json::json!({ - "tool": tool.as_cli_value(), - "status": "stopped", - "mutating": true, - "result": result, - }) + internal_stop_server_value(stop_internal_managed_service(paths, &service_id)?) } SandboxToolArg::RestartServer => { let service_id = service_id.context("restart_server requires --service-id")?; @@ -684,6 +818,32 @@ pub(crate) fn run_internal_sandbox_tool( /// after `SIGTERM` before escalating to `SIGKILL` and then reporting a timeout. const MANAGED_STOP_GRACE: Duration = Duration::from_secs(10); +/// One recorded PID's fate in a managed stop: the role the record gave it, and +/// what [`rocm_core::terminate_verified`] did about it. Kept per PID because the +/// outcomes that leave a stop unconfirmed are reported differently: a +/// `TimedOut` PID was signalled and it or a process under it outlived the +/// deadline, while an `Unverified` one is not signalled by this stop, and the +/// report names a command to check on it. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +struct RecordedPidOutcome { + pid: u32, + /// `supervisor`, `engine`, or `supervisor_and_engine` when the record names + /// one PID for both — the same labels `rocmd`'s `pid_outcomes` uses. + role: &'static str, + outcome: rocm_core::TerminationOutcome, +} + +/// What a managed stop did to the processes its record names. +#[derive(Debug, Clone, Default, PartialEq, Eq)] +struct RecordedStopTermination { + /// Every PID that received a signal, including one that then outlived the + /// deadline. + signaled_pids: Vec, + /// Whether every recorded process is confirmed no longer running. + all_stopped: bool, + pid_outcomes: Vec, +} + /// Terminate the processes recorded for a managed service, verifying each PID's /// identity first so a recycled PID never causes an unrelated process tree to be /// killed. @@ -692,43 +852,52 @@ const MANAGED_STOP_GRACE: Duration = Duration::from_secs(10); /// each PID is paired with **its own** start-time token (`supervisor_start_ticks` /// vs `engine_start_ticks`). When they resolve to the same PID (e.g. before the /// engine state has been refreshed) the entry is de-duplicated, preferring a -/// known token. Returns the PIDs actually signalled and whether every recorded -/// process is confirmed no longer running. -fn terminate_recorded_service_pids(record: &ManagedServiceRecord) -> (Vec, bool) { - // Build the (pid, own-token) work list, de-duplicating on PID and preferring - // an entry that carries a verifiable start-time. - let mut entries: Vec<(u32, Option)> = Vec::new(); - for (pid, ticks) in [ - (Some(record.supervisor_pid), record.supervisor_start_ticks), - (record.engine_pid, record.engine_start_ticks), +/// known token. Returns the PIDs actually signalled, whether every recorded +/// process is confirmed no longer running, and each PID's own outcome. +fn terminate_recorded_service_pids(record: &ManagedServiceRecord) -> RecordedStopTermination { + // Build the (pid, own-token, role) work list, de-duplicating on PID and + // preferring an entry that carries a verifiable start-time. + let mut entries: Vec<(u32, Option, &'static str)> = Vec::new(); + for (pid, ticks, role) in [ + ( + Some(record.supervisor_pid), + record.supervisor_start_ticks, + "supervisor", + ), + (record.engine_pid, record.engine_start_ticks, "engine"), ] { let Some(pid) = pid.filter(|pid| *pid != 0 && *pid != std::process::id()) else { continue; }; - if let Some(existing) = entries.iter_mut().find(|(seen, _)| *seen == pid) { + if let Some(existing) = entries.iter_mut().find(|(seen, _, _)| *seen == pid) { if existing.1.is_none() { existing.1 = ticks; } + existing.2 = "supervisor_and_engine"; } else { - entries.push((pid, ticks)); + entries.push((pid, ticks, role)); } } - let mut signaled_pids = Vec::new(); - let mut all_stopped = true; - for (pid, ticks) in entries { + let mut termination = RecordedStopTermination { + all_stopped: true, + ..RecordedStopTermination::default() + }; + for (pid, ticks, role) in entries { let identity = rocm_core::ProcessIdentity::new(pid, ticks); // The managed stop contract is definitive: after the adapter gets its // graceful opportunity, this cleanup pass forces any verified survivor // so the command does not report success while a GPU worker remains. - let outcome = rocm_core::terminate_verified( - &identity, - rocm_core::KillScope::Tree, - MANAGED_STOP_GRACE, - true, - ); + let outcome = scripted_stop_outcome().unwrap_or_else(|| { + rocm_core::terminate_verified( + &identity, + rocm_core::KillScope::Tree, + MANAGED_STOP_GRACE, + true, + ) + }); if !outcome.stopped() { - all_stopped = false; + termination.all_stopped = false; } // Report every PID that received a signal. TimedOut belongs here because // signalling was attempted even though the process was not confirmed @@ -739,10 +908,37 @@ fn terminate_recorded_service_pids(record: &ManagedServiceRecord) -> (Vec, | rocm_core::TerminationOutcome::Forced | rocm_core::TerminationOutcome::TimedOut ) { - signaled_pids.push(pid); + termination.signaled_pids.push(pid); } + termination + .pid_outcomes + .push(RecordedPidOutcome { pid, role, outcome }); + } + termination +} + +/// E2E hook: when `ROCM_E2E_STOP_OUTCOME` is `timed_out` or `unverified`, a +/// managed stop reports that outcome for every recorded PID without signalling +/// anything. +/// +/// Neither outcome can be staged from outside the binary: `TimedOut` needs a +/// process that survives `SIGKILL`, and `Unverified` one whose recorded +/// start-time cannot be read back. Without this seam the "stop not confirmed" +/// report, its exit status and what it keeps on disk have no live coverage. +/// The recorded process is left untouched. Compiled only into the +/// `e2e-test-hooks` binary; production builds never see it. +#[cfg(feature = "e2e-test-hooks")] +fn scripted_stop_outcome() -> Option { + match std::env::var("ROCM_E2E_STOP_OUTCOME").ok()?.trim() { + "timed_out" => Some(rocm_core::TerminationOutcome::TimedOut), + "unverified" => Some(rocm_core::TerminationOutcome::Unverified), + _ => None, } - (signaled_pids, all_stopped) +} + +#[cfg(not(feature = "e2e-test-hooks"))] +const fn scripted_stop_outcome() -> Option { + None } fn stop_internal_managed_service(paths: &AppPaths, service_id: &str) -> Result { @@ -757,7 +953,7 @@ fn stop_internal_managed_service(paths: &AppPaths, service_id: &str) -> Result (Vec, bool), + terminate: impl FnOnce(&ManagedServiceRecord) -> RecordedStopTermination, ) -> Result { stop_internal_managed_service_confirmed_with(paths, service_id, terminate) .map(|(report, _)| report) @@ -771,7 +967,7 @@ fn stop_internal_managed_service_with( fn stop_internal_managed_service_confirmed_with( paths: &AppPaths, service_id: &str, - terminate: impl FnOnce(&ManagedServiceRecord) -> (Vec, bool), + terminate: impl FnOnce(&ManagedServiceRecord) -> RecordedStopTermination, ) -> Result<(serde_json::Value, bool)> { let mut stopping = load_managed_service(paths, service_id)?; // Record the request on disk before anything is stopped, not only after. @@ -799,7 +995,11 @@ fn stop_internal_managed_service_confirmed_with( }, ) }; - let (signaled_pids, terminated_all) = terminate(&stopping); + let RecordedStopTermination { + signaled_pids, + all_stopped: terminated_all, + pid_outcomes, + } = terminate(&stopping); // Re-read the record rather than write back the copy loaded before the // stop, which can be some forty seconds old by now: `write` replaces the // whole file, and a supervisor, the daemon's restart or another stop may @@ -823,8 +1023,8 @@ fn stop_internal_managed_service_confirmed_with( // supervisor that follows it, so a failed `Stop` leaves the stop unconfirmed. let engine_stop_confirms = !rocm_core::engine_stop_decides_confirmation(&stopping.engine) || engine_stop.is_ok(); - let all_stopped = - terminated_all && stopping.names_same_processes(&record) && engine_stop_confirms; + let record_changed = !stopping.names_same_processes(&record); + let all_stopped = terminated_all && !record_changed && engine_stop_confirms; if all_stopped { record.status = "stopped".to_owned(); record.stop_requested_unix_ms = None; @@ -849,6 +1049,15 @@ fn stop_internal_managed_service_confirmed_with( if all_stopped { endpoint_keys::clear_endpoint_api_key(paths, &record.service_id); } + // `endpoint_key_kept`: whether this unconfirmed stop left a *usable* key — + // one the server may still be enforcing — on disk. Usable as + // `endpoint_api_key` decides it, the same test the managed spawn applies + // before handing a key to the engine: an empty or malformed key file is no + // key, because nothing enforces it. A loopback service started without + // `--require-api-key` never had one. The unconfirmed report names the key + // only when this is set. + let endpoint_key_kept = + !all_stopped && endpoint_keys::endpoint_api_key(paths, &record.service_id).is_some(); let engine_stop = match engine_stop { Ok(response) => serde_json::json!({ "attempted": true, @@ -865,10 +1074,58 @@ fn stop_internal_managed_service_confirmed_with( "status": record.status, "engine_stop": engine_stop, "signaled_pids": signaled_pids, + "pid_outcomes": pid_outcomes + .iter() + .map(|entry| { + serde_json::json!({ + "pid": entry.pid, + "role": entry.role, + "outcome": entry.outcome.as_str(), + }) + }) + .collect::>(), + "record_changed": record_changed, + // A container engine is confirmed stopped by its own `Stop`; when that + // failed, the verdict is unconfirmed whatever the PIDs did. + "engine_stop_unconfirmed": !engine_stop_confirms, + "endpoint_key_kept": endpoint_key_kept, + "stopped": all_stopped, }); Ok((report, all_stopped)) } +/// Whether a [`stop_internal_managed_service`] report confirms that every +/// recorded process is gone. A report without the verdict counts as +/// unconfirmed, so a missing field can never read as a completed stop. Same +/// rule as `rocmd`'s `stop_report_confirmed`. +fn stop_report_confirmed(report: &serde_json::Value) -> bool { + report.get("stopped").and_then(serde_json::Value::as_bool) == Some(true) +} + +/// The `stop_server` sandbox tool's answer for a stop report: `stopped` only +/// when the stop confirmed it, `stop_unconfirmed` otherwise — the same status +/// `rocmd`'s `stop_server` tool reports, taken from the same verdict that +/// decided what the stop wrote to the record. +pub(crate) fn internal_stop_server_value(report: serde_json::Value) -> serde_json::Value { + let status = if stop_report_confirmed(&report) { + "stopped" + } else { + "stop_unconfirmed" + }; + serde_json::json!({ + "tool": SandboxToolArg::StopServer.as_cli_value(), + "status": status, + "mutating": true, + "result": report, + }) +} + +/// Whether a `stop_server` tool answer reports a stop it could not confirm. +pub(crate) fn service_stop_unconfirmed(value: &serde_json::Value) -> bool { + let output = value.get("output").unwrap_or(value); + output.get("status").and_then(serde_json::Value::as_str) == Some("stop_unconfirmed") +} + fn unload_lemonade_service_model(record: &ManagedServiceRecord) -> Result<()> { let body = serde_json::json!({ "model_name": record.canonical_model_id, @@ -979,7 +1236,7 @@ fn restart_internal_managed_service_with( paths: &AppPaths, service_id: &str, runtime_pin: Option<&str>, - terminate: impl FnOnce(&ManagedServiceRecord) -> (Vec, bool), + terminate: impl FnOnce(&ManagedServiceRecord) -> RecordedStopTermination, ) -> Result { let record = load_service_for_restart(paths, service_id, runtime_pin)?; // Preserve the endpoint key across the restart: `stop_internal_managed_service` @@ -1305,10 +1562,11 @@ pub(crate) fn read_tail_lines(path: &Path, limit: usize, label: &str) -> Result< Ok(lines.into_iter().collect()) } #[cfg(test)] -mod tests { +pub(crate) mod tests { use std::cell::RefCell; use super::*; + use crate::finish_service_action; use crate::providers; use crate::runtime_services; use crate::tests::{ @@ -2161,7 +2419,7 @@ mod tests { let report = stop_internal_managed_service_with(&paths, service_id, |_| { let on_disk = on_disk(); seen_at_signal.set(Some(on_disk.stop_requested_unix_ms)); - (Vec::new(), false) + bare_termination(Vec::new(), false) }) .unwrap(); @@ -2229,7 +2487,7 @@ mod tests { restarted.supervisor_start_ticks = Some(7); restarted.stop_requested_unix_ms = None; restarted.write().unwrap(); - (Vec::new(), true) + bare_termination(Vec::new(), true) }) .unwrap(); @@ -2263,8 +2521,10 @@ mod tests { record.write().unwrap(); endpoint_keys::store_endpoint_api_key(&paths, service_id, "key-123").unwrap(); - let report = - stop_internal_managed_service_with(&paths, service_id, |_| (Vec::new(), true)).unwrap(); + let report = stop_internal_managed_service_with(&paths, service_id, |_| { + bare_termination(Vec::new(), true) + }) + .unwrap(); drop(env); let on_disk = raw_manifest(&paths, service_id); @@ -2275,6 +2535,21 @@ mod tests { // refresh to settle, rather than cleared as for a confirmed stop. assert!(on_disk.stop_requested_unix_ms.is_some()); assert_eq!(key.as_deref(), Some("key-123"), "the key is kept"); + // The report gives the engine's failed stop as its reason, since no + // PID outcome and no record change explains it. + assert_eq!(report["engine_stop_unconfirmed"], true, "{report}"); + let rendered = + render_service_action_result("stop_server", &internal_stop_server_value(report)); + assert!( + rendered.contains("Local server stop not confirmed"), + "{rendered}" + ); + assert!( + rendered.contains("not confirmed: the engine's own stop failed: "), + "{rendered}" + ); + assert!(rendered.contains("and its endpoint key"), "{rendered}"); + assert_no_retry_line(&rendered); } #[test] @@ -2291,7 +2566,7 @@ mod tests { let mut meanwhile = raw_manifest(&paths, service_id); meanwhile.restart_count = 7; meanwhile.write().unwrap(); - (Vec::new(), true) + bare_termination(Vec::new(), true) }) .unwrap(); @@ -2305,6 +2580,344 @@ mod tests { assert_eq!(key, None, "a confirmed stop drops the key"); } + #[test] + fn services_stop_reports_an_unconfirmed_stop_as_an_error_and_keeps_the_service() { + // `rocm services stop --yes` printed "Local server stopped" and exited 0 + // from the tool name alone, even when the stop could not confirm the + // recorded process gone and so kept the record, its stop request and + // the endpoint key. The answer now carries the stop's own verdict: the + // message, the exit and the state on disk are checked together here. + let (root, paths) = test_paths("services-stop-unconfirmed"); + paths.ensure().unwrap(); + let service_id = "svc-services-stop-unconfirmed"; + stop_test_record(&paths, service_id).write().unwrap(); + endpoint_keys::store_endpoint_api_key(&paths, service_id, "key-123").unwrap(); + + let report = stop_internal_managed_service_with(&paths, service_id, |_| { + timed_out_termination(999_999_999) + }) + .unwrap(); + let answer = internal_stop_server_value(report); + let outcome = finish_service_action(&paths, "stop_server", service_id, &answer); + + let on_disk = raw_manifest(&paths, service_id); + let key = endpoint_keys::endpoint_api_key(&paths, service_id); + let audit = last_audit_event(&paths); + let _ = fs::remove_dir_all(root); + assert_eq!(answer["status"], "stop_unconfirmed", "{answer}"); + assert_eq!(answer["result"]["stopped"], false, "{answer}"); + let rendered = format!( + "{:#}", + outcome.expect_err("an unconfirmed stop must not exit as a success") + ); + assert!( + !rendered.contains("Local server stopped"), + "claims a stop that was not confirmed: {rendered}" + ); + assert!( + rendered.contains("Local server stop not confirmed"), + "{rendered}" + ); + assert!(rendered.contains("signaled processes: 1"), "{rendered}"); + assert!( + rendered.contains("still running: process 999999999 (supervisor_and_engine)"), + "{rendered}" + ); + assert!( + rendered.contains("kept: the server record, which still names its processes, and its endpoint key, which the server may still be enforcing"), + "{rendered}" + ); + assert_no_retry_line(&rendered); + assert!( + rendered.contains( + "process 999999999 (supervisor_and_engine) or a process under it did not exit" + ), + "{rendered}" + ); + assert!(!rendered.contains("check:"), "{rendered}"); + assert!( + !rendered.contains("status:"), + "a record status would contradict the header: {rendered}" + ); + assert_eq!(audit["level"], "error", "{audit}"); + assert_eq!(audit["action"], "stop_server", "{audit}"); + assert_eq!( + audit["message"], + format!("stop of managed service {service_id} not confirmed"), + "{audit}" + ); + // The claims in that message, checked against the state they describe. + assert_eq!( + on_disk.supervisor_pid, 999_999_999, + "the record still names the process" + ); + assert!( + on_disk.stop_requested_unix_ms.is_some(), + "the stop request stays recorded" + ); + assert_eq!(key.as_deref(), Some("key-123"), "the endpoint key is kept"); + } + + /// No line of an unconfirmed-stop report offers a command to run the stop + /// again — no `retry:` line, and no `services stop` anywhere: a second stop + /// can confirm without reaching a surviving process under the recorded one. + pub(crate) fn assert_no_retry_line(rendered: &str) { + assert!( + !rendered.lines().any(|line| { + line.trim_start().starts_with("retry:") || line.contains("services stop") + }), + "an unconfirmed stop names no stop command: {rendered}" + ); + } + + /// A stop stand-in's bare verdict, without per-PID detail. + fn bare_termination(signaled_pids: Vec, all_stopped: bool) -> RecordedStopTermination { + RecordedStopTermination { + signaled_pids, + all_stopped, + pid_outcomes: Vec::new(), + } + } + + /// A stop stand-in whose one recorded process (the record's shared + /// supervisor/engine PID) was signalled and outlived the deadline. + fn timed_out_termination(pid: u32) -> RecordedStopTermination { + RecordedStopTermination { + signaled_pids: vec![pid], + all_stopped: false, + pid_outcomes: vec![RecordedPidOutcome { + pid, + role: "supervisor_and_engine", + outcome: rocm_core::TerminationOutcome::TimedOut, + }], + } + } + + /// The most recent audit event written under `paths`. + fn last_audit_event(paths: &AppPaths) -> serde_json::Value { + let text = fs::read_to_string(paths.audit_events_path()).expect("audit log"); + serde_json::from_str(text.lines().last().expect("an audit event")).expect("audit json") + } + + #[test] + fn services_stop_reports_an_unverified_process_with_a_check() { + // A process whose recorded start-time cannot be read back is not + // signalled by this stop; the report says so and names a command to + // check on it. + let (root, paths) = test_paths("services-stop-unverified"); + paths.ensure().unwrap(); + let service_id = "svc-services-stop-unverified"; + stop_test_record(&paths, service_id).write().unwrap(); + endpoint_keys::store_endpoint_api_key(&paths, service_id, "key-123").unwrap(); + + let report = + stop_internal_managed_service_with(&paths, service_id, |_| RecordedStopTermination { + signaled_pids: Vec::new(), + all_stopped: false, + pid_outcomes: vec![RecordedPidOutcome { + pid: 999_999_999, + role: "supervisor_and_engine", + outcome: rocm_core::TerminationOutcome::Unverified, + }], + }) + .unwrap(); + let answer = internal_stop_server_value(report); + let outcome = finish_service_action(&paths, "stop_server", service_id, &answer); + + let on_disk = raw_manifest(&paths, service_id); + let key = endpoint_keys::endpoint_api_key(&paths, service_id); + let _ = fs::remove_dir_all(root); + let rendered = format!("{:#}", outcome.expect_err("an unverified stop fails")); + assert!( + rendered.contains("Local server stop not confirmed"), + "{rendered}" + ); + assert!( + rendered.contains("not signaled: process 999999999 (supervisor_and_engine)"), + "{rendered}" + ); + assert_no_retry_line(&rendered); + assert!( + rendered.contains(&format!("check: `{}`", process_check_command(999_999_999))), + "{rendered}" + ); + assert!(on_disk.stop_requested_unix_ms.is_some()); + assert_eq!(on_disk.supervisor_pid, 999_999_999); + assert_eq!(key.as_deref(), Some("key-123")); + } + + #[test] + fn services_stop_notes_a_changed_record_even_when_a_process_timed_out() { + // Process A timed out, then a restart recorded B: the report must say + // the record changed, beside A's own line. + let (root, paths) = test_paths("services-stop-timeout-then-changed"); + paths.ensure().unwrap(); + let service_id = "svc-services-stop-timeout-then-changed"; + stop_test_record(&paths, service_id).write().unwrap(); + + let report = stop_internal_managed_service_with(&paths, service_id, |_| { + let mut restarted = raw_manifest(&paths, service_id); + restarted.supervisor_pid = 4_242_424; + restarted.supervisor_start_ticks = Some(7); + restarted.write().unwrap(); + timed_out_termination(999_999_999) + }) + .unwrap(); + let answer = internal_stop_server_value(report); + let outcome = finish_service_action(&paths, "stop_server", service_id, &answer); + let _ = fs::remove_dir_all(root); + let rendered = format!("{:#}", outcome.expect_err("unconfirmed")); + assert!( + rendered.contains("the record changed while the stop ran"), + "{rendered}" + ); + assert_no_retry_line(&rendered); + } + + #[test] + fn services_stop_gives_a_mixed_result_a_line_each_and_a_check() { + let (root, paths) = test_paths("services-stop-mixed"); + paths.ensure().unwrap(); + let service_id = "svc-services-stop-mixed"; + let mut record = stop_test_record(&paths, service_id); + record.engine_pid = Some(888_888_888); + record.write().unwrap(); + + let report = + stop_internal_managed_service_with(&paths, service_id, |_| RecordedStopTermination { + signaled_pids: vec![999_999_999], + all_stopped: false, + pid_outcomes: vec![ + RecordedPidOutcome { + pid: 999_999_999, + role: "supervisor", + outcome: rocm_core::TerminationOutcome::TimedOut, + }, + RecordedPidOutcome { + pid: 888_888_888, + role: "engine", + outcome: rocm_core::TerminationOutcome::Unverified, + }, + ], + }) + .unwrap(); + let answer = internal_stop_server_value(report); + let outcome = finish_service_action(&paths, "stop_server", service_id, &answer); + let _ = fs::remove_dir_all(root); + let rendered = format!("{:#}", outcome.expect_err("unconfirmed")); + assert_no_retry_line(&rendered); + assert!( + rendered.contains("check: `ps -p 888888888 -o pid,args`"), + "{rendered}" + ); + assert!(!rendered.contains("the record changed"), "{rendered}"); + } + + #[test] + fn services_stop_mentions_no_endpoint_key_for_a_keyless_service() { + // A loopback service started without `--require-api-key` has no key, so + // an unconfirmed stop of it keeps only the record; the report must not + // claim it kept a key. + let (root, paths) = test_paths("services-stop-keyless"); + paths.ensure().unwrap(); + let service_id = "svc-services-stop-keyless"; + stop_test_record(&paths, service_id).write().unwrap(); + + let report = stop_internal_managed_service_with(&paths, service_id, |_| { + timed_out_termination(999_999_999) + }) + .unwrap(); + let answer = internal_stop_server_value(report); + let outcome = finish_service_action(&paths, "stop_server", service_id, &answer); + let on_disk = raw_manifest(&paths, service_id); + let key = endpoint_keys::endpoint_api_key(&paths, service_id); + let _ = fs::remove_dir_all(root); + let rendered = format!("{:#}", outcome.expect_err("unconfirmed")); + assert_eq!(answer["result"]["endpoint_key_kept"], false, "{answer}"); + assert!( + rendered + .lines() + .any(|line| line == " kept: the server record, which still names its processes"), + "{rendered}" + ); + assert!(!rendered.contains("endpoint key"), "{rendered}"); + assert_eq!(key, None, "there was no key to keep"); + assert_eq!(on_disk.supervisor_pid, 999_999_999, "the record is kept"); + assert!(on_disk.stop_requested_unix_ms.is_some()); + } + + #[test] + fn services_stop_reports_a_changed_record_with_a_note() { + // Every process the stop handled is gone, but the record names others + // now: the verdict says nothing about them, and the report says so. + let (root, paths) = test_paths("services-stop-record-changed"); + paths.ensure().unwrap(); + let service_id = "svc-services-stop-record-changed"; + stop_test_record(&paths, service_id).write().unwrap(); + + let report = stop_internal_managed_service_with(&paths, service_id, |_| { + let mut restarted = raw_manifest(&paths, service_id); + restarted.supervisor_pid = 4_242_424; + restarted.supervisor_start_ticks = Some(7); + restarted.write().unwrap(); + bare_termination(Vec::new(), true) + }) + .unwrap(); + let answer = internal_stop_server_value(report); + let outcome = finish_service_action(&paths, "stop_server", service_id, &answer); + let _ = fs::remove_dir_all(root); + let rendered = format!( + "{:#}", + outcome.expect_err("a changed record is unconfirmed") + ); + assert!( + rendered.contains("the record changed while the stop ran"), + "{rendered}" + ); + assert_no_retry_line(&rendered); + assert!( + rendered.contains("check: `rocm services` lists what the record names now"), + "{rendered}" + ); + } + + #[test] + fn services_stop_reports_a_confirmed_stop_as_stopped() { + let (root, paths) = test_paths("services-stop-confirmed"); + paths.ensure().unwrap(); + let service_id = "svc-services-stop-confirmed"; + stop_test_record(&paths, service_id).write().unwrap(); + endpoint_keys::store_endpoint_api_key(&paths, service_id, "key-123").unwrap(); + + let report = stop_internal_managed_service_with(&paths, service_id, |_| { + bare_termination(vec![4242], true) + }) + .unwrap(); + let answer = internal_stop_server_value(report); + let outcome = finish_service_action(&paths, "stop_server", service_id, &answer); + + let on_disk = raw_manifest(&paths, service_id); + let key = endpoint_keys::endpoint_api_key(&paths, service_id); + let _ = fs::remove_dir_all(root); + assert_eq!(answer["status"], "stopped", "{answer}"); + let rendered = outcome.expect("a confirmed stop succeeds"); + assert!(rendered.contains("Local server stopped"), "{rendered}"); + assert!(rendered.contains("stopped processes: 1"), "{rendered}"); + assert_eq!(on_disk.status, "stopped"); + assert_eq!(on_disk.stop_requested_unix_ms, None); + assert_eq!(key, None, "a confirmed stop drops the key"); + } + + #[test] + fn services_stop_reports_a_report_without_a_verdict_as_unconfirmed() { + let answer = internal_stop_server_value(serde_json::json!({ + "service_id": "svc-legacy", + "status": "ready", + "signaled_pids": [], + })); + assert_eq!(answer["status"], "stop_unconfirmed", "{answer}"); + } + #[test] fn restart_does_not_start_an_engine_over_an_unconfirmed_stop() { // A restart used to discard its stop's result and start the new engine @@ -2319,7 +2932,7 @@ mod tests { endpoint_keys::store_endpoint_api_key(&paths, service_id, "key-123").unwrap(); let result = restart_internal_managed_service_with(&paths, service_id, None, |_| { - (vec![999_999_999], false) + bare_termination(vec![999_999_999], false) }); let on_disk = raw_manifest(&paths, service_id); @@ -2759,7 +3372,11 @@ mod tests { let real = rocm_core::process_start_ticks(pid).expect("start-ticks"); let record = managed_record_for_pid(&paths, pid, Some(real.wrapping_add(1))); - let (signaled, all_stopped) = terminate_recorded_service_pids(&record); + let RecordedStopTermination { + signaled_pids: signaled, + all_stopped, + .. + } = terminate_recorded_service_pids(&record); assert!(signaled.is_empty(), "must not signal a mismatched identity"); // A recycled PID means the recorded service process itself is gone. @@ -2793,7 +3410,11 @@ mod tests { record.engine_pid = Some(eng_pid); record.engine_start_ticks = rocm_core::process_start_ticks(eng_pid); - let (mut signaled, all_stopped) = terminate_recorded_service_pids(&record); + let RecordedStopTermination { + signaled_pids: mut signaled, + all_stopped, + .. + } = terminate_recorded_service_pids(&record); signaled.sort_unstable(); let mut expected = vec![sup_pid, eng_pid]; expected.sort_unstable(); @@ -2821,7 +3442,11 @@ mod tests { let real = rocm_core::process_start_ticks(pid).expect("start-ticks"); let record = managed_record_for_pid(&paths, pid, Some(real)); - let (signaled, all_stopped) = terminate_recorded_service_pids(&record); + let RecordedStopTermination { + signaled_pids: signaled, + all_stopped, + .. + } = terminate_recorded_service_pids(&record); assert_eq!(signaled, vec![pid]); assert!(all_stopped); diff --git a/apps/rocmd/src/mcp.rs b/apps/rocmd/src/mcp.rs index 8b086a52e..5ee897112 100644 --- a/apps/rocmd/src/mcp.rs +++ b/apps/rocmd/src/mcp.rs @@ -798,12 +798,12 @@ fn mcp_stop_server_reply(service_id: &str, stopped: Value) -> Value { tool_success(format!("Stopped managed service `{service_id}`."), stopped) } else { // Not a success: a recorded process may still be running and holding - // the device. `stop_managed_service` keeps the record's PIDs and the + // the device. `stop_managed_service` keeps the record's PIDs and any // endpoint key for exactly that case, and `pid_outcomes` in the // structured result names the PID that could not be confirmed. tool_error( format!( - "Could not confirm that managed service `{service_id}` stopped; a recorded process may still be running. Its recorded PIDs and any endpoint key were kept so a later stop can still reach it; see `pid_outcomes`." + "Could not confirm that managed service `{service_id}` stopped; a recorded process may still be running. Its record, which names the processes it last recorded, and any endpoint key, which the server may still be enforcing, were kept; see `pid_outcomes`." ), stopped, ) diff --git a/apps/rocmd/src/service.rs b/apps/rocmd/src/service.rs index 79793d1f8..ce86b1992 100644 --- a/apps/rocmd/src/service.rs +++ b/apps/rocmd/src/service.rs @@ -142,14 +142,15 @@ pub(crate) fn stop_managed_service_via( record.stop_requested_unix_ms = None; // Recorded PIDs go stale the instant their processes exit, and a stale // PID is exactly what the identity check exists to catch — so do not - // leave one behind for the next stop to find. Only safe here: an - // unconfirmed survivor is still the service's, and a later stop has to - // be able to reach it. + // leave one behind for the next stop to find. record.supervisor_pid = 0; record.supervisor_start_ticks = None; record.engine_pid = None; record.engine_start_ticks = None; } else { + // The recorded PIDs stay: an unconfirmed survivor is still the + // service's, and the record is what names it. + // // The marker that tells a service the operator stopped from one that // merely crashed. While it is set the daemon will not recover the // service (`stop_requested`), so an unconfirmed stop is not undone. @@ -157,9 +158,9 @@ pub(crate) fn stop_managed_service_via( // It is also what the deferred key cleanup keys on — but that cleanup // lives in the `rocm` binary (`settle_pending_stop_key_cleanup`, run by // its liveness refresh), not here. A caller that only ever drives - // `rocmd` finishes the job by repeating the stop: once the processes - // are gone the repeat confirms, clears the marker and drops the key. - // Until then, both stay on disk. + // `rocmd` keeps both the marker and the key on disk until a later stop + // confirms; that confirmation is only as good as the check above it, + // which cannot see a survivor under a dead recorded root. record.stop_requested_unix_ms = Some(requested_at); } record.write()?; diff --git a/apps/rocmd/src/test_support.rs b/apps/rocmd/src/test_support.rs index f1c000bfe..424ad9d5c 100644 --- a/apps/rocmd/src/test_support.rs +++ b/apps/rocmd/src/test_support.rs @@ -165,8 +165,8 @@ pub(crate) fn seed_keyed_service(paths: &AppPaths, service_id: &str, port: u16) } /// The state an unconfirmed stop must leave behind: not marked stopped, the -/// PID kept so a later stop can still reach it, the deferred-cleanup marker -/// set, and the endpoint key still on disk. +/// PID kept because the record still names that process, the deferred-cleanup +/// marker set, and the endpoint key still on disk. pub(crate) fn assert_unconfirmed_stop_kept_the_service( reloaded: &ManagedServiceRecord, key_kept: bool, @@ -177,7 +177,7 @@ pub(crate) fn assert_unconfirmed_stop_kept_the_service( ); assert_eq!( reloaded.supervisor_pid, UNCONFIRMED_STOP_PID, - "an unconfirmed stop must keep the PID a later stop needs" + "an unconfirmed stop must keep the PID of the process it may have left running" ); assert!( reloaded.stop_requested_unix_ms.is_some(), diff --git a/docs/manual-testing.md b/docs/manual-testing.md index ed8f7da68..b73276fd0 100644 --- a/docs/manual-testing.md +++ b/docs/manual-testing.md @@ -317,8 +317,11 @@ While the log stream is attached, verify detach and stop behave differently: "detached - server still running" note with the service id. Confirm the server is still up: `rocm services` lists it and the endpoint still answers a chat request. Stop it afterward with `rocm services stop --yes`. -- Re-run the serve command and press `Ctrl+C` instead. The server shuts down and - `rocm services` no longer lists it as running. +- Re-run the serve command and press `Ctrl+C` instead. The server shuts down, + the command prints `Local server stopped` and exits 0, and `rocm services` no + longer lists it as running. (A stop that cannot confirm the process exited + prints `Local server stop not confirmed` on stderr and exits non-zero + instead.) ### Windows display driver check @@ -392,6 +395,13 @@ rocm services stop --yes rocm services restart --yes ``` +`stop` prints `Local server stopped` only once every recorded process is +confirmed gone; otherwise it prints `Local server stop not confirmed` on stderr, +keeps the record and any endpoint key, and exits non-zero. It names each +process that, or a process under it, did not exit, and for one it could not +verify, an operating-system command to check on it. It never prints a `retry:` +line. + `restart` starts the server again only once its stop has confirmed every recorded process gone; otherwise it reports that and starts nothing. diff --git a/docs/testing.md b/docs/testing.md index e49a3c524..a7d05b0b1 100644 --- a/docs/testing.md +++ b/docs/testing.md @@ -974,9 +974,10 @@ otherwise the CLI would lock itself out of a service that is still running and still enforcing the key — and the deferred cleanup lands on the liveness refresh that later observes the process dead. `service-stop-01` (`features/service_stop.feature`) covers `services stop` succeeding against a -running record on the mock lane and the record being persisted as stopped; -there is still no e2e coverage of the key being dropped or `services restart`, -which remain unit-tested only. Reusing a running service for a +running record on the mock lane and the record being persisted as stopped, and +`service-stop-02` covers the key being dropped once the daemon's `stop_server` +confirms a stop. There is still no e2e coverage of `services restart`, which +remains unit-tested only. Reusing a running service for a `--require-api-key` request it never had is refused rather than silently upgraded — `serve-24` (`features/model_serving.feature`, Lemonade GPU lane, Linux-only since the Windows managed Lemonade spawn can't enforce the key) @@ -1160,7 +1161,39 @@ bubblewrap isolation must still execute only this internal tool API and record a sandbox audit event. `stop_server` — the sandbox tool and the MCP tool alike — reports a stop only once every recorded process is confirmed gone: otherwise the sandbox tool reports `status: stop_unconfirmed`, the MCP tool answers with -`isError: true`, and the manifest keeps its PIDs and endpoint key. The stop +`isError: true`, and the manifest keeps its PIDs and any endpoint key. `rocm +services stop --yes` takes the same verdict from its own stop: it prints `Local +server stop not confirmed` on stderr instead of `Local server stopped`, and +exits non-zero. Its lines follow each recorded PID's outcome (`pid_outcomes`, +as in `rocmd`): a `timed_out` process, or one under it, did not exit; an +`unverified` one is not signaled and gets an OS command to check on it. Like +`rocmd`'s MCP answer it names no command to run the stop again, because +`terminate_verified` reports a dead recorded process as `already_gone` without +looking at the tree under it, so a second stop could confirm while a process +under it still runs. When the stop answers unconfirmed, the attached `rocm serve` +Ctrl-C stop prints the same report on stderr, signals nothing further, exits +with an error and records an `error` audit event; when the stop itself fails, +it notes the stop's error on stderr, signals the child the session launched +directly, exits 0, and records whether that signal worked, adding a second +stderr `note:` when it did not (`cargo test -p rocm --bin rocm services_stop_` and +`cargo test -p rocm --bin rocm attached_ctrl_c_`). + +No scenario drives the attached Ctrl-C stop end to end. Attaching needs a real +`rocm serve` launch — an engine and a runtime the mock lane does not have, +which is why the chat scenarios there plant a record behind a mock server +instead — and the GPU lanes, which can launch one, cannot be run from here to +prove such a scenario. `attached_ctrl_c_` covers everything after the stop +answers: the stream each report goes to, the exit, the signal and the audit +event. + +In `rocm sandbox-run stop_server`'s answer the authoritative fields are +`output.status` (`stopped` or `stop_unconfirmed`) and `output.result.stopped`. +`output.result.status` is the server record's own status, which can already +read `stopped` (the liveness refresh reconciles a record whose PID it sees +gone) beside `stopped: false`. `rocmd sandbox-tool stop_server` answers with the +same top-level `status` and `result.stopped`, and carries the record under +`result.service`. Both commands exit 0 with `stop_unconfirmed`, leaving the +verdict to the JSON; `rocm services stop` exits 1. The stop records the request in the manifest before it signals anything, and applies its result to the manifest as it is once the stop ends, so a write made meanwhile is kept — and a restart that recorded new processes meanwhile makes the stop @@ -1172,6 +1205,18 @@ process and checks the confirmed report against the process, the record and the endpoint key file. Run it with `ROCM_CLI_BINARY=target/debug/rocm ROCM_CLI_ROCMD_BINARY=target/debug/rocmd cargo test -p e2e-cucumber --test e2e -- -n "service-stop-02"`. +`service-stop-03`, `-04` and `-05` (Linux, mock lane) cover `rocm services +stop`'s unconfirmed half through the `e2e-test-hooks` seam +`ROCM_E2E_STOP_OUTCOME` (`timed_out` or `unverified`), which makes the verified +stop report that outcome for the recorded process without signalling it: each +checks the report on stderr, exit 1, the kept PID and stop request, and that no +stop command is named. -03 and -04 plant an endpoint key and check that the +`kept:` line names it and the key file is still there; -05 plants none and +checks that the line omits it and no key file exists. Because the seam +replaces `terminate_verified`, they say nothing about what is signalled. They need +a hooks build, as `cargo xtask e2e` makes: `cargo build -p rocm -p rocmd +--features rocm/e2e-test-hooks`, then the command above with `-n +"service-stop"`. Manual restricted-tool smoke: diff --git a/tests/e2e-cucumber/features/service_stop.feature b/tests/e2e-cucumber/features/service_stop.feature index 33d4fee9b..cae0e9859 100644 --- a/tests/e2e-cucumber/features/service_stop.feature +++ b/tests/e2e-cucumber/features/service_stop.feature @@ -20,6 +20,10 @@ Feature: Stopping a managed service # # Plants the record rather than failing a real serve: no GPU, no network, so # this runs on the mock lane every PR. + # + # The `Local server stopped` header follows the stop's own verdict, so this + # is the confirmed half; service-stop-03 and -04 below are the unconfirmed + # one. @id:service-stop-yes-stops-a-running-service Scenario: service-stop-01 - `rocm services stop --yes` stops a running managed service @@ -42,10 +46,12 @@ Feature: Stopping a managed service # Linux-only: the token is read from `/proc`, which is where `rocmd` reads it # too; without one the identity check is not exercised at all. # - # The unconfirmed half of the contract — a recorded process that survives the - # stop, or whose identity cannot be read — needs a process that outlives - # SIGKILL or an unreadable `/proc` entry. Neither can be staged from outside - # the binary, so that half is covered by `rocmd`'s unit tests instead. + # The daemon's unconfirmed half — a recorded process that survives the stop, + # or whose identity cannot be read — needs a process that outlives SIGKILL or + # an unreadable `/proc` entry. Neither can be staged from outside `rocmd`, + # which has no test seam for it, so that half of `stop_server` is covered by + # `rocmd`'s unit tests. `rocm services stop`'s unconfirmed half is staged + # below, in service-stop-03 and -04. @id:service-stop-confirms-a-stop-and-cleans-up @requires-os:linux @@ -56,3 +62,60 @@ Feature: Stopping a managed service And the recorded process is no longer running And the server's record reads stopped and names no process And the server's endpoint key file is gone + + # `rocm services stop`'s unconfirmed half. Neither way a stop goes + # unconfirmed can be produced from outside the binary — a recorded process + # that outlives SIGKILL, or one whose start-time cannot be read back — so the + # `e2e-test-hooks` build's `ROCM_E2E_STOP_OUTCOME` seam makes the verified + # stop report that outcome for the recorded process without signalling it. + # Everything else runs for real: the stop's record writes, the key handling, + # the report and the exit status. The seam applies to the one stop the Given + # sets it up for. + # + # Neither report names a command to run the stop again. A second stop cannot + # be relied on to finish: when the recorded process is gone and only a + # process under it survived, a second stop finds the recorded one gone and + # confirms without reaching the survivor. + # + # What the seam cannot show is what `terminate_verified` itself does: it + # replaces that call, so these scenarios prove the CLI's report, exit status + # and kept record and key for each outcome, not whether a process was + # signalled. That an `unverified` PID is never signalled rests on + # `terminate_verified` returning before any signal when the identity is + # indeterminate (`rocm-core`'s `proc_lifecycle.rs`); no unit test covers that + # path yet, because an unreadable `/proc` entry cannot be staged there either. + # + # Linux-only for the same reason as service-stop-02: the recorded process + # carries the start-time token `/proc` gives it. + + @id:service-stop-unconfirmed-fails-and-keeps-the-record + @requires-os:linux + Scenario: service-stop-03 - A stop that cannot confirm the exit fails, keeps the server's record, and names no retry + Given a managed server whose recorded process is running + And the next stop cannot confirm that process exited + When the user stops it with --yes + Then the CLI reports the stop as not confirmed for a process that did not exit + And the server's record still names its process and the stop request + And the report says the record and the endpoint key were kept, and the key file is still there + + @id:service-stop-unverified-fails-without-a-retry + @requires-os:linux + Scenario: service-stop-04 - A stop that cannot verify its process fails, keeps the server's record, and names a check, not a retry + Given a managed server whose recorded process is running + And the next stop cannot verify that process as the server's + When the user stops it with --yes + Then the CLI reports the stop as not confirmed for a process it could not verify + And the server's record still names its process and the stop request + And the report says the record and the endpoint key were kept, and the key file is still there + + # A server started without an API key has no key file, and an unconfirmed + # stop of it keeps only the record; the report must not claim otherwise. + @id:service-stop-unconfirmed-keyless-keeps-only-the-record + @requires-os:linux + Scenario: service-stop-05 - An unconfirmed stop of a server without an endpoint key reports keeping only its record + Given a managed server without an endpoint key whose recorded process is running + And the next stop cannot confirm that process exited + When the user stops it with --yes + Then the CLI reports the stop as not confirmed and names no stop command + And the server's record still names its process and the stop request + And the report says only the record was kept, and there is no key file diff --git a/tests/e2e-cucumber/tests/e2e.rs b/tests/e2e-cucumber/tests/e2e.rs index d0d368577..7a3652b64 100644 --- a/tests/e2e-cucumber/tests/e2e.rs +++ b/tests/e2e-cucumber/tests/e2e.rs @@ -731,7 +731,7 @@ fn stop_managed_services(root: &std::path::Path) -> String { Ok(out) => format!( "{service_id}: STOP FAILED (rc={}) {}", out.status.code().unwrap_or(-1), - last_line(&String::from_utf8_lossy(&out.stderr)) + stop_failure_summary(&String::from_utf8_lossy(&out.stderr)) ), Err(error) => format!("{service_id}: STOP NOT RUN ({error})"), }); @@ -742,6 +742,17 @@ fn stop_managed_services(root: &std::path::Path) -> String { outcomes.join("; ") } +/// One line summing up a failed `rocm services stop`: its `Error:` line, which +/// is the report's header (`Local server stop not confirmed`) for an +/// unconfirmed stop, rather than the report's last detail line; otherwise the +/// last non-blank line. +fn stop_failure_summary(stderr: &str) -> String { + stderr + .lines() + .find(|line| line.starts_with("Error:")) + .map_or_else(|| last_line(stderr), last_line) +} + /// The last non-blank line of `text`, clipped, for a one-line failure summary. fn last_line(text: &str) -> String { let line = text diff --git a/tests/e2e-cucumber/tests/e2e/service_stop_steps.rs b/tests/e2e-cucumber/tests/e2e/service_stop_steps.rs index f0805c53c..31df329d2 100644 --- a/tests/e2e-cucumber/tests/e2e/service_stop_steps.rs +++ b/tests/e2e-cucumber/tests/e2e/service_stop_steps.rs @@ -2,7 +2,8 @@ // // SPDX-License-Identifier: MIT -//! Steps for stopping a managed service: `rocm services stop --yes`, and +//! Steps for stopping a managed service: `rocm services stop --yes` +//! (confirmed, and unconfirmed through the `ROCM_E2E_STOP_OUTCOME` seam), and //! `rocmd sandbox-tool stop_server`. //! //! Black-box: plants a managed-service record as plain JSON in its own isolated @@ -147,6 +148,17 @@ async fn plant_running_service(world: &mut E2eWorld) { /// endpoint key on disk beside the record. #[given("a managed server whose recorded process is running")] async fn managed_server_with_running_process(world: &mut E2eWorld) { + plant_server_with_running_process(world, "0.0.0.0", true); +} + +/// The same server bound to loopback and started without an API key, so no +/// endpoint key file exists for it. +#[given("a managed server without an endpoint key whose recorded process is running")] +async fn keyless_managed_server_with_running_process(world: &mut E2eWorld) { + plant_server_with_running_process(world, "127.0.0.1", false); +} + +fn plant_server_with_running_process(world: &mut E2eWorld, host: &str, with_key: bool) { let process = Command::new("sleep") .arg("300") .stdin(Stdio::null()) @@ -166,10 +178,10 @@ async fn managed_server_with_running_process(world: &mut E2eWorld) { "engine": "vllm", "model_ref": "qwen", "canonical_model_id": "Qwen/Qwen3.5", - "host": "0.0.0.0", + "host": host, // Discard port: closed, so nothing can answer on the server's behalf. "port": 9, - "endpoint_url": "http://0.0.0.0:9/v1", + "endpoint_url": format!("http://{host}:9/v1"), "mode": "managed", "status": "ready", "supervisor_pid": pid, @@ -185,8 +197,29 @@ async fn managed_server_with_running_process(world: &mut E2eWorld) { serde_json::to_vec_pretty(&record).expect("failed to serialize record"), ) .expect("failed to write service record"); - std::fs::write(endpoint_key_path(world), "e2e-endpoint-key") - .expect("failed to write endpoint key"); + if with_key { + std::fs::write(endpoint_key_path(world), "e2e-endpoint-key") + .expect("failed to write endpoint key"); + } +} + +/// Script the next `rocm` stop's verified termination to report `outcome` for +/// the recorded process, without signalling it — the `e2e-test-hooks` seam +/// `ROCM_E2E_STOP_OUTCOME`. Consumed by that one invocation. +fn script_next_stop_outcome(world: &mut E2eWorld, outcome: &str) { + world + .command_env + .push(("ROCM_E2E_STOP_OUTCOME", outcome.into())); +} + +#[given("the next stop cannot confirm that process exited")] +async fn next_stop_times_out(world: &mut E2eWorld) { + script_next_stop_outcome(world, "timed_out"); +} + +#[given("the next stop cannot verify that process as the server's")] +async fn next_stop_unverified(world: &mut E2eWorld) { + script_next_stop_outcome(world, "unverified"); } // ── When ─────────────────────────────────────────────────────────── @@ -199,7 +232,8 @@ async fn managed_server_with_running_process(world: &mut E2eWorld) { /// prove, by asserting the hint text first and then running it. #[when("the user stops it with --yes")] async fn stop_with_yes(world: &mut E2eWorld) { - let (stdout, stderr, rc) = crate::run_rocm(world, &["services", "stop", SERVICE_ID, "--yes"]); + let (stdout, stderr, rc) = + crate::run_rocm_with_scenario_env(world, &["services", "stop", SERVICE_ID, "--yes"]); record(world, stdout, stderr, rc); } @@ -221,9 +255,8 @@ async fn stop_server_tool(world: &mut E2eWorld) { // (as `restart_server` does); `stop_server`'s result is the flat // `service_id`/`status` shape `stop_internal_managed_service` returns, so none // of those lines ever print for a stop today. That mismatch is a pre-existing -// gap in that renderer, unrelated to the summary hint this PR fixes, so this -// assertion covers only what the command actually prints; the on-disk status -// below is what proves the stop itself. +// gap in that renderer, so this assertion covers only what the command +// actually prints; the on-disk status below is what proves the stop itself. #[then("the CLI reports the service as stopped")] async fn reports_stopped(world: &mut E2eWorld) { assert_succeeded(world); @@ -314,6 +347,124 @@ async fn endpoint_key_gone(world: &mut E2eWorld) { assert!(!key.exists(), "{} survived the stop", key.display()); } +/// An unconfirmed stop fails, on stderr, and never claims the server stopped. +fn assert_unconfirmed_stop_reported(world: &E2eWorld) -> String { + let rc = world.cli_rc.expect("no command rc recorded"); + let combined = combined_output(world); + assert_eq!(rc, 1, "an unconfirmed stop must exit 1:\n{combined}"); + let stderr = world.cli_stderr.as_deref().unwrap_or_default(); + assert!( + stderr.contains("Local server stop not confirmed"), + "the stop must say, on stderr, that it was not confirmed:\n{combined}" + ); + assert!( + !combined.contains("Local server stopped"), + "an unconfirmed stop must not claim the server stopped:\n{combined}" + ); + combined +} + +/// No line of an unconfirmed-stop report offers a command to run the stop +/// again — no `retry:` line, and no `services stop` anywhere: a second stop +/// can confirm without reaching a surviving process under the recorded one. +fn assert_no_retry_line(combined: &str) { + assert!( + !combined.lines().any(|line| { + line.trim_start().starts_with("retry:") || line.contains("services stop") + }), + "an unconfirmed stop names no stop command: {combined}" + ); +} + +#[then("the CLI reports the stop as not confirmed for a process that did not exit")] +async fn reports_unconfirmed_timed_out(world: &mut E2eWorld) { + let combined = assert_unconfirmed_stop_reported(world); + let pid = recorded_pid(world); + assert!( + combined.contains(&format!( + "still running: process {pid} (supervisor) or a process under it did not exit" + )), + "{combined}" + ); + assert_no_retry_line(&combined); +} + +#[then("the CLI reports the stop as not confirmed for a process it could not verify")] +async fn reports_unconfirmed_unverified(world: &mut E2eWorld) { + let combined = assert_unconfirmed_stop_reported(world); + let pid = recorded_pid(world); + assert!( + combined.contains(&format!("not signaled: process {pid} (supervisor)")), + "{combined}" + ); + assert!( + combined.contains(&format!("check: `ps -p {pid} -o pid,args`")), + "{combined}" + ); + assert_no_retry_line(&combined); +} + +#[then("the server's record still names its process and the stop request")] +async fn record_keeps_process_and_marker(world: &mut E2eWorld) { + let record = read_record(world); + assert_eq!( + record["supervisor_pid"], + u64::from(recorded_pid(world)), + "{record}" + ); + assert!( + !record["stop_requested_unix_ms"].is_null(), + "the unconfirmed stop keeps its request recorded: {record}" + ); + assert_ne!( + record["status"], "stopped", + "a stop that confirmed nothing must not mark the record stopped: {record}" + ); +} + +/// The report's `kept:` line, checked against the key file it describes. +#[then( + "the report says the record and the endpoint key were kept, and the key file is still there" +)] +async fn kept_line_names_the_key(world: &mut E2eWorld) { + let combined = combined_output(world); + assert!( + combined.lines().any(|line| line + == " kept: the server record, which still names its processes, and its endpoint key, which the server may still be enforcing"), + "{combined}" + ); + let key = endpoint_key_path(world); + assert!( + key.exists(), + "the report says the key was kept, but {} is gone", + key.display() + ); +} + +#[then("the report says only the record was kept, and there is no key file")] +async fn kept_line_omits_the_key(world: &mut E2eWorld) { + let combined = combined_output(world); + assert!( + combined + .lines() + .any(|line| line == " kept: the server record, which still names its processes"), + "{combined}" + ); + assert!(!combined.contains("endpoint key"), "{combined}"); + let key = endpoint_key_path(world); + assert!( + !key.exists(), + "a keyless server has a key file: {}", + key.display() + ); +} + +#[then("the CLI reports the stop as not confirmed and names no stop command")] +async fn reports_unconfirmed_no_command(world: &mut E2eWorld) { + let combined = assert_unconfirmed_stop_reported(world); + assert_no_retry_line(&combined); +} + // ── Helpers ──────────────────────────────────────────────────────── fn record(world: &mut E2eWorld, stdout: String, stderr: String, rc: i32) {