From 7dda8c2a6e67dd62da9dd0aac15166a66b1846c2 Mon Sep 17 00:00:00 2001 From: Nikhil Unni Date: Wed, 7 Oct 2026 16:03:41 -0700 Subject: [PATCH] fix(firecracker): a guest that dies fails its agent-ready waiters at once, with the console tail `wait_agent_ready` sat out its full 180 s deadline when the guest died first: the supervisor pruned the sandbox and deleted the jail, but the ready-dial listener kept the watch sender alive, so waiters saw neither "ready" nor "closed". A base capture whose guest panicked at boot hung with no diagnosis, and the console log was gone before anyone read it. The listener is now owned by the sandbox. Prune and destroy read the last 4 KiB of `firecracker.log` before the jail is removed, store it as the sandbox's death note, log it at WARN on an unexpected death, and abort the listener. A closed watch becomes "guest died before agentd dialed ready port" with the console tail attached. The ready fast path and the 180 s backstop for a hung guest are unchanged. Tests: two pending waiters receive the panic marker after the supervisor's real teardown callback; the same without a console file; explicit destroy; a tail that starts inside a UTF-8 character; pooled base capture propagates the death within one second and still destroys the VM; a KVM lifecycle test boots a fixture whose init exits and asserts the failure names the kernel panic within 15 s. Co-Authored-By: Claude Fable 5.1 Claude-Session: https://claude.ai/code/session_01UHxL6gj4o8EvxYpgtwEWaM --- .../engram-host-agent/src/pooled_backend.rs | 66 ++++++ crates/engram-sandbox-firecracker/src/lib.rs | 208 ++++++++++++++++-- .../tests/lifecycle.rs | 54 +++++ 3 files changed, 308 insertions(+), 20 deletions(-) diff --git a/crates/engram-host-agent/src/pooled_backend.rs b/crates/engram-host-agent/src/pooled_backend.rs index 55693b59f..f94e678bd 100644 --- a/crates/engram-host-agent/src/pooled_backend.rs +++ b/crates/engram-host-agent/src/pooled_backend.rs @@ -11240,6 +11240,72 @@ mod tests { } } + #[tokio::test] + async fn base_capture_propagates_guest_death() { + struct DeadGuest(Arc); + #[async_trait] + impl SandboxBackend for DeadGuest { + async fn create(&self, _: SandboxSpec) -> Result { + Ok(SandboxId::new()) + } + async fn wait_agent_ready(&self, _: SandboxId) -> Result<(), SandboxError> { + Err(SandboxError::Vm( + "guest died before agentd dialed ready port: Kernel panic: capture-tail-marker" + .into(), + )) + } + async fn exec_stream( + &self, + _: SandboxId, + _: ExecRequest, + ) -> Result { + unreachable!("dead guest must not execute a warm hook") + } + async fn snapshot(&self, _: SandboxId) -> Result { + unreachable!("dead guest must not be captured") + } + fn snapshot_path_for(&self, _: engram_core::SnapshotId) -> PathBuf { + unreachable!("dead guest has no snapshot") + } + async fn restore(&self, _: SnapshotMetadata) -> Result { + unreachable!("cold boot") + } + async fn destroy(&self, _: SandboxId) -> Result<(), SandboxError> { + self.0.store(true, std::sync::atomic::Ordering::SeqCst); + Ok(()) + } + async fn list(&self) -> Result, SandboxError> { + Ok(Vec::new()) + } + async fn start_agent(&self, _: SandboxId, _: AgentSpec) -> Result<(), SandboxError> { + unreachable!("base capture does not start a harness") + } + } + let destroyed = Arc::new(std::sync::atomic::AtomicBool::new(false)); + let pooled = PooledBackend::new(Arc::new(DeadGuest(destroyed.clone()))); + let (progress, _rx) = tokio::sync::mpsc::channel(16); + let error = tokio::time::timeout( + std::time::Duration::from_secs(1), + pooled.build_base_snapshot( + engram_core::traits::sandbox::BuildBaseSnapshotRequest { + spec: live_spec("dead-guest"), + warm: None, + capture_env: Default::default(), + capture_egress: None, + cold_base_plan: engram_core::types::capture_job::ColdBasePlan::NotApplicable, + }, + progress, + ), + ) + .await + .expect("capture must fail promptly") + .unwrap_err() + .to_string(); + assert!(error.contains("guest died before agentd dialed"), "{error}"); + assert!(error.contains("capture-tail-marker"), "{error}"); + assert!(destroyed.load(std::sync::atomic::Ordering::SeqCst)); + } + /// Review finding 1: a slow cold boot (agentd-ready takes a while) /// must keep emitting `phase=boot` `CaptureProgress` on the keepalive /// interval — not just the one frame at the very start — or the diff --git a/crates/engram-sandbox-firecracker/src/lib.rs b/crates/engram-sandbox-firecracker/src/lib.rs index 19f96b4d0..8d1cca2dc 100644 --- a/crates/engram-sandbox-firecracker/src/lib.rs +++ b/crates/engram-sandbox-firecracker/src/lib.rs @@ -812,6 +812,31 @@ impl FirecrackerConfig { } } +/// The sandbox owns the listener. Waiters keep the console note after removal. +struct AgentReadiness { + receiver: tokio::sync::watch::Receiver, + listener: Option>, + death_note: Arc>, +} + +impl From> for AgentReadiness { + fn from(receiver: tokio::sync::watch::Receiver) -> Self { + Self { + receiver, + listener: None, + death_note: Arc::new(std::sync::OnceLock::new()), + } + } +} + +impl Drop for AgentReadiness { + fn drop(&mut self) { + if let Some(listener) = &self.listener { + listener.abort(); + } + } +} + /// Live sandbox handle. Keeps the spawned firecracker `Child` so /// `destroy` can SIGKILL it. ADR 0044 K2 removed `kill_on_drop` from /// the FC and uffd-handler `Child`s so a live VM is decoupled from the @@ -883,7 +908,7 @@ struct LiveSandbox { /// sandboxes pre-set to `true` because agentd was already /// running when the snapshot was captured. Replaces the /// pre-M1 boot-race CONNECT-then-retry on port 1024. - agent_ready: tokio::sync::watch::Receiver, + agent_ready: AgentReadiness, /// RAM ledger (issue #540): true iff this sandbox is RAM-resident /// but its session no longer holds a coordinator memory reservation /// (epic-parking-ladder rungs 2-3). Always `false` today — no @@ -1237,6 +1262,7 @@ impl FirecrackerBackend { net_allocator, vm_cgroup_parent, work_dir, + true, )) } } @@ -1579,7 +1605,7 @@ impl FirecrackerBackend { #[cfg(target_os = "linux")] parked: false, agentd_slot_swapped: false, - agent_ready: ready_rx, + agent_ready: ready_rx.into(), vsock_epoch: tokio::sync::watch::channel(0).0, }, ); @@ -2705,7 +2731,7 @@ impl FirecrackerBackend { /// watch sender to `true`; `start_agent` blocks on the matching /// receiver and proceeds straight to SpawnHarness with no poll. /// - /// Returns the receiver half; caller stores it in `LiveSandbox`. + /// Returns the receiver and owned task; caller stores them in `LiveSandbox`. /// The accept task owns the sender and exits after the first /// successful dial (subsequent dials are no-ops — agentd only /// signals once per process lifetime). @@ -2713,7 +2739,7 @@ impl FirecrackerBackend { &self, sandbox_id: SandboxId, vsock_uds_path: &Path, - ) -> Result, SandboxError> { + ) -> Result { let path = per_port_uds(vsock_uds_path, engram_agentd::ENGRAM_AGENTD_READY_PORT); let _ = tokio::fs::remove_file(&path).await; let listener = tokio::net::UnixListener::bind(&path).map_err(|e| { @@ -2726,7 +2752,7 @@ impl FirecrackerBackend { ) })?; let (tx, rx) = tokio::sync::watch::channel(false); - tokio::spawn(async move { + let listener = tokio::spawn(async move { // ADR 0020: keep accepting until we read a valid AgentReady, rather // than giving up after the first connection. On a slow cold boot the // guest's vsock connect can time out (FC's single device thread @@ -2736,7 +2762,7 @@ impl FirecrackerBackend { // first failure drops `tx`, the channel closes, and `wait_agent_ready` // returns "channel closed" instead of waiting its full deadline. // Bounded just past `wait_agent_ready`'s 180s so the task + UDS - // listener can't outlive a destroyed sandbox. + // listener has a backstop even if no caller waits. let listen = async { loop { match listener.accept().await { @@ -2778,7 +2804,9 @@ impl FirecrackerBackend { }; let _ = tokio::time::timeout(Duration::from_secs(190), listen).await; }); - Ok(rx) + let mut readiness = AgentReadiness::from(rx); + readiness.listener = Some(listener); + Ok(readiness) } /// Bind a host-side UDS for inbound harness connections from @@ -3790,7 +3818,7 @@ impl FirecrackerBackend { #[cfg(target_os = "linux")] parked: false, agentd_slot_swapped, - agent_ready: ready_rx, + agent_ready: ready_rx.into(), vsock_epoch: tokio::sync::watch::channel(0).0, }, ); @@ -5087,9 +5115,9 @@ async fn read_tail(path: &Path, max: u64) -> Option { if len > max { f.seek(SeekFrom::Start(len - max)).await.ok()?; } - let mut buf = String::new(); - f.read_to_string(&mut buf).await.ok()?; - Some(buf) + let mut buf = Vec::new(); + f.take(max).read_to_end(&mut buf).await.ok()?; + Some(String::from_utf8_lossy(&buf).into_owned()) } #[async_trait] @@ -5598,7 +5626,15 @@ impl SandboxBackend for FirecrackerBackend { let work_dir = self.work_dir.clone(); Box::pin(async move { if let Some(live) = live { - destroy_teardown(id, live, net_allocator, vm_cgroup_parent, work_dir).await; + destroy_teardown( + id, + live, + net_allocator, + vm_cgroup_parent, + work_dir, + false, + ) + .await; } Ok(()) }) @@ -6238,9 +6274,12 @@ impl SandboxBackend for FirecrackerBackend { /// reach a quiescent guest without spawning a session harness. #[tracing::instrument(name = "fc.wait_agent_ready", skip_all, fields(sandbox_id = %id))] async fn wait_agent_ready(&self, id: SandboxId) -> Result<(), SandboxError> { - let mut agent_ready = { + let (mut agent_ready, death_note) = { let live = self.sandboxes.get(&id).ok_or(SandboxError::NotFound)?; - live.agent_ready.clone() + ( + live.agent_ready.receiver.clone(), + live.agent_ready.death_note.clone(), + ) }; // Generous deadline (180 s): the dev-vm's fake-gcs path can // stretch chunked-NBD page-ins to ~2-3 min on a cold cache; @@ -6263,7 +6302,13 @@ impl SandboxBackend for FirecrackerBackend { ) })? .map_err(|e| { - SandboxError::Vm(format!("agent_ready watch closed unexpectedly: {e}").into()) + let tail = death_note + .get() + .map(String::as_str) + .unwrap_or("console tail unavailable"); + SandboxError::Vm(format!( + "guest died before agentd dialed ready port: {e}\n--- firecracker log ---\n{tail}" + ).into()) })?; } Ok(()) @@ -6652,6 +6697,7 @@ async fn destroy_teardown( net_allocator: Arc>, vm_cgroup_parent: Option, work_dir: PathBuf, + unexpected: bool, ) { // Belt-and-braces kill backstop (issue #196): arm a SIGKILL guard for // the FC and uffd pids up front. If this task is itself aborted before @@ -6666,6 +6712,20 @@ async fn destroy_teardown( .or(live.uffd_pid) .map(SpawnKillGuard::new); + // Save the console before the jail is removed, then wake all ready waiters. + let log_path = work_dir.join(id.to_string()).join("firecracker.log"); + let tail = read_tail(&log_path, 4096) + .await + .unwrap_or_else(|| "console tail unavailable".into()); + if unexpected { + tracing::warn!(sandbox_id = %id, console_tail = %tail, "unexpected guest death"); + } + let _ = live.agent_ready.death_note.set(tail); + if let Some(listener) = live.agent_ready.listener.take() { + listener.abort(); + let _ = listener.await; + } + // Try a graceful shutdown first: PUT /actions { SendCtrlAltDel } // tells the guest kernel to halt cleanly via the keyboard // controller's CAD signal, draining the page cache before we @@ -9240,7 +9300,7 @@ mod tests { #[cfg(target_os = "linux")] parked: false, agentd_slot_swapped: false, - agent_ready, + agent_ready: agent_ready.into(), vsock_epoch: tokio::sync::watch::channel(0).0, } }; @@ -9309,7 +9369,7 @@ mod tests { #[cfg(target_os = "linux")] parked: false, agentd_slot_swapped: false, - agent_ready, + agent_ready: agent_ready.into(), vsock_epoch: tokio::sync::watch::channel(0).0, } }; @@ -9349,6 +9409,114 @@ mod tests { assert!(super::read_smaps_rollup_pss_rss(u32::MAX).await.is_none()); } + #[tokio::test] + async fn console_tail_keeps_marker_after_partial_utf8() { + let dir = tempfile::tempdir().unwrap(); + let log = dir.path().join("firecracker.log"); + let marker = "Kernel panic: tail-marker"; + std::fs::write(&log, format!("é{marker}")).unwrap(); + // The tail starts at the second byte of the first character. + let tail = read_tail(&log, marker.len() as u64 + 1).await.unwrap(); + assert!(tail.ends_with(marker), "{tail}"); + } + + async fn dead_guest_fails_ready_waiters(console: Option<&str>, unexpected: bool) { + let (be, _dir) = backend(); + let id = SandboxId::new(); + let jail = be.work_dir.join(id.to_string()); + std::fs::create_dir_all(&jail).unwrap(); + if let Some(console) = console { + std::fs::write(jail.join("firecracker.log"), console).unwrap(); + } + // Keep the UDS below macOS's 104-byte path limit. + let sockets = tempfile::tempdir_in("/tmp").unwrap(); + let vsock = sockets.path().join("vsock.sock"); + let readiness = be.spawn_agent_ready_listener(id, &vsock).await.unwrap(); + let listener_abort = readiness.listener.as_ref().unwrap().abort_handle(); + let mut child = tokio::process::Command::new("sleep") + .arg("30") + .kill_on_drop(true) + .spawn() + .unwrap(); + let pid = child.id().unwrap(); + child.kill().await.unwrap(); + child.wait().await.unwrap(); + be.sandboxes.insert( + id, + LiveSandbox { + state: SandboxState { + spec: spec(), + firecracker_socket: jail.join("firecracker.sock"), + rootfs_path: jail.join("rootfs.ext4"), + vsock_cid: 3, + vsock_uds_path: vsock, + rootfs_canonical: jail.join("rootfs.ext4"), + swap_canonical: None, + memory_backing: None, + }, + child: Some(child), + fc_pid: Some(pid), + uffd_handler: None, + uffd_pid: None, + net: None, + netns: None, + guest_endpoints: parking_lot::Mutex::new(None), + agentd_slot_swapped: false, + agent_ready: readiness, + #[cfg(target_os = "linux")] + parked: false, + vsock_epoch: tokio::sync::watch::channel(0).0, + }, + ); + let mut first = Box::pin(be.wait_agent_ready(id)); + let mut second = Box::pin(be.wait_agent_ready(id)); + assert!(futures::poll!(&mut first).is_pending()); + assert!(futures::poll!(&mut second).is_pending()); + tokio::time::timeout(Duration::from_secs(1), async { + // Call the supervisor's actual prune callback, without its polling delay. + if unexpected { + let (_, live) = be.sandboxes.remove(&id).unwrap(); + be.supervisor_teardown_fn()(id, live).await; + } else { + be.destroy(id).await.unwrap(); + } + }) + .await + .expect("prune must stop the ready listener within one second"); + assert!(!jail.exists(), "tail must survive removal of the jail"); + for waiter in [first, second] { + let error = tokio::time::timeout(Duration::from_secs(1), waiter) + .await + .expect("dead guest must wake every waiter") + .unwrap_err() + .to_string(); + assert!(error.contains("guest died before agentd dialed"), "{error}"); + assert!( + error.contains(console.unwrap_or("console tail unavailable")), + "{error}" + ); + } + assert!( + listener_abort.is_finished(), + "listener must stop during teardown" + ); + } + + #[tokio::test] + async fn pruned_guest_fails_ready_waiters_with_console_tail() { + dead_guest_fails_ready_waiters(Some("Kernel panic: ready-tail-marker"), true).await; + } + + #[tokio::test] + async fn pruned_guest_without_console_fails_ready_waiters() { + dead_guest_fails_ready_waiters(None, true).await; + } + + #[tokio::test] + async fn destroyed_guest_fails_ready_waiters() { + dead_guest_fails_ready_waiters(Some("destroy-tail-marker"), false).await; + } + /// Issue #540: `guest_memory_stats` must bucket PSS/RSS by the /// per-sandbox `parked` flag so the RAM ledger never adds a parked /// resident's memory back into `allocatable_mib`. Both entries @@ -9386,7 +9554,7 @@ mod tests { guest_endpoints: parking_lot::Mutex::new(None), parked: false, agentd_slot_swapped: false, - agent_ready: agent_ready.clone(), + agent_ready: agent_ready.clone().into(), vsock_epoch: tokio::sync::watch::channel(0).0, }, ); @@ -9404,7 +9572,7 @@ mod tests { guest_endpoints: parking_lot::Mutex::new(None), parked: false, agentd_slot_swapped: false, - agent_ready: agent_ready.clone(), + agent_ready: agent_ready.clone().into(), vsock_epoch: tokio::sync::watch::channel(0).0, }, ); @@ -9550,7 +9718,7 @@ mod tests { #[cfg(target_os = "linux")] parked: false, agentd_slot_swapped: false, - agent_ready, + agent_ready: agent_ready.into(), vsock_epoch: tokio::sync::watch::channel(0).0, }, ); diff --git a/crates/engram-sandbox-firecracker/tests/lifecycle.rs b/crates/engram-sandbox-firecracker/tests/lifecycle.rs index b6018f3ed..d6663c700 100644 --- a/crates/engram-sandbox-firecracker/tests/lifecycle.rs +++ b/crates/engram-sandbox-firecracker/tests/lifecycle.rs @@ -135,3 +135,57 @@ async fn create_list_destroy_round_trip() { .await .expect("destroy on unknown id is no-op"); } + +/// A PID 1 exit must reach ready waiters before the normal boot deadline. +#[tokio::test] +#[ignore = "requires Linux + KVM + firecracker + static busybox"] +async fn init_exit_fails_ready_with_kernel_panic() { + let Some(env) = common::fc_preflight() else { + return; + }; + let busybox = common::find_busybox().expect("static busybox fixture dependency"); + let work = tempfile::tempdir().unwrap(); + let blobs = std::sync::Arc::new(engram_storage_local::LocalBlobStorage::new( + work.path().join("blobs"), + )); + let chunks = engram_chunk_store::ChunkStore::new(blobs); + let rootfs = work.path().join("panic.ext4"); + common::bake_fixture_ext4(&rootfs, &chunks, &busybox, None, |tree| { + use std::os::unix::fs::PermissionsExt; + let init = tree.join("sbin/engram-init"); + std::fs::write(&init, "#!/bin/sh\nexit 0\n")?; + std::fs::set_permissions(init, std::fs::Permissions::from_mode(0o755)) + }) + .await; + let mut cfg = FirecrackerConfig::with_kernel(env.kernel); + cfg.net_pool = None; + let backend = FirecrackerBackend::new(work.path(), cfg); + let id = backend + .create(SandboxSpec { + image: "init-exit-fixture".into(), + rootfs_source: Some(rootfs), + image_uri: None, + rootfs_manifest: None, + cpu: CpuLimit { vcpus: 1 }, + memory: MemoryLimit { max_mib: 64 }, + disk: DiskLimit { max_gib: 1 }, + ttl: None, + env: HashMap::new(), + workdir: None, + network: Default::default(), + aux_ro_drives: Vec::new(), + swap_mib: None, + swap_source: None, + swap_manifest: None, + }) + .await + .expect("boot exit fixture"); + let result = tokio::time::timeout(Duration::from_secs(15), backend.wait_agent_ready(id)).await; + backend.destroy(id).await.expect("cleanup"); + let error = result + .expect("dead guest must fail within 15 seconds") + .expect_err("PID 1 exited") + .to_string(); + assert!(error.contains("guest died before agentd dialed"), "{error}"); + assert!(error.contains("Kernel panic"), "{error}"); +}