diff --git a/packages/orchestrator/pkg/sandbox/sandbox.go b/packages/orchestrator/pkg/sandbox/sandbox.go index 3ff51305ab..c674ae175e 100644 --- a/packages/orchestrator/pkg/sandbox/sandbox.go +++ b/packages/orchestrator/pkg/sandbox/sandbox.go @@ -52,6 +52,9 @@ var ( envdCollapseChunks = utils.Must(telemetry.GetCounter(meter, telemetry.EnvdCollapseChunks)) guestSyncDurationHistogram = utils.Must(telemetry.GetHistogram(meter, telemetry.GuestSyncDurationHistogramName)) + processMemoryDurationHistogram = utils.Must(telemetry.GetHistogram(meter, telemetry.SnapshotProcessMemoryDurationName)) + processRootfsDurationHistogram = utils.Must(telemetry.GetHistogram(meter, telemetry.SnapshotProcessRootfsDurationName)) + uffdStartupPagesHistogram = utils.Must(telemetry.GetHistogram(meter, telemetry.UffdStartupPagesHistogramName)) uffdStartupSourcePagesHistogram = utils.Must(telemetry.GetHistogram(meter, telemetry.UffdStartupSourcePagesHistogramName)) uffdStartupBytesHistogram = utils.Must(telemetry.GetHistogram(meter, telemetry.UffdStartupBytesHistogramName)) @@ -1459,6 +1462,7 @@ func (s *Sandbox) Pause( closeHook: s.Close, }, s.config.DefaultCacheDir, + pauseOpts.filesystemSnapshot, ) if err != nil { return nil, fmt.Errorf("error while post processing: %w", err) @@ -1644,6 +1648,14 @@ func pauseProcessMemory( ctx, span := tracer.Start(ctx, "process-memory") defer span.End() + // Duration of the synchronous memory export+diff (memory pauses only; fs-only + // pauses skip this). The async header dedup goroutine below outlives this span. + start := time.Now() + defer func() { + processMemoryDurationHistogram.Record(ctx, time.Since(start).Milliseconds(), + metric.WithAttributes(attribute.Bool("success", e == nil))) + }() + memfileDiffPath := build.GenerateDiffCachePath(cacheDir, buildID.String(), build.Memfile) metaOut := utils.NewSetOnce[*header.DiffMetadata]() // ExportMemory owns memfd and closes it on all paths. @@ -1756,10 +1768,22 @@ func pauseProcessRootfs( originalHeader *header.Header, diffCreator DiffCreator, cacheDir string, + filesystemOnly bool, ) (d build.Diff, h *header.Header, e error) { ctx, span := tracer.Start(ctx, "process-rootfs") defer span.End() + // Duration of the rootfs export+diff, split by fs_only (runs for both pause + // kinds) so the fs-only pause latency can be decomposed into quiesce + rootfs. + start := time.Now() + defer func() { + processRootfsDurationHistogram.Record(ctx, time.Since(start).Milliseconds(), + metric.WithAttributes( + attribute.Bool("fs_only", filesystemOnly), + attribute.Bool("success", e == nil), + )) + }() + rootfsDiffFile, err := build.NewLocalDiffFile(cacheDir, buildId.String(), build.Rootfs) if err != nil { return nil, nil, fmt.Errorf("failed to create rootfs diff: %w", err) diff --git a/packages/shared/pkg/telemetry/meters.go b/packages/shared/pkg/telemetry/meters.go index 24a1664315..736bd69d25 100644 --- a/packages/shared/pkg/telemetry/meters.go +++ b/packages/shared/pkg/telemetry/meters.go @@ -107,6 +107,8 @@ const ( WaitForEnvdDurationHistogramName HistogramType = "orchestrator.sandbox.envd.init.duration" GuestSyncDurationHistogramName HistogramType = "orchestrator.sandbox.guest_sync.duration" PauseDurationHistogramName HistogramType = "orchestrator.sandbox.pause.duration" + SnapshotProcessMemoryDurationName HistogramType = "orchestrator.sandbox.snapshot.process_memory.duration" + SnapshotProcessRootfsDurationName HistogramType = "orchestrator.sandbox.snapshot.process_rootfs.duration" // Pre-pause envd heap collapse round-trip duration (the pause-path cost of // POST /collapse: network plus envd's madvise work), recorded once per pause @@ -453,6 +455,8 @@ var histogramDesc = map[HistogramType]string{ EnvdCollapseDurationHistogramName: "Time taken for the pre-pause envd heap collapse round-trip", GuestSyncDurationHistogramName: "Time taken for the mandatory pre-pause guest sync (filesystem-only pause)", PauseDurationHistogramName: "Time taken to pause a sandbox, labeled by fs_only (filesystem-only vs memory) and success", + SnapshotProcessMemoryDurationName: "Time to export+diff the memory file during a pause snapshot (memory pauses only), labeled by success", + SnapshotProcessRootfsDurationName: "Time to export+diff the rootfs during a pause snapshot, labeled by fs_only and success", PauseResumePrefetchHarvestDurationName: "Time taken for a pause-resume prefetch harvest run (slot-hold cost)", PauseResumePrefetchHarvestPagesName: "Harvested resume-prefetch trace size in 2 MiB blocks, per successful harvest", @@ -504,6 +508,8 @@ var histogramUnits = map[HistogramType]string{ EnvdCollapseDurationHistogramName: "ms", GuestSyncDurationHistogramName: "ms", PauseDurationHistogramName: "ms", + SnapshotProcessMemoryDurationName: "ms", + SnapshotProcessRootfsDurationName: "ms", PauseResumePrefetchHarvestDurationName: "ms", PauseResumePrefetchHarvestPagesName: "{page}", UffdStartupPagesHistogramName: "{page}",