feat(profiling): tag profiles with operation's start vital's id

Author: MandragoreVR

packages/core/src/tools/valueHistory.ts

@@ -26,6 +26,7 @@ export interface ValueHistory<Value> {
 
   closeActive: (endTime: RelativeTime) => void
   findAll: (startTime?: RelativeTime, duration?: Duration) => Value[]
+  findAllEntries: (startTime?: RelativeTime, duration?: Duration) => Array<ValueHistoryEntry<Value>>
   getEntries: (startTime: RelativeTime) => Array<ValueHistoryEntry<Value>>
   reset: () => void
   stop: () => void
@@ -130,6 +131,19 @@ export function createValueHistory<Value>({
       .map((entry) => entry.value)
   }
 
+  /**
+   * Return all entries with an active period overlapping with the duration,
+   * or all entries that were active during `startTime` if no duration is provided,
+   * or all currently active entries if no `startTime` is provided.
+   */
+  function findAllEntries(
+    startTime: RelativeTime = END_OF_TIMES,
+    duration = 0 as Duration
+  ): Array<ValueHistoryEntry<Value>> {
+    const endTime = addDuration(startTime, duration)
+    return entries.filter((entry) => entry.startTime <= endTime && startTime <= entry.endTime)
+  }
+
   /**
    * Return all the entries whose start time is equal to the given startTime.
    */
@@ -155,7 +169,7 @@ export function createValueHistory<Value>({
     }
   }
 
-  return { add, find, closeActive, findAll, getEntries, reset, stop }
+  return { add, find, closeActive, findAll, findAllEntries, getEntries, reset, stop }
 }
 
 /**

packages/rum-core/src/domain/lifeCycle.ts

@@ -46,7 +46,7 @@ export const enum LifeCycleEventType {
   RUM_EVENT_COLLECTED,
   RAW_ERROR_COLLECTED,
   ACTION_STARTED,
-  VITAL_STARTED,
+  DURATION_VITAL_STARTED,
 }
 
 // This is a workaround for an issue occurring when the Browser SDK is included in a TypeScript
@@ -79,7 +79,7 @@ declare const LifeCycleEventTypeAsConst: {
   RAW_RUM_EVENT_COLLECTED: LifeCycleEventType.RAW_RUM_EVENT_COLLECTED
   RUM_EVENT_COLLECTED: LifeCycleEventType.RUM_EVENT_COLLECTED
   RAW_ERROR_COLLECTED: LifeCycleEventType.RAW_ERROR_COLLECTED
-  VITAL_STARTED: LifeCycleEventType.VITAL_STARTED
+  DURATION_VITAL_STARTED: LifeCycleEventType.DURATION_VITAL_STARTED
 }
 
 // Note: this interface needs to be exported even if it is not used outside of this module, else TS
@@ -104,7 +104,7 @@ export interface LifeCycleEventMap {
     error: RawError
     customerContext?: Context
   }
-  [LifeCycleEventTypeAsConst.VITAL_STARTED]: DurationVitalStart
+  [LifeCycleEventTypeAsConst.DURATION_VITAL_STARTED]: DurationVitalStart
 }
 
 export interface RawRumEventCollectedData<E extends RawRumEvent = RawRumEvent> {

packages/rum-core/src/domain/vital/vitalCollection.spec.ts

@@ -211,7 +211,7 @@ describe('vitalCollection', () => {
 
     it('should notify lifecycle with vital started event when starting a duration vital', () => {
       const subscriberSpy = jasmine.createSpy()
-      lifeCycle.subscribe(LifeCycleEventType.VITAL_STARTED, subscriberSpy)
+      lifeCycle.subscribe(LifeCycleEventType.DURATION_VITAL_STARTED, subscriberSpy)
 
       vitalCollection.startDurationVital('foo')
 

packages/rum-core/src/domain/vital/vitalCollection.ts

@@ -142,7 +142,7 @@ export function startVitalCollection(lifeCycle: LifeCycle, pageStateHistory: Pag
       name,
       ...options,
     })
-    lifeCycle.notify(LifeCycleEventType.VITAL_STARTED, { id, name, startClocks, ...options })
+    lifeCycle.notify(LifeCycleEventType.DURATION_VITAL_STARTED, { id, name, startClocks, ...options })
   }
 
   function stopDurationVital(name: string, options: DurationVitalOptions = {}, stopClocks = clocksNow()) {

packages/rum-core/src/index.ts

@@ -23,7 +23,7 @@ export type {
   RumVitalEventDomainContext,
 } from './domainContext.types'
 export type { ReplayStats, RawRumActionEvent, RawRumEvent } from './rawRumEvent.types'
-export { ActionType, RumEventType, FrustrationType, RumLongTaskEntryType } from './rawRumEvent.types'
+export { ActionType, RumEventType, FrustrationType, RumLongTaskEntryType, VitalType } from './rawRumEvent.types'
 export { startRum } from './boot/startRum'
 export type { RawRumEventCollectedData } from './domain/lifeCycle'
 export { LifeCycle, LifeCycleEventType } from './domain/lifeCycle'

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

@@ -229,7 +229,12 @@ export function createRumProfiler(
         const duration = elapsed(startClocks.relative, endClocks.relative)
         const longTasks = longTaskHistory.findAll(startClocks.relative, duration)
         const actions = actionHistory.findAll(startClocks.relative, duration)
-        const vitals = vitalHistory.findAll(startClocks.relative, duration)
+        const vitals = vitalHistory.findAll(startClocks.relative, duration).map((vital) => ({
+          id: vital.id,
+          label: vital.label,
+          startClocks: vital.startClocks,
+          duration: vital.duration,
+        }))
         const isBelowDurationThreshold = duration < profilerConfiguration.minProfileDurationMs
 
         if (longTasks.length === 0 && isBelowDurationThreshold) {

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

@@ -1,5 +1,11 @@
 import type { ViewHistoryEntry } from '@datadog/browser-rum-core'
-import { LifeCycle, LifeCycleEventType, RumPerformanceEntryType, createHooks } from '@datadog/browser-rum-core'
+import {
+  LifeCycle,
+  LifeCycleEventType,
+  RumPerformanceEntryType,
+  VitalType,
+  createHooks,
+} from '@datadog/browser-rum-core'
 import type { Duration, SessionRenewalEvent } from '@datadog/browser-core'
 import {
   addDuration,
@@ -8,6 +14,7 @@ import {
   createIdentityEncoder,
   createValueHistory,
   deepClone,
+  elapsed,
   ONE_DAY,
   relativeNow,
   timeStampNow,
@@ -141,6 +148,18 @@ describe('profiler', () => {
       addVital: (vital: VitalContext) => {
         vitalHistory.add(vital, relativeNow()).close(addDuration(relativeNow(), vital.duration ?? (0 as Duration)))
       },
+      startOperationStep: (id: string, label: string, operationKey?: string) => {
+        const startClocks = clocksNow()
+        const entry = vitalHistory.add(
+          { id, type: VitalType.OPERATION_STEP, label, operationKey, startClocks, duration: undefined },
+          startClocks.relative
+        )
+        return () => {
+          const endTime = relativeNow()
+          entry.value.duration = elapsed(entry.startTime, endTime)
+          entry.close(endTime)
+        }
+      },
     }
   }
 
@@ -415,6 +434,7 @@ describe('profiler', () => {
     expect(profilingContextManager.get()?.status).toBe('running')
     addVital({
       id: 'vital-id-1',
+      type: VitalType.DURATION,
       label: 'vital-label-1',
       startClocks: clocksNow(),
       duration: 50 as Duration,
@@ -423,6 +443,7 @@ describe('profiler', () => {
 
     addVital({
       id: 'vital-id-2',
+      type: VitalType.DURATION,
       label: 'vital-label-2',
       startClocks: clocksNow(),
       duration: 100 as Duration,
@@ -442,6 +463,7 @@ describe('profiler', () => {
 
     addVital({
       id: 'vital-id-3',
+      type: VitalType.DURATION,
       label: 'vital-label-3',
       startClocks: clocksNow(),
       duration: 100 as Duration,
@@ -495,6 +517,79 @@ describe('profiler', () => {
     ])
   })
 
+  it('should collect all ongoing operations during a profiling session', async () => {
+    const clock = mockClock()
+    const { profiler, startOperationStep } = setupProfiler()
+
+    // Profile 1: start all three operations, end op1
+    profiler.start()
+    await waitForBoolean(() => profiler.isRunning())
+
+    const endOp1 = startOperationStep('op-id-1', 'op-label-1')
+    clock.tick(10)
+    const endOp2 = startOperationStep('op-id-2', 'op-label-2')
+    clock.tick(10)
+    const endOp3 = startOperationStep('op-id-3', 'op-label-3')
+    clock.tick(10)
+    endOp1() // op1 ends during profile 1
+
+    clock.tick(70)
+    profiler.stop()
+    await waitNextMicrotask()
+
+    // Profile 2: end op2
+    profiler.start()
+    await waitForBoolean(() => profiler.isRunning())
+
+    clock.tick(50)
+    endOp2() // op2 ends during profile 2
+
+    clock.tick(50)
+    profiler.stop()
+    await waitNextMicrotask()
+
+    // Profile 3: end op3
+    profiler.start()
+    await waitForBoolean(() => profiler.isRunning())
+
+    clock.tick(50)
+    endOp3() // op3 ends during profile 3
+
+    clock.tick(50)
+    profiler.stop()
+    await waitNextMicrotask()
+    await waitNextMicrotask()
+
+    expect(interceptor.requests.length).toBe(3)
+
+    const req1 = await readFormDataRequest<ProfileEventPayload>(interceptor.requests[0])
+    const req2 = await readFormDataRequest<ProfileEventPayload>(interceptor.requests[1])
+    const req3 = await readFormDataRequest<ProfileEventPayload>(interceptor.requests[2])
+
+    const vitals1 = req1['wall-time.json'].vitals
+    const vitals2 = req2['wall-time.json'].vitals
+    const vitals3 = req3['wall-time.json'].vitals
+
+    // Profile 1: all three operations present, only op1 has a duration
+    expect(vitals1?.map((v) => v.id)).toEqual(jasmine.arrayContaining(['op-id-1', 'op-id-2', 'op-id-3']))
+    expect(vitals1?.find((v) => v.id === 'op-id-1')?.duration).toBe(30 as Duration)
+    expect(vitals1?.find((v) => v.id === 'op-id-2')?.duration).toBeUndefined()
+    expect(vitals1?.find((v) => v.id === 'op-id-3')?.duration).toBeUndefined()
+
+    // Profile 2: op1 is gone (ended before profile 2 started), op2 and op3 present, only op2 has a duration
+    expect(vitals2?.map((v) => v.id)).not.toContain('op-id-1')
+    expect(vitals2?.map((v) => v.id)).toEqual(jasmine.arrayContaining(['op-id-2', 'op-id-3']))
+    expect(vitals2?.find((v) => v.id === 'op-id-2')?.duration).toBe(140 as Duration)
+    expect(vitals2?.find((v) => v.id === 'op-id-3')?.duration).toBeUndefined()
+
+    // Profile 3: only op3 remains, with a duration
+    expect(vitals3?.map((v) => v.id)).not.toContain('op-id-1')
+    expect(vitals3?.map((v) => v.id)).not.toContain('op-id-2')
+    expect(vitals3?.length).toBe(1)
+    expect(vitals3?.[0].id).toBe('op-id-3')
+    expect(vitals3?.[0].duration).toBe(230 as Duration)
+  })
+
   it('should collect views and set default view name in the Profile', async () => {
     const initialViewEntry = {
       id: 'view-user',