✨[PANA-3819] Add telemetry for recorder initialization (#3793)

Author: sethfowler-datadog

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

@@ -248,6 +248,7 @@ export interface RumConfiguration extends Configuration {
   subdomain?: string
   customerDataTelemetrySampleRate: number
   initialViewMetricsTelemetrySampleRate: number
+  recorderInitTelemetrySampleRate: number
   segmentTelemetrySampleRate: number
   traceContextInjection: TraceContextInjection
   plugins: RumPlugin[]
@@ -321,6 +322,7 @@ export function validateAndBuildRumConfiguration(
     enablePrivacyForActionName: !!initConfiguration.enablePrivacyForActionName,
     customerDataTelemetrySampleRate: 1,
     initialViewMetricsTelemetrySampleRate: 1,
+    recorderInitTelemetrySampleRate: 1,
     segmentTelemetrySampleRate: 1,
     traceContextInjection: objectHasValue(TraceContextInjection, initConfiguration.traceContextInjection)
       ? initConfiguration.traceContextInjection

packages/rum/src/boot/lazyLoadRecorder.spec.ts

@@ -1,5 +1,5 @@
-import type { DeflateWorker, Telemetry } from '@datadog/browser-core'
-import { display, resetTelemetry } from '@datadog/browser-core'
+import type { DeflateWorker, RawTelemetryEvent, Telemetry } from '@datadog/browser-core'
+import { display } from '@datadog/browser-core'
 import type { RecorderApi, RumSessionManager } from '@datadog/browser-rum-core'
 import { LifeCycle } from '@datadog/browser-rum-core'
 import type { MockTelemetry } from '@datadog/browser-core/test'
@@ -13,6 +13,19 @@ import { makeRecorderApi } from './recorderApi'
 import type { StartRecording } from './postStartStrategy'
 import { lazyLoadRecorder } from './lazyLoadRecorder'
 
+const RECORDER_INIT_TELEMETRY: RawTelemetryEvent = {
+  type: 'log',
+  status: 'debug',
+  message: 'Recorder init metrics',
+  metrics: {
+    forced: false,
+    loadRecorderModuleDuration: jasmine.any(Number),
+    recorderInitDuration: jasmine.any(Number),
+    result: 'recorder-load-failed',
+    waitForDocReadyDuration: jasmine.any(Number),
+  },
+}
+
 describe('lazyLoadRecorder', () => {
   let displaySpy: jasmine.Spy
   let telemetry: MockTelemetry
@@ -43,22 +56,27 @@ describe('lazyLoadRecorder', () => {
     stopRecordingSpy = jasmine.createSpy('stopRecording')
     startRecordingSpy = jasmine.createSpy('startRecording')
 
-    // Workaround because using resolveTo(startRecordingSpy) was not working
-    loadRecorderSpy = jasmine.createSpy('loadRecorder').and.resolveTo((...args: any) => {
+    loadRecorderSpy = jasmine.createSpy('loadRecorder').and.callFake((...args) => {
       if (loadRecorderError) {
         return lazyLoadRecorder(() => Promise.reject(loadRecorderError))
       }
       startRecordingSpy(...args)
-      return {
+      return Promise.resolve({
         stop: stopRecordingSpy,
-      }
+      })
+    })
+
+    const configuration = mockRumConfiguration({
+      startSessionReplayRecordingManually: startSessionReplayRecordingManually ?? false,
+      recorderInitTelemetrySampleRate: 100,
+      telemetrySampleRate: 100,
     })
 
     recorderApi = makeRecorderApi(loadRecorderSpy, createDeflateWorkerSpy)
     rumInit = ({ worker } = {}) => {
       recorderApi.onRumStart(
         lifeCycle,
-        mockRumConfiguration({ startSessionReplayRecordingManually: startSessionReplayRecordingManually ?? false }),
+        configuration,
         sessionManager ?? createRumSessionManagerMock().setId('1234'),
         mockViewHistory(),
         worker,
@@ -69,11 +87,10 @@ describe('lazyLoadRecorder', () => {
     registerCleanupTask(() => {
       resetDeflateWorkerState()
       replayStats.resetReplayStats()
-      resetTelemetry()
     })
   }
 
-  it('should report an error but no telemetry if CSP blocks the module', async () => {
+  it('should report a console error and metrics but no telemetry error if CSP blocks the module', async () => {
     const loadRecorderError = new Error('Dynamic import was blocked due to Content Security Policy')
     setupRecorderApi({
       loadRecorderError,
@@ -87,10 +104,12 @@ describe('lazyLoadRecorder', () => {
 
     expect(displaySpy).toHaveBeenCalledWith(jasmine.stringContaining('Recorder failed to start'), loadRecorderError)
     expect(displaySpy).toHaveBeenCalledWith(jasmine.stringContaining('Please make sure CSP is correctly configured'))
-    expect(await telemetry.hasEvents()).toBe(false)
+
+    // There should be no actual telemetry error, but we should see the failure in the metrics.
+    expect(await telemetry.getEvents()).toEqual([RECORDER_INIT_TELEMETRY])
   })
 
-  it('should report an error but no telemetry if importing fails for non-CSP reasons', async () => {
+  it('should report a console error and metrics but no telemetry error if importing fails for non-CSP reasons', async () => {
     const loadRecorderError = new Error('Dynamic import failed')
     setupRecorderApi({
       loadRecorderError,
@@ -103,6 +122,8 @@ describe('lazyLoadRecorder', () => {
     await wait(0)
 
     expect(displaySpy).toHaveBeenCalledWith(jasmine.stringContaining('Recorder failed to start'), loadRecorderError)
-    expect(await telemetry.hasEvents()).toBe(false)
+
+    // There should be no actual telemetry error, but we should see the failure in the metrics.
+    expect(await telemetry.getEvents()).toEqual([RECORDER_INIT_TELEMETRY])
   })
 })

packages/rum/src/boot/postStartStrategy.ts

@@ -7,9 +7,10 @@ import type {
   RumSession,
 } from '@datadog/browser-rum-core'
 import { LifeCycleEventType, SessionReplayState } from '@datadog/browser-rum-core'
-import { asyncRunOnReadyState, monitorError } from '@datadog/browser-core'
+import { asyncRunOnReadyState, monitorError, Observable } from '@datadog/browser-core'
 import type { Telemetry, DeflateEncoder } from '@datadog/browser-core'
 import { getSessionReplayLink } from '../domain/getSessionReplayLink'
+import { startRecorderInitTelemetry } from '../domain/startRecorderInitTelemetry'
 import type { startRecording } from './startRecording'
 
 export type StartRecording = typeof startRecording
@@ -26,6 +27,15 @@ export const enum RecorderStatus {
   Started,
 }
 
+export type RecorderInitEvent =
+  | { type: 'start'; forced: boolean }
+  | { type: 'document-ready' }
+  | { type: 'recorder-settled' }
+  | { type: 'aborted' }
+  | { type: 'deflate-encoder-load-failed' }
+  | { type: 'recorder-load-failed' }
+  | { type: 'succeeded' }
+
 export interface Strategy {
   start: (options?: StartRecordingOptions) => void
   stop: () => void
@@ -58,16 +68,32 @@ export function createPostStartStrategy(
     }
   })
 
-  const doStart = async () => {
-    const [startRecordingImpl] = await Promise.all([loadRecorder(), asyncRunOnReadyState(configuration, 'interactive')])
+  const observable = new Observable<RecorderInitEvent>()
+  startRecorderInitTelemetry(configuration, telemetry, observable)
+
+  const doStart = async (forced: boolean) => {
+    observable.notify({ type: 'start', forced })
+
+    const [startRecordingImpl] = await Promise.all([
+      notifyWhenSettled(observable, { type: 'recorder-settled' }, loadRecorder()),
+      notifyWhenSettled(observable, { type: 'document-ready' }, asyncRunOnReadyState(configuration, 'interactive')),
+    ])
 
     if (status !== RecorderStatus.Starting) {
+      observable.notify({ type: 'aborted' })
+      return
+    }
+
+    if (!startRecordingImpl) {
+      status = RecorderStatus.Stopped
+      observable.notify({ type: 'recorder-load-failed' })
       return
     }
 
     const deflateEncoder = getOrCreateDeflateEncoder()
-    if (!deflateEncoder || !startRecordingImpl) {
+    if (!deflateEncoder) {
       status = RecorderStatus.Stopped
+      observable.notify({ type: 'deflate-encoder-load-failed' })
       return
     }
 
@@ -81,6 +107,7 @@ export function createPostStartStrategy(
     ))
 
     status = RecorderStatus.Started
+    observable.notify({ type: 'succeeded' })
   }
 
   function start(options?: StartRecordingOptions) {
@@ -96,10 +123,12 @@ export function createPostStartStrategy(
 
     status = RecorderStatus.Starting
 
+    const forced = shouldForceReplay(session!, options) || false
+
     // Intentionally not awaiting doStart() to keep it asynchronous
-    doStart().catch(monitorError)
+    doStart(forced).catch(monitorError)
 
-    if (shouldForceReplay(session!, options)) {
+    if (forced) {
       sessionManager.setForcedReplay()
     }
   }
@@ -133,3 +162,15 @@ function isRecordingInProgress(status: RecorderStatus) {
 function shouldForceReplay(session: RumSession, options?: StartRecordingOptions) {
   return options && options.force && session.sessionReplay === SessionReplayState.OFF
 }
+
+async function notifyWhenSettled<Event, Result>(
+  observable: Observable<Event>,
+  event: Event,
+  promise: Promise<Result>
+): Promise<Result> {
+  try {
+    return await promise
+  } finally {
+    observable.notify(event)
+  }
+}

packages/rum/src/boot/recorderApi.spec.ts

@@ -1,8 +1,15 @@
-import type { DeflateEncoder, DeflateWorker, DeflateWorkerAction, Telemetry } from '@datadog/browser-core'
+import type {
+  DeflateEncoder,
+  DeflateWorker,
+  DeflateWorkerAction,
+  RawTelemetryEvent,
+  Telemetry,
+} from '@datadog/browser-core'
 import { BridgeCapability, display } from '@datadog/browser-core'
 import type { RecorderApi, RumSessionManager } from '@datadog/browser-rum-core'
 import { LifeCycle, LifeCycleEventType } from '@datadog/browser-rum-core'
-import { collectAsyncCalls, mockEventBridge, registerCleanupTask } from '@datadog/browser-core/test'
+import type { MockTelemetry } from '@datadog/browser-core/test'
+import { collectAsyncCalls, mockEventBridge, registerCleanupTask, startMockTelemetry } from '@datadog/browser-core/test'
 import type { RumSessionManagerMock } from '../../../rum-core/test'
 import {
   createRumSessionManagerMock,
@@ -14,6 +21,7 @@ import type { CreateDeflateWorker } from '../domain/deflate'
 import { MockWorker } from '../../test'
 import { resetDeflateWorkerState } from '../domain/deflate'
 import * as replayStats from '../domain/replayStats'
+import type { RecorderInitMetrics } from '../domain/startRecorderInitTelemetry'
 import { makeRecorderApi } from './recorderApi'
 import type { StartRecording } from './postStartStrategy'
 
@@ -26,12 +34,13 @@ describe('makeRecorderApi', () => {
   let mockWorker: MockWorker
   let createDeflateWorkerSpy: jasmine.Spy<CreateDeflateWorker>
   let rumInit: (options?: { worker?: DeflateWorker }) => void
+  let telemetry: MockTelemetry
 
   function setupRecorderApi({
     sessionManager,
     startSessionReplayRecordingManually,
   }: { sessionManager?: RumSessionManager; startSessionReplayRecordingManually?: boolean } = {}) {
-    const mockTelemetry = { enabled: true } as Telemetry
+    telemetry = startMockTelemetry()
     mockWorker = new MockWorker()
     createDeflateWorkerSpy = jasmine.createSpy('createDeflateWorkerSpy').and.callFake(() => mockWorker)
     spyOn(display, 'error')
@@ -48,15 +57,21 @@ describe('makeRecorderApi', () => {
       }
     })
 
+    const configuration = mockRumConfiguration({
+      startSessionReplayRecordingManually: startSessionReplayRecordingManually ?? false,
+      recorderInitTelemetrySampleRate: 100,
+      telemetrySampleRate: 100,
+    })
+
     recorderApi = makeRecorderApi(loadRecorderSpy, createDeflateWorkerSpy)
     rumInit = ({ worker } = {}) => {
       recorderApi.onRumStart(
         lifeCycle,
-        mockRumConfiguration({ startSessionReplayRecordingManually: startSessionReplayRecordingManually ?? false }),
+        configuration,
         sessionManager ?? createRumSessionManagerMock().setId('1234'),
         mockViewHistory(),
         worker,
-        mockTelemetry
+        { enabled: true } as Telemetry
       )
     }
 
@@ -72,9 +87,11 @@ describe('makeRecorderApi', () => {
         setupRecorderApi()
         expect(loadRecorderSpy).not.toHaveBeenCalled()
         expect(startRecordingSpy).not.toHaveBeenCalled()
+        expect(await telemetry.hasEvents()).toEqual(false)
         rumInit()
         await collectAsyncCalls(startRecordingSpy, 1)
         expect(startRecordingSpy).toHaveBeenCalled()
+        expect(await telemetry.getEvents()).toEqual([expectedRecorderInitTelemetry()])
       })
 
       it('starts recording after the DOM is loaded', async () => {
@@ -84,32 +101,39 @@ describe('makeRecorderApi', () => {
 
         expect(loadRecorderSpy).toHaveBeenCalled()
         expect(startRecordingSpy).not.toHaveBeenCalled()
+        expect(await telemetry.hasEvents()).toEqual(false)
+
         triggerOnDomLoaded()
         await collectAsyncCalls(startRecordingSpy, 1)
 
         expect(startRecordingSpy).toHaveBeenCalled()
+        expect(await telemetry.getEvents()).toEqual([expectedRecorderInitTelemetry()])
       })
     })
 
     describe('with manual start', () => {
-      it('does not start recording when init() is called', () => {
+      it('does not start recording when init() is called', async () => {
         setupRecorderApi({ startSessionReplayRecordingManually: true })
         expect(loadRecorderSpy).not.toHaveBeenCalled()
         expect(startRecordingSpy).not.toHaveBeenCalled()
+        expect(await telemetry.hasEvents()).toEqual(false)
         rumInit()
         expect(loadRecorderSpy).not.toHaveBeenCalled()
         expect(startRecordingSpy).not.toHaveBeenCalled()
+        expect(await telemetry.hasEvents()).toEqual(false)
       })
 
-      it('does not start recording after the DOM is loaded', () => {
+      it('does not start recording after the DOM is loaded', async () => {
         setupRecorderApi({ startSessionReplayRecordingManually: true })
         const { triggerOnDomLoaded } = mockDocumentReadyState()
         rumInit()
         expect(loadRecorderSpy).not.toHaveBeenCalled()
         expect(startRecordingSpy).not.toHaveBeenCalled()
+        expect(await telemetry.hasEvents()).toEqual(false)
         triggerOnDomLoaded()
         expect(loadRecorderSpy).not.toHaveBeenCalled()
         expect(startRecordingSpy).not.toHaveBeenCalled()
+        expect(await telemetry.hasEvents()).toEqual(false)
       })
     })
   })
@@ -178,6 +202,7 @@ describe('makeRecorderApi', () => {
 
       expect(startRecordingSpy).toHaveBeenCalledTimes(1)
       expect(setForcedReplaySpy).toHaveBeenCalledTimes(1)
+      expect(await telemetry.getEvents()).toEqual([expectedRecorderInitTelemetry({ forced: true })])
     })
 
     it('uses the previously created worker if available', async () => {
@@ -201,6 +226,13 @@ describe('makeRecorderApi', () => {
       await collectAsyncCalls(createDeflateWorkerSpy, 1)
 
       expect(startRecordingSpy).not.toHaveBeenCalled()
+      const events = await telemetry.getEvents()
+      expect(events).toEqual([
+        jasmine.objectContaining({
+          error: jasmine.anything(),
+        }),
+        expectedRecorderInitTelemetry({ result: 'deflate-encoder-load-failed' }),
+      ])
     })
 
     it('stops recording if worker initialization fails', async () => {
@@ -630,3 +662,19 @@ describe('makeRecorderApi', () => {
     })
   })
 })
+
+function expectedRecorderInitTelemetry(overrides: Partial<RecorderInitMetrics> = {}): RawTelemetryEvent {
+  return {
+    type: 'log',
+    status: 'debug',
+    message: 'Recorder init metrics',
+    metrics: {
+      forced: false,
+      loadRecorderModuleDuration: jasmine.any(Number),
+      recorderInitDuration: jasmine.any(Number),
+      result: 'succeeded',
+      waitForDocReadyDuration: jasmine.any(Number),
+      ...overrides,
+    },
+  }
+}