diff --git a/packages/orchestrator/pkg/hyperloopserver/handlers/logs.go b/packages/orchestrator/pkg/hyperloopserver/handlers/logs.go index 8f3b02ed18..965869e325 100644 --- a/packages/orchestrator/pkg/hyperloopserver/handlers/logs.go +++ b/packages/orchestrator/pkg/hyperloopserver/handlers/logs.go @@ -9,6 +9,7 @@ import ( "fmt" "net" "net/http" + "time" "github.com/gin-gonic/gin" "go.uber.org/zap" @@ -47,6 +48,13 @@ func (h *APIStore) Logs(c *gin.Context) { return } + if hasStaleLogTimestamp(payload, sbx.LifecycleStartedAt) { + h.sendAPIStoreError(c, http.StatusBadRequest, "Log timestamp predates this sandbox's resume") + h.logger.Warn(ctx, "dropping envd log with a stale pre-resume timestamp", logger.WithSandboxID(sbxID)) + + return + } + // Overwrite instanceID, envID, and teamID to avoid spoofing payload["instanceID"] = sbxID payload["envID"] = sbx.Runtime.TemplateID @@ -98,3 +106,28 @@ func (h *APIStore) validatePayloadSandboxID(payload map[string]any, sbxID string return nil } + +// Matches envd's zerolog timestamp format. +const envdTimestampLayout = time.RFC3339Nano + +// Allows normal host/guest clock skew. +const clockSkewTolerance = time.Minute + +// True if timestamp predates resume. +func hasStaleLogTimestamp(payload map[string]any, lifecycleStart time.Time) bool { + if lifecycleStart.IsZero() { + return false + } + + raw, ok := payload["timestamp"].(string) + if !ok { + return false + } + + ts, err := time.Parse(envdTimestampLayout, raw) + if err != nil { + return false + } + + return ts.Before(lifecycleStart.Add(-clockSkewTolerance)) +} diff --git a/packages/orchestrator/pkg/hyperloopserver/handlers/logs_test.go b/packages/orchestrator/pkg/hyperloopserver/handlers/logs_test.go new file mode 100644 index 0000000000..ccc2e51c68 --- /dev/null +++ b/packages/orchestrator/pkg/hyperloopserver/handlers/logs_test.go @@ -0,0 +1,102 @@ +//go:build linux + +package handlers + +import ( + "testing" + "time" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +func TestHasStaleLogTimestamp(t *testing.T) { + t.Parallel() + + lifecycleStart, err := time.Parse(envdTimestampLayout, "2026-07-16T10:00:00Z") + require.NoError(t, err) + + t.Run("timestamp from the snapshot-restored clock is stale", func(t *testing.T) { + t.Parallel() + + payload := map[string]any{"timestamp": "2026-06-09T08:00:00.123456789Z"} + + assert.True(t, hasStaleLogTimestamp(payload, lifecycleStart)) + }) + + t.Run("timestamp after lifecycle start is not stale", func(t *testing.T) { + t.Parallel() + + freshRaw := lifecycleStart.Add(time.Second).Format(envdTimestampLayout) + payload := map[string]any{"timestamp": freshRaw} + + assert.False(t, hasStaleLogTimestamp(payload, lifecycleStart)) + }) + + t.Run("timestamp at lifecycle start is not stale", func(t *testing.T) { + t.Parallel() + + payload := map[string]any{"timestamp": lifecycleStart.Format(envdTimestampLayout)} + + assert.False(t, hasStaleLogTimestamp(payload, lifecycleStart)) + }) + + t.Run("timestamp at the cutoff is not stale", func(t *testing.T) { + t.Parallel() + + cutoffRaw := lifecycleStart.Add(-clockSkewTolerance).Format(envdTimestampLayout) + payload := map[string]any{"timestamp": cutoffRaw} + + assert.False(t, hasStaleLogTimestamp(payload, lifecycleStart)) + }) + + t.Run("timestamp within clock-skew tolerance is not stale", func(t *testing.T) { + t.Parallel() + + withinToleranceRaw := lifecycleStart.Add(-clockSkewTolerance / 2).Format(envdTimestampLayout) + payload := map[string]any{"timestamp": withinToleranceRaw} + + assert.False(t, hasStaleLogTimestamp(payload, lifecycleStart)) + }) + + t.Run("timestamp past the cutoff is stale", func(t *testing.T) { + t.Parallel() + + staleRaw := lifecycleStart.Add(-clockSkewTolerance - time.Second).Format(envdTimestampLayout) + payload := map[string]any{"timestamp": staleRaw} + + assert.True(t, hasStaleLogTimestamp(payload, lifecycleStart)) + }) + + t.Run("zero lifecycle start disables stale detection", func(t *testing.T) { + t.Parallel() + + payload := map[string]any{"timestamp": "2026-06-09T08:00:00Z"} + + assert.False(t, hasStaleLogTimestamp(payload, time.Time{})) + }) + + t.Run("missing timestamp is not stale", func(t *testing.T) { + t.Parallel() + + payload := map[string]any{"message": "hello"} + + assert.False(t, hasStaleLogTimestamp(payload, lifecycleStart)) + }) + + t.Run("non-string timestamp is not stale", func(t *testing.T) { + t.Parallel() + + payload := map[string]any{"timestamp": 12345} + + assert.False(t, hasStaleLogTimestamp(payload, lifecycleStart)) + }) + + t.Run("invalid timestamp is not stale", func(t *testing.T) { + t.Parallel() + + payload := map[string]any{"timestamp": "not-a-time"} + + assert.False(t, hasStaleLogTimestamp(payload, lifecycleStart)) + }) +} diff --git a/packages/orchestrator/pkg/sandbox/sandbox.go b/packages/orchestrator/pkg/sandbox/sandbox.go index 2d6a33b3e4..d52651a5c2 100644 --- a/packages/orchestrator/pkg/sandbox/sandbox.go +++ b/packages/orchestrator/pkg/sandbox/sandbox.go @@ -270,6 +270,9 @@ type Sandbox struct { // every time a new Firecracker VM is started. LifecycleID string + // Fresh host timestamp marking lifecycle start. + LifecycleStartedAt time.Time + config cfg.BuilderConfig files *storage.SandboxFiles cleanup *Cleanup @@ -599,7 +602,8 @@ func (f *Factory) CreateSandbox( } sbx := &Sandbox{ - LifecycleID: lifecycleID, + LifecycleID: lifecycleID, + LifecycleStartedAt: time.Now().UTC(), Resources: resources, Metadata: metadata, @@ -1010,7 +1014,8 @@ func (f *Factory) ResumeSandbox( } sbx := &Sandbox{ - LifecycleID: lifecycleID, + LifecycleID: lifecycleID, + LifecycleStartedAt: time.Now().UTC(), Resources: resources, Metadata: metadata,