{"record":{"id":"afadd99c5327f47f","repo":"JuliusBrussee/caveman","slug":"schedule-drift","errorCode":"schedule_drift","errorMessage":"cachebench: request %q exceeded schedule drift tolerance","messagePattern":"cachebench: request %q exceeded schedule drift tolerance","errorType":"exception","errorClass":"ReplayRunError","httpStatus":null,"severity":"error","filePath":"cacheengine/cachebench/replay.go","lineNumber":578,"sourceCode":"\t\ttraceAt, _ := time.Parse(time.RFC3339Nano, record.At)\n\t\toffset, _ := scaledReplayGap(traceAt.Sub(anchorTrace), runner.TimeScale)\n\t\tscheduled := anchorReal.Add(offset)\n\t\tif delay := scheduled.Sub(now().UTC()); delay > 0 {\n\t\t\tif err := sleep(ctx, delay); err != nil {\n\t\t\t\treturn fmt.Errorf(\"cachebench: replay schedule interrupted: %w\", err)\n\t\t\t}\n\t\t}\n\t\tstarted := now().UTC()\n\t\tevidence := replayEvidenceBase(record, item.optimized, runner.TimeScale, scheduled, started, runner.Limits.MaxScheduleDrift)\n\t\tif runner.Limits.RequireGroundedTiming && evidence.ScheduleDriftMilliseconds > evidence.ScheduleToleranceMilliseconds {\n\t\t\tevidence.FailureCode = \"schedule_drift\"\n\t\t\tevidence.CompletedAt = now().UTC().Format(time.RFC3339Nano)\n\t\t\tif err := emitValidatedReplayResult(emit, ReplayResult{Evidence: evidence}); err != nil {\n\t\t\t\treturn err\n\t\t\t}\n\t\t\treturn &ReplayRunError{\n\t\t\t\tRequestID: record.RequestID, FailureCode: evidence.FailureCode,\n\t\t\t\tErr: fmt.Errorf(\"cachebench: request %q exceeded schedule drift tolerance\", record.RequestID),\n\t\t\t}\n\t\t}\n\t\tresult, runErr := runner.executePrepared(ctx, item, evidence, started, now)\n\t\tif err := emitValidatedReplayResult(emit, result); err != nil {\n\t\t\treturn err\n\t\t}\n\t\tif runErr != nil {\n\t\t\treturn runErr\n\t\t}\n\t}\n\treturn nil\n}\n\nfunc (runner ReplayRunner) runConcurrent(ctx context.Context, prepared []preparedReplay, anchorTrace, anchorReal time.Time, now func() time.Time, sleep func(context.Context, time.Duration) error, emit func(ReplayResult) error) error {\n\tscheduleCtx, stopScheduling := context.WithCancel(ctx)\n\tdefer stopScheduling()\n\tsemaphore := make(chan struct{}, runner.Limits.MaxConcurrency)\n\tvar workers sync.WaitGroup","sourceCodeStart":560,"sourceCodeEnd":596,"githubUrl":"https://github.com/JuliusBrussee/caveman/blob/27d5a3981a347890211bb1bf2439e5c821a63bc9/cacheengine/cachebench/replay.go#L560-L596","documentation":"With Limits.RequireGroundedTiming enabled, a sequential replay request started later than its scheduled time by more than the drift tolerance (derived from Limits.MaxScheduleDrift). The harness fails the request with FailureCode schedule_drift and emits its evidence record, because timing-sensitive measurements are invalid when real send time diverges from the schedule.","triggerScenarios":"sleep returning late (scheduler contention, GC pause, overloaded host) so started - scheduled exceeds ScheduleToleranceMilliseconds; a too-tight MaxScheduleDrift for the achievable pacing; TimeScale so small that sub-millisecond scheduling is expected.","commonSituations":"Running timing-grounded replays on shared CI runners or busy laptops; MaxScheduleDrift left at a strict default while the machine cannot keep up; long traces where occasional pauses accumulate.","solutions":["Raise Limits.MaxScheduleDrift to a tolerance the host can realistically honor.","Run timing-sensitive replays on an idle machine (no CI neighbors, power saving disabled).","If exact timing is not the measurement goal, set Limits.RequireGroundedTiming = false.","Use a slower TimeScale (larger gaps) so scheduling jitter is proportionally smaller than the tolerance."],"exampleFix":"// before\nlimits := cachebench.ReplayLimits{RequireGroundedTiming: true, MaxScheduleDrift: time.Millisecond}\n\n// after\nlimits := cachebench.ReplayLimits{RequireGroundedTiming: true, MaxScheduleDrift: 50 * time.Millisecond}","handlingStrategy":"validation","validationCode":"// calibrate before the run: assert tolerance comfortably exceeds observed scheduler jitter\nif limits.RequireGroundedTiming && limits.MaxScheduleDrift < 10*time.Millisecond {\n    return errors.New(\"drift tolerance too strict for this host; raise MaxScheduleDrift\")\n}","typeGuard":"func isScheduleDrift(err error) bool {\n    var rre *cachebench.ReplayRunError\n    return errors.As(err, &rre) && rre.FailureCode == \"schedule_drift\"\n}","tryCatchPattern":"if err := runner.Run(ctx, records, emit); err != nil {\n    if isScheduleDrift(err) {\n        // evidence was emitted for the failed request; widen MaxScheduleDrift and re-run\n    }\n    return err\n}","preventionTips":["Calibrate MaxScheduleDrift against a pilot run on the target host.","Avoid timing-grounded replays on shared CI machines; use a dedicated host.","Keep sequential replay host idle (no builds, backups) during the run."],"tags":["cachebench","timing","scheduling","replay"],"backgroundTag":null,"analyzedSha":"27d5a3981a347890211bb1bf2439e5c821a63bc9","analyzedAt":"2026-08-15T09:26:11.751Z","schemaVersion":2},"datasetVersion":"2026-08-15T22:17:37.221Z"}