Skip to content

Commit 8d3e8a9

Browse files
authored
🐛 [RUM Profiler] Fix long tasks query using wrong clock for duration computation (#4227)
Co-authored-by: thomas.bertet <thomas.bertet@datadoghq.com>
1 parent b3a077d commit 8d3e8a9

2 files changed

Lines changed: 53 additions & 1 deletion

File tree

packages/rum/src/domain/profiling/profiler.spec.ts

Lines changed: 52 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -860,6 +860,58 @@ describe('profiler', () => {
860860
expect(profilingContextManager.get()?.status).toBe('stopped')
861861
})
862862

863+
it('should not include long tasks outside the profiling window when clocks drift', async () => {
864+
const clock = mockClock()
865+
const timeOrigin = performance.timing.navigationStart
866+
const { profiler, addLongTask } = setupProfiler()
867+
868+
profiler.start()
869+
expect(profiler.isRunning()).toBe(true)
870+
871+
// Add a long task at T=100ms (inside the profile window)
872+
clock.tick(100)
873+
addLongTask({
874+
id: 'long-task-inside',
875+
startClocks: clocksNow(),
876+
duration: 50 as Duration,
877+
entryType: RumPerformanceEntryType.LONG_ANIMATION_FRAME,
878+
})
879+
880+
// Add a long task at T=1000ms (outside the actual profile relative window)
881+
clock.tick(900)
882+
addLongTask({
883+
id: 'long-task-outside',
884+
startClocks: clocksNow(),
885+
duration: 50 as Duration,
886+
entryType: RumPerformanceEntryType.LONG_ANIMATION_FRAME,
887+
})
888+
889+
// Advance to T=1100ms
890+
clock.tick(100)
891+
892+
// Simulate clock drift: Date.now() drifted 1000ms ahead of performance.now()
893+
// This mimics NTP sync or system clock adjustments in production
894+
;(performance.now as jasmine.Spy).and.callFake(() => Date.now() - timeOrigin - 1000)
895+
896+
// Stop profiler — state changes synchronously, data collection is async via Promise
897+
profiler.stop()
898+
expect(profiler.isStopped()).toBe(true)
899+
900+
// Flush microtasks for profiler.stop() Promise and transport.send()
901+
await waitNextMicrotask()
902+
await waitNextMicrotask()
903+
904+
expect(interceptor.requests.length).toBe(1)
905+
const request = await readFormDataRequest<ProfileEventPayload>(interceptor.requests[0])
906+
const trace = request['wall-time.json']
907+
908+
// Should only include the long task that occurred during the actual profiling window.
909+
// Without the fix (using timeStamp for duration), both long tasks would be included
910+
// because the inflated timeStamp-based duration extends the query window.
911+
expect(trace.longTasks.length).toBe(1)
912+
expect(trace.longTasks[0].id).toBe('long-task-inside')
913+
})
914+
863915
it('should restart profiling when session expires while paused and then renews', async () => {
864916
const { profiler, profilingContextManager } = setupProfiler()
865917

packages/rum/src/domain/profiling/profiler.ts

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -234,7 +234,7 @@ export function createRumProfiler(
234234
.stop()
235235
.then((trace) => {
236236
const endClocks = clocksNow()
237-
const duration = elapsed(startClocks.timeStamp, endClocks.timeStamp)
237+
const duration = elapsed(startClocks.relative, endClocks.relative)
238238
const longTasks = longTaskHistory.findAll(startClocks.relative, duration)
239239
const actions = actionHistory.findAll(startClocks.relative, duration)
240240
const vitals = vitalHistory.findAll(startClocks.relative, duration)

0 commit comments

Comments
 (0)