Skip to content

feat(metrics): break down pause-snapshot latency by step #3426

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
bchalios merged 1 commit into from
Jul 28, 2026
Merged

feat(metrics): break down pause-snapshot latency by step #3426

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
24 changes: 24 additions & 0 deletions packages/orchestrator/pkg/sandbox/sandbox.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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))
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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.
Expand Down Expand Up @@ -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)
Expand Down
6 changes: 6 additions & 0 deletions packages/shared/pkg/telemetry/meters.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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",
Expand Down Expand Up @@ -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}",
Expand Down
Loading