Skip to content

[RUM Profiler] Use clocks for start/end time #3510

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.

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
merged 6 commits into from
May 5, 2025
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
36 changes: 22 additions & 14 deletions packages/rum/src/domain/profiling/profiler.ts
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
import type { Duration, RelativeTime } from '@datadog/browser-core'
import {
addEventListener,
clearTimeout,
Expand All @@ -6,6 +7,10 @@ import {
monitorError,
display,
getGlobalObject,
relativeToClocks,
clocksOrigin,
clocksNow,
elapsed,
} from '@datadog/browser-core'

import type { LifeCycle, RumConfiguration, RumSessionManager, ViewHistoryEntry } from '@datadog/browser-rum-core'
Expand Down Expand Up @@ -58,7 +63,7 @@ export function createRumProfiler(
// Add initial view
// Note: `viewEntry.name` is only filled when users use manual view creation via `startView` method.
lastViewEntry = viewEntry
? { startTime: viewEntry.startClocks.relative, viewId: viewEntry.id, viewName: viewEntry.name }
? { startClocks: viewEntry.startClocks, viewId: viewEntry.id, viewName: viewEntry.name }
: undefined

// Add global clean-up tasks for listeners that are not specific to a profiler instance (eg. visibility change, before unload)
Expand Down Expand Up @@ -122,7 +127,7 @@ export function createRumProfiler(
// Whenever the View is updated, we add a views entry to the profiler instance.
const viewUpdatedSubscription = lifeCycle.subscribe(LifeCycleEventType.VIEW_CREATED, (view) => {
// Note: `view.name` is only filled when users use manual view creation via `startView` method.
collectViewEntry({ viewId: view.id, viewName: view.name, startTime: view.startClocks.relative })
collectViewEntry({ viewId: view.id, viewName: view.name, startClocks: view.startClocks })
})
cleanupTasks.push(viewUpdatedSubscription.unsubscribe)

Expand Down Expand Up @@ -168,7 +173,7 @@ export function createRumProfiler(
// Kick-off the new instance
instance = {
state: 'running',
startTime: performance.now(),
startClocks: clocksNow(),
profiler,
timeoutId: setTimeout(startNextProfilerInstance, profilerConfiguration.collectIntervalMs),
longTasks: [],
Expand Down Expand Up @@ -197,19 +202,20 @@ export function createRumProfiler(
lastInstance.profiler.removeEventListener('samplebufferfull', handleSampleBufferFull)

// Store instance data snapshot in local variables to use in async callback
const { startTime, longTasks, views } = lastInstance
const { startClocks, longTasks, views } = lastInstance

// Capturing when we stop the profiler so we use this time as a reference to clean-up long task registry, eg. remove the long tasks that we collected already
const collectTime = performance.now()
const collectClocks = clocksNow()

// Stop current profiler to get trace
await lastInstance.profiler
.stop()
.then((trace) => {
const endTime = performance.now()
const endClocks = clocksNow()

const hasLongTasks = longTasks.length > 0
const isBelowDurationThreshold = endTime - startTime < profilerConfiguration.minProfileDurationMs
const isBelowDurationThreshold =
elapsed(startClocks.timeStamp, endClocks.timeStamp) < profilerConfiguration.minProfileDurationMs
const isBelowSampleThreshold = getNumberOfSamples(trace.samples) < profilerConfiguration.minNumberOfSamples

if (!hasLongTasks && (isBelowDurationThreshold || isBelowSampleThreshold)) {
Expand All @@ -220,17 +226,17 @@ export function createRumProfiler(
handleProfilerTrace(
// Enrich trace with time and instance data
Object.assign(trace, {
startTime,
endTime,
timeOrigin: performance.timeOrigin,
startClocks,
endClocks,
clocksOrigin: clocksOrigin(),
longTasks,
views,
sampleInterval: profilerConfiguration.sampleIntervalMs,
})
)

// Clear long task registry, remove entries that we collected already (eg. avoid slowly growing memory usage by keeping outdated entries)
deleteLongTaskIdsBefore(collectTime)
deleteLongTaskIdsBefore(collectClocks)
})
.catch(monitorError)
}
Expand Down Expand Up @@ -286,12 +292,14 @@ export function createRumProfiler(
continue
}

const startClocks = relativeToClocks(entry.startTime as RelativeTime)

// Store Long Task entry, which is a lightweight version of the PerformanceEntry
instance.longTasks.push({
id: getLongTaskId(entry),
duration: entry.duration,
id: getLongTaskId(startClocks.relative),
duration: entry.duration as Duration,
entryType: entry.entryType,
startTime: entry.startTime,
startClocks,
})
}
}
Expand Down
4 changes: 2 additions & 2 deletions packages/rum/src/domain/profiling/profilingCorrelation.ts
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
import type { RawRumEvent } from '@datadog/browser-rum-core'
import { RumEventType } from '@datadog/browser-rum-core'

import type { RelativeTime } from '@datadog/browser-core'
import { setLongTaskId } from './utils/longTaskRegistry'

/**
Expand All @@ -14,7 +14,7 @@ export function mayStoreLongTaskIdForProfilerCorrelation({
startTime,
}: {
rawRumEvent: RawRumEvent
startTime: number
startTime: RelativeTime
}) {
if (rawRumEvent.type !== RumEventType.LONG_TASK) {
return
Expand Down
17 changes: 10 additions & 7 deletions packages/rum/src/domain/profiling/transport/transport.ts
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
import { addTelemetryDebug, type EndpointBuilder, type Payload } from '@datadog/browser-core'
import { addTelemetryDebug, currentDrift, type EndpointBuilder, type Payload } from '@datadog/browser-core'
import type { RumProfilerTrace } from '../types'
import { getLongTaskId } from '../utils/longTaskRegistry'

Expand All @@ -17,6 +17,9 @@ interface ProfileEvent extends ProfileEventAttributes {
format: 'json'
version: 4
tags_profiler: string
_dd: {
clock_drift: number
}
}

type SendProfileFunction = (
Expand Down Expand Up @@ -55,19 +58,19 @@ function buildProfileEvent(
const profileAttributes = buildProfileEventAttributes(profilerTrace, applicationId, sessionId)
const profileEventTags = buildProfileEventTags(tags)

const start = new Date(profilerTrace.timeOrigin + profilerTrace.startTime)
const end = new Date(profilerTrace.timeOrigin + profilerTrace.endTime)

const profileEvent: ProfileEvent = {
...profileAttributes,
attachments: ['wall-time.json'],
start: start.toISOString(),
end: end.toISOString(),
start: new Date(profilerTrace.startClocks.timeStamp).toISOString(),
end: new Date(profilerTrace.endClocks.timeStamp).toISOString(),
family: 'chrome',
runtime: 'chrome',
format: 'json',
version: 4, // Ingestion event version (not the version application tag)
tags_profiler: profileEventTags.join(','),
_dd: {
clock_drift: currentDrift(),
},
}

return profileEvent
Expand Down Expand Up @@ -132,7 +135,7 @@ function buildProfileEventAttributes(
}
}
const longTaskIds: string[] = profilerTrace.longTasks
.map((longTask) => getLongTaskId(longTask))
.map((longTask) => getLongTaskId(longTask.startClocks.relative))
.filter((id) => id !== undefined)

if (longTaskIds.length) {
Expand Down
16 changes: 8 additions & 8 deletions packages/rum/src/domain/profiling/types/rumProfiler.types.ts
Original file line number Diff line number Diff line change
@@ -1,10 +1,10 @@
import type { TimeoutId } from '@datadog/browser-core'
import type { TimeoutId, ClocksState, Duration } from '@datadog/browser-core'
import type { ViewHistoryEntry } from '@datadog/browser-rum-core'
import type { ProfilerTrace, Profiler } from './profilerApi.types'

export interface RumViewEntry {
/** Detected start time of view */
readonly startTime: DOMHighResTimeStamp
readonly startClocks: ClocksState
/** RUM view id */
readonly viewId: string
/** RUM view name */
Expand All @@ -15,11 +15,11 @@ export interface RUMProfilerLongTaskEntry {
/** RUM Long Task id */
readonly id: string | undefined
/** RUM Long Task duration */
readonly duration: number
readonly duration: Duration
/** RUM Long Task entry type */
readonly entryType: string
/** RUM Long Task start time */
readonly startTime: DOMHighResTimeStamp
readonly startClocks: ClocksState
}

/**
Expand All @@ -34,11 +34,11 @@ export interface RumProfilerEnrichmentData {

export interface RumProfilerTrace extends ProfilerTrace, RumProfilerEnrichmentData {
/** High resolution time when profiler trace started, relative to the profiling session's time origin */
readonly startTime: DOMHighResTimeStamp
readonly startClocks: ClocksState
/** High resolution time when profiler trace ended, relative to the profiling session's time origin */
readonly endTime: DOMHighResTimeStamp
readonly endClocks: ClocksState
/** Time origin of the profiling session */
readonly timeOrigin: number
readonly clocksOrigin: ClocksState
/** Sample interval in milliseconds */
readonly sampleInterval: number
}
Expand Down Expand Up @@ -66,7 +66,7 @@ export interface RumProfilerRunningInstance extends RumProfilerEnrichmentData {
/** Current profiler instance */
readonly profiler: Profiler
/** High resolution time when profiler session started */
readonly startTime: DOMHighResTimeStamp
readonly startClocks: ClocksState
/** Timeout id to stop current session */
readonly timeoutId: TimeoutId
/** Clean-up tasks to execute after running the Profiler */
Expand Down
29 changes: 16 additions & 13 deletions packages/rum/src/domain/profiling/utils/longTaskRegistry.ts
Original file line number Diff line number Diff line change
@@ -1,45 +1,48 @@
type PerformanceEntryStartTimeMs = number
import type { ClocksState, RelativeTime } from '@datadog/browser-core'
import { clocksNow } from '@datadog/browser-core'

type PerformanceEntryStartTime = RelativeTime

// Maps PerformanceEntry start-time to the corresponding long task id (from RUM LongTaskEvent),
// We need this to link RUM Long Tasks with RUM Profiler stack traces
// Given that long task takes at least 50ms and we export profile at least every 60 seconds, we can have up to 1200 entries (60s / 50ms = 1200).
const registry = new Map<PerformanceEntryStartTimeMs, string>()
const registry = new Map<PerformanceEntryStartTime, string>()

// Enable Long Task Registry only if RUM Profiler has been activated
let enabledTime: false | number = false
let enabledClocks: false | ClocksState = false

export function enableLongTaskRegistry() {
enabledTime = performance.now()
enabledClocks = clocksNow()
}

export function disableLongTaskRegistry() {
enabledTime = false
enabledClocks = false
registry.clear() // Free-up the memory
}

/**
* Store the long task ID in the registry for the Profiler to link it with the corresponding Profile.
*/
export function setLongTaskId(longTaskId: string, performanceEntryStartTime: number) {
registry.set(performanceEntryStartTime, longTaskId)
export function setLongTaskId(longTaskId: string, startTime: RelativeTime) {
registry.set(startTime, longTaskId)
}

export function getLongTaskId(longTaskEntry: { startTime: DOMHighResTimeStamp }): string | undefined {
export function getLongTaskId(startTime: RelativeTime): string | undefined {
// Don't return if it's not enabled or the long task has been reported before the activation
if (enabledTime === false || longTaskEntry.startTime < enabledTime) {
if (enabledClocks === false || startTime < enabledClocks.relative) {
return undefined
}

return registry.get(longTaskEntry.startTime)
return registry.get(startTime)
}

export function deleteLongTaskIdsBefore(collectionTime: number) {
if (enabledTime === false || collectionTime < enabledTime) {
export function deleteLongTaskIdsBefore(collectionClocks: ClocksState) {
if (enabledClocks === false || collectionClocks.relative < enabledClocks.relative) {
return undefined
}

for (const performanceEntryStartTime of registry.keys()) {
if (performanceEntryStartTime < collectionTime) {
if (performanceEntryStartTime < collectionClocks.relative) {
registry.delete(performanceEntryStartTime)
}
}
Expand Down