From 5c0ca8a19ef0e80e585a4d88e70b3335507600d9 Mon Sep 17 00:00:00 2001 From: nashzhou Date: Thu, 15 Oct 2026 21:14:28 +0800 Subject: [PATCH] feat(metrics): break stop into wait_process/release_devices/release_network The stop stage sits at 1.5-2s under high pause/resume concurrency and on-CPU flame graphs attribute none of it: the time hides in off-CPU waits - the SIGTERM->waitpid over the dying Firecracker process (whose teardown runs kernel-side), the ublk release RPCs (the daemon drops device page cache via fadvise before returning a device to the pool), and the synchronous network-slot release. Split the existing stop stage into three sub-stages on a dedicated operation="stop" so existing dashboards can attribute the wall time: - stop.wait_process: SIGTERM + wait for the VMM process to exit - stop.release_devices: rootfs/tools/memory/extra-drive ublk releases - stop.release_network: network slot release The outer pause-op stage="stop" timer keeps its meaning as the total. Verified with cargo check and the firecracker::sandbox unit suite (28 tests). --- src/sandbox/firecracker/sandbox.rs | 92 +++++++++++++++++------------- 1 file changed, 53 insertions(+), 39 deletions(-) diff --git a/src/sandbox/firecracker/sandbox.rs b/src/sandbox/firecracker/sandbox.rs index cd0ea82..e6f2d88 100644 --- a/src/sandbox/firecracker/sandbox.rs +++ b/src/sandbox/firecracker/sandbox.rs @@ -29,6 +29,7 @@ use crate::sandbox::custom_extension::{ use crate::sandbox::manifest::SandboxSnapshotManifest; use crate::cfg::ConfigManager; +use crate::observability::prometheus::SandboxStageTimer; use crate::sandbox::access::EnvdAccessToken; use crate::sandbox::backend::{ CapturedSandboxSnapshot, PausedSandboxState, RuntimeArtifactSet, SandboxBackend, @@ -1384,9 +1385,13 @@ impl FirecrackerSandbox { #[tracing::instrument(skip(self))] pub async fn stop(&mut self) -> Result<()> { debug!("stopping firecracker sandbox"); + let timer = SandboxStageTimer::new("stop"); - self.fc_instance - .stop(self.runtime_policy.socket_timeout) + timer + .time( + "stop.wait_process", + self.fc_instance.stop(self.runtime_policy.socket_timeout), + ) .await?; // Clear envd instance @@ -1397,43 +1402,48 @@ impl FirecrackerSandbox { self.frozen_volume_mounts.clear(); // Cleanup ublk device (must happen after FC stop, before network cleanup) - if let Some(runtime) = self.rootfs_runtime.take() { - if let Err(e) = UblkDeviceManager::global() - .release_device(&runtime.device) - .await - { - warn!(error = %e, "failed to release ublk device during stop"); - } - } + timer + .time("stop.release_devices", async { + if let Some(runtime) = self.rootfs_runtime.take() { + if let Err(e) = UblkDeviceManager::global() + .release_device(&runtime.device) + .await + { + warn!(error = %e, "failed to release ublk device during stop"); + } + } - // Release shared devices explicitly so a following resume for the same - // image cannot race the detached Drop cleanup. - if let Some(tools_device) = self.tools_ublk_device.take() { - if let Err(error) = tools_device.release().await { - warn!(error = %error, "failed to release shared tools device during stop"); - } - } - if let Some(mem_device) = self.mem_ublk_device.take() { - if let Err(e) = mem_device.release().await { - warn!(error = %e, "failed to release shared memory ublk device during stop"); - } - } + // Release shared devices explicitly so a following resume for the same + // image cannot race the detached Drop cleanup. + if let Some(tools_device) = self.tools_ublk_device.take() { + if let Err(error) = tools_device.release().await { + warn!(error = %error, "failed to release shared tools device during stop"); + } + } + if let Some(mem_device) = self.mem_ublk_device.take() { + if let Err(e) = mem_device.release().await { + warn!(error = %e, "failed to release shared memory ublk device during stop"); + } + } - // Dedicated pack-recording memory device: delete, never pool-release. - if let Some(device) = self.mem_dedicated_device.take() { - if let Err(e) = UblkDeviceManager::global().delete_device(&device).await { - warn!(error = %e, "failed to delete dedicated memory ublk device during stop"); - } - } + // Dedicated pack-recording memory device: delete, never pool-release. + if let Some(device) = self.mem_dedicated_device.take() { + if let Err(e) = UblkDeviceManager::global().delete_device(&device).await { + warn!(error = %e, "failed to delete dedicated memory ublk device during stop"); + } + } - for runtime in self.extra_drive_runtimes.drain(..) { - if let Err(e) = UblkDeviceManager::global() - .release_device(&runtime.device) - .await - { - warn!(error = %e, "failed to release extra drive device during stop"); - } - } + for runtime in self.extra_drive_runtimes.drain(..) { + if let Err(e) = UblkDeviceManager::global() + .release_device(&runtime.device) + .await + { + warn!(error = %e, "failed to release extra drive device during stop"); + } + } + Ok::<(), anyhow::Error>(()) + }) + .await?; // Invoke the stop hook before releasing network resources. Delivery // failures are logged inside the client and never fail stop(). @@ -1444,9 +1454,13 @@ impl FirecrackerSandbox { // Cleanup network resources if let Some(slot) = self.network_slot.take() { let idx = slot.idx; - NetworkManager::global() - .release(slot) - .context("Failed to release network slot")?; + timer + .time("stop.release_network", async { + NetworkManager::global() + .release(slot) + .context("Failed to release network slot") + }) + .await?; debug!(slot = idx, "network slot released"); } -- 2.43.0