From 93fe93a249d8db6b15169af16b472c2506016f1e Mon Sep 17 00:00:00 2001 From: nashzhou Date: Wed, 14 Oct 2026 11:55:40 +0800 Subject: [PATCH] feat(metrics): break pause and resume into stage duration metrics Pause and resume each had a single coarse stage sample in agentenv_sandbox_stage_duration_seconds; the internal segments (memory conversion, restack, persist, snapshot load) were only inferable by differencing against agentenv_ublk_operation_duration_seconds. Time the natural segments with the existing SandboxStageTimer so they land in the same stage metric family (operation/stage/status labels plus the inflight gauge): - pause path, shared with capture flows: volume_sync, vm_pause, vm_state, mem_convert, restack_rootfs, restack_drives. pause_to_dir/snapshot_to_dir/snapshot_memory_to_overlaybd now take an operation label -- "pause" from the pause entry points, and "snapshot" from snapshot/capture_to_dir -- so captures do not pollute pause breakdowns. - paused-state persistence (orchestrator): persist. - resume path: rootfs_device, extra_drives, fc_spawn, mem_acquire, load_snapshot under operation="resume". start_resume is also used by template-based warm creates; those invocations record under operation="resume" as well, so compare inner stage counts against the outer resume stage to attribute samples. No behavior change; instrumentation only. Example: avg by (stage) (rate(agentenv_sandbox_stage_duration_seconds_sum{operation="pause"}[5m])) / avg by (stage) (rate(agentenv_sandbox_stage_duration_seconds_count{operation="pause"}[5m])) --- src/orchestrator/service.rs | 15 +-- src/sandbox/firecracker/sandbox.rs | 164 ++++++++++++++++++----------- tests/integration/fc.rs | 4 +- 3 files changed, 111 insertions(+), 72 deletions(-) diff --git a/src/orchestrator/service.rs b/src/orchestrator/service.rs index 06c1d9c..f02ea86 100644 --- a/src/orchestrator/service.rs +++ b/src/orchestrator/service.rs @@ -14,6 +14,7 @@ use crate::cfg::ConfigManager; use crate::image::cache::{ local_image_services_from_global_config, RuntimeImageOwner, RuntimeImageRefs, }; +use crate::observability::prometheus::SandboxStageTimer; use crate::sandbox::{ CustomExtensionClient, CustomExtensionParams, EnvdAccessToken, FirecrackerSandboxFactory, FreshSandboxBuildSpec, PausedSandboxState, RuntimeArtifactSet, SandboxAccessTokenGenerator, @@ -1556,12 +1557,14 @@ where metadata.paused_state = Some(paused_state.clone()); metadata }; - if let Err(err) = self - .persister - .persist_paused( - &persisted_metadata, - artifact_root.as_deref(), - paused_state.as_ref(), + if let Err(err) = SandboxStageTimer::new("pause") + .time( + "persist", + self.persister.persist_paused( + &persisted_metadata, + artifact_root.as_deref(), + paused_state.as_ref(), + ), ) .await { diff --git a/src/sandbox/firecracker/sandbox.rs b/src/sandbox/firecracker/sandbox.rs index cd0ea82..f832a1d 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, @@ -367,7 +368,7 @@ impl SandboxBackend for FirecrackerSandbox { artifact_root: Option<&Path>, ) -> SandboxCaptureResult> { let pause_result = match artifact_root { - Some(artifact_root) => FirecrackerSandbox::pause_to_dir(self, artifact_root) + Some(artifact_root) => FirecrackerSandbox::pause_to_dir(self, artifact_root, "pause") .await .map(|(snapshot_config, _)| snapshot_config), None => FirecrackerSandbox::pause(self).await, @@ -386,7 +387,7 @@ impl SandboxBackend for FirecrackerSandbox { .map_err(SandboxCaptureError::from)?; let snapshot_dir = live_snapshot_root.path().join(Uuid::now_v7().to_string()); - let (snapshot_config, manifest) = match self.pause_to_dir(&snapshot_dir).await { + let (snapshot_config, manifest) = match self.pause_to_dir(&snapshot_dir, "snapshot").await { Ok(snapshot) => snapshot, Err(error) => { return self @@ -411,7 +412,7 @@ impl SandboxBackend for FirecrackerSandbox { SandboxSnapshotManifest, Option>, )> { - match self.pause_to_dir(at).await { + match self.pause_to_dir(at, "snapshot").await { Ok((snapshot_config, manifest)) => Ok((manifest, Some(Box::new(snapshot_config)))), Err(error) => self.recover_capture_failure("capture", error).await, } @@ -1141,7 +1142,7 @@ impl FirecrackerSandbox { snapshot_root.prepare().await?; let snapshot_dir = snapshot_root.path().join(Uuid::now_v7().to_string()); - let (mut snapshot, _) = self.pause_to_dir(&snapshot_dir).await?; + let (mut snapshot, _) = self.pause_to_dir(&snapshot_dir, "pause").await?; snapshot.managed_snapshot_root = Some(snapshot_root); Ok(snapshot) @@ -1152,22 +1153,26 @@ impl FirecrackerSandbox { pub async fn pause_to_dir( &mut self, snapshot_dir: &Path, + operation: &'static str, ) -> Result<(FirecrackerSnapshotConfig, SandboxSnapshotManifest)> { + let stages = SandboxStageTimer::new(operation); debug!(snapshot_dir = %snapshot_dir.display(), "pausing sandbox"); if self.has_writable_persistent_volumes() { let envd = self .envd_instance .clone() .context("cannot flush writable volumes because envd is not running")?; - Self::sync_writable_volume_filesystems(envd).await?; + stages + .time("volume_sync", Self::sync_writable_volume_filesystems(envd)) + .await?; } - self.fc_instance.pause().await?; + stages.time("vm_pause", self.fc_instance.pause()).await?; tokio::fs::create_dir_all(snapshot_dir) .await .with_context(|| format!("create snapshot dir {}", snapshot_dir.display()))?; - let snapshot_result = self.snapshot_to_dir(snapshot_dir).await; + let snapshot_result = self.snapshot_to_dir(snapshot_dir, &stages).await; match snapshot_result { Ok(snapshot) => Ok(snapshot), Err(err) => { @@ -1180,6 +1185,7 @@ impl FirecrackerSandbox { async fn snapshot_to_dir( &self, snapshot_dir: &Path, + stages: &SandboxStageTimer, ) -> Result<(FirecrackerSnapshotConfig, SandboxSnapshotManifest)> { let vm_state_path = snapshot_dir.join(VM_STATE_FILE_NAME); // Memory layers stay raw unless `[memory_snapshot].compression_enabled` @@ -1192,7 +1198,7 @@ impl FirecrackerSandbox { &global_config.snapshot.publish_compression, ); let (mem_layer_path, mem_virtual_size) = self - .snapshot_memory_to_overlaybd(&vm_state_path, snapshot_dir, memory_output) + .snapshot_memory_to_overlaybd(&vm_state_path, snapshot_dir, memory_output, stages) .await?; // Build the memory image config: collect parent layers, make runtime @@ -1245,14 +1251,18 @@ impl FirecrackerSandbox { .rootfs_runtime .as_ref() .context("overlaybd snapshot requires an active ublk device")?; - let rootfs_image_path = restack_snapshot_overlaybd_rootfs( - &rootfs_runtime.device, - overlaybd_source.read_only, - &rootfs_runtime.image_config_path, - snapshot_dir, - ) - .await - .context("snapshot overlaybd runtime state to persistent dir")?; + let rootfs_image_path = stages + .time( + "restack_rootfs", + restack_snapshot_overlaybd_rootfs( + &rootfs_runtime.device, + overlaybd_source.read_only, + &rootfs_runtime.image_config_path, + snapshot_dir, + ), + ) + .await + .context("snapshot overlaybd runtime state to persistent dir")?; let size = self .snapshot_rootfs_virtual_size() .context("persist rootfs virtual size for snapshot")?; @@ -1267,8 +1277,8 @@ impl FirecrackerSandbox { .context("persist rootfs virtual size for snapshot")?; (rootfs_path, size) }; - let snapshot_extra_drives = self - .snapshot_extra_drives(snapshot_dir) + let snapshot_extra_drives = stages + .time("restack_drives", self.snapshot_extra_drives(snapshot_dir)) .await .context("snapshot extra drives to persistent dir")?; let manifest_extra_drives = snapshot_extra_drives @@ -1340,24 +1350,32 @@ impl FirecrackerSandbox { vm_state_path: &Path, snapshot_dir: &Path, memory_output: OverlaybdCompactOutput, + stages: &SandboxStageTimer, ) -> Result<(PathBuf, u64)> { let mem_overlaybd_dir = snapshot_dir.join("mem_overlaybd"); let firecracker_pid = self.fc_instance.pid()?; - self.fc_instance - .create_state_only_snapshot(vm_state_path) + stages + .time( + "vm_state", + self.fc_instance.create_state_only_snapshot(vm_state_path), + ) .await?; // `vm_state.bin` now represents this paused VM state. Any later - // error aborts this direct snapshot attempt and is propagated to - // the lifecycle caller for recovery. + // error aborts this direct snapshot attempt and is propagated to the + // lifecycle caller for recovery. let dirty_ranges = self.fc_instance.get_dirty_memory_ranges().await?; - convert_dirty_memory_to_overlaybd( - firecracker_pid, - &dirty_ranges, - &mem_overlaybd_dir, - memory_output, - ) - .await - .context("convert dirty memory ranges to overlaybd layer") + stages + .time( + "mem_convert", + convert_dirty_memory_to_overlaybd( + firecracker_pid, + &dirty_ranges, + &mem_overlaybd_dir, + memory_output, + ), + ) + .await + .context("convert dirty memory ranges to overlaybd layer") } /// Resume a paused sandbox in-place. @@ -1944,6 +1962,7 @@ impl FirecrackerSandbox { "snapshot resume requires an available ublk daemon client \ because memory restore uses a shared ublk device" ); + let stages = SandboxStageTimer::new("resume"); let global_config = ConfigManager::global_config(); @@ -2010,17 +2029,22 @@ impl FirecrackerSandbox { let user_image_symlink = fc_cwd.join(USER_ROOTFS_DRIVE_PATH); let global_cfg_path = global_config.ublk.overlaybd.global_config_path.clone(); let runtime_dir = fc_cwd.join("overlaybd"); - let runtime_device = UblkDeviceManager::global() - .create_overlaybd_runtime_device(CreateOverlaybdRuntimeDeviceRequest { - source_image_config: &rootfs_image_config.image_config_path, - global_config: &global_cfg_path, - runtime_dir: &runtime_dir, - read_only: rootfs_image_config.read_only, - runtime_upper_mode: rootfs_image_config.runtime_upper_mode, - requested_virtual_size: Some(rootfs_virtual_size), - known_source_virtual_size: Some(rootfs_virtual_size), - allow_shrink: false, - }) + let runtime_device = stages + .time( + "rootfs_device", + UblkDeviceManager::global().create_overlaybd_runtime_device( + CreateOverlaybdRuntimeDeviceRequest { + source_image_config: &rootfs_image_config.image_config_path, + global_config: &global_cfg_path, + runtime_dir: &runtime_dir, + read_only: rootfs_image_config.read_only, + runtime_upper_mode: rootfs_image_config.runtime_upper_mode, + requested_virtual_size: Some(rootfs_virtual_size), + known_source_virtual_size: Some(rootfs_virtual_size), + allow_shrink: false, + }, + ), + ) .await .context("create user image overlaybd runtime device for resume")?; self.rootfs_image_config_path = Some(rootfs_image_config.image_config_path.clone()); @@ -2048,8 +2072,11 @@ impl FirecrackerSandbox { } // ── Extra drives ── - let extra_drive_attachments = self - .prepare_snapshot_backing_drives(&config.common.extra_drives) + let extra_drive_attachments = stages + .time( + "extra_drives", + self.prepare_snapshot_backing_drives(&config.common.extra_drives), + ) .await .context("prepare snapshot-backed extra drives for resume")?; // Snapshot loading reopens every serialized slot path, so all @@ -2100,13 +2127,16 @@ impl FirecrackerSandbox { let firecracker_binary = config.common.firecracker_binary.clone(); let (stdout_path, stderr_path) = self.firecracker_stdio_paths(); - self.fc_instance - .spawn_with_netns( - &firecracker_binary, - stdout_path.as_deref(), - stderr_path.as_deref(), - Some(&netns), - self.network_slot.as_ref().and_then(Slot::tap_handoff), + stages + .time( + "fc_spawn", + self.fc_instance.spawn_with_netns( + &firecracker_binary, + stdout_path.as_deref(), + stderr_path.as_deref(), + Some(&netns), + self.network_slot.as_ref().and_then(Slot::tap_handoff), + ), ) .await?; @@ -2208,13 +2238,16 @@ impl FirecrackerSandbox { ) .await; } - let mem_device = UblkDeviceManager::global() - .get_or_create_shared_mem( - &UblkCreateSpec::Overlaybd { - image_config: config.mem_overlaybd_config.image_config_path.clone(), - global_config: mem_global_config.clone(), - }, - config.mem_virtual_size, + let mem_device = stages + .time( + "mem_acquire", + UblkDeviceManager::global().get_or_create_shared_mem( + &UblkCreateSpec::Overlaybd { + image_config: config.mem_overlaybd_config.image_config_path.clone(), + global_config: mem_global_config.clone(), + }, + config.mem_virtual_size, + ), ) .await .context("create or reuse shared memory ublk device for resume")?; @@ -2242,13 +2275,16 @@ impl FirecrackerSandbox { SANDBOX_NET_IFACE_ID.to_string(), self.sandbox_host_dev_name(), )]; - self.fc_instance - .load_snapshot_file( - &vm_state_src, - &mem_device_path, - &network_overrides, - false, - config.common.track_dirty_pages, + stages + .time( + "load_snapshot", + self.fc_instance.load_snapshot_file( + &vm_state_src, + &mem_device_path, + &network_overrides, + false, + config.common.track_dirty_pages, + ), ) .await?; diff --git a/tests/integration/fc.rs b/tests/integration/fc.rs index a59b1c6..82454b5 100644 --- a/tests/integration/fc.rs +++ b/tests/integration/fc.rs @@ -351,7 +351,7 @@ async fn run_memory_snapshot_format_and_resume_case() -> Result<()> { write_disk_marker(&mut sandbox).await?; let snapshot_dir = tempfile::tempdir()?; - let (snapshot, _) = sandbox.pause_to_dir(snapshot_dir.path()).await?; + let (snapshot, _) = sandbox.pause_to_dir(snapshot_dir.path(), "pause").await?; sandbox.stop().await?; assert!(snapshot.vm_state_path.exists()); @@ -522,7 +522,7 @@ async fn snapshot_chain_survives_after_parent_snapshot_handle_is_dropped() -> Re // Also test pause_to_dir with snapshot-owned inherited layer adoption. let expected_snapshot_dir = tempfile::tempdir()?; let (dir_snapshot, _) = resumed_again - .pause_to_dir(expected_snapshot_dir.path()) + .pause_to_dir(expected_snapshot_dir.path(), "pause") .await?; resumed_again.stop().await?; let managed_snapshot_base_root = ConfigManager::global_config() -- 2.43.0