fix: session recording performance metrics (#20230)

frontend/src/lib/utils/eventUsageLogic.ts

@@ -841,16 +841,16 @@ export const eventUsageLogic = kea<eventUsageLogicType>([
             // @ts-expect-error
             const eventIndex = new EventIndex(playerData?.snapshots || [])
             const payload: Partial<RecordingViewedProps> = {
-                snapshots_load_time: durations.snapshots?.duration,
-                metadata_load_time: durations.metadata?.duration,
-                events_load_time: durations.events?.duration,
-                first_paint_load_time: durations.firstPaint?.duration,
+                snapshots_load_time: durations.snapshots,
+                metadata_load_time: durations.metadata,
+                events_load_time: durations.events,
+                first_paint_load_time: durations.firstPaint,
                 duration: eventIndex.getDuration(),
                 start_time: playerData.start?.valueOf() ?? 0,
                 end_time: playerData.end?.valueOf() ?? 0,
                 page_change_events_length: eventIndex.pageChangeEvents().length,
                 recording_width: eventIndex.getRecordingScreenMetadata(0)[0]?.width,
-                load_time: durations.firstPaint?.duration ?? 0, // TODO: DEPRECATED field. Keep around so dashboards don't break
+                load_time: durations.firstPaint ?? 0, // TODO: DEPRECATED field. Keep around so dashboards don't break
             }
             posthog.capture(`recording ${type}`, payload)
         },

frontend/src/scenes/session-recordings/player/sessionRecordingDataLogic.test.ts

@@ -117,7 +117,11 @@ describe('sessionRecordingDataLogic', () => {
                 logic.actions.loadRecordingMeta()
                 logic.actions.loadRecordingSnapshots()
             })
-                .toDispatchActions(['loadRecordingMetaSuccess', 'loadRecordingSnapshotsSuccess'])
+                .toDispatchActions([
+                    'loadRecordingMetaSuccess',
+                    'loadRecordingSnapshotsSuccess',
+                    'reportUsageIfFullyLoaded',
+                ])
                 .toFinishAllListeners()
 
             const actual = logic.values.sessionPlayerData
@@ -248,7 +252,7 @@ describe('sessionRecordingDataLogic', () => {
     })
 
     describe('report usage', () => {
-        it('send `recording loaded` event only when entire recording has loaded', async () => {
+        it('sends `recording loaded` event only when entire recording has loaded', async () => {
             await expectLogic(logic, () => {
                 logic.actions.loadRecordingSnapshots()
             })
@@ -260,7 +264,7 @@ describe('sessionRecordingDataLogic', () => {
                 ])
                 .toDispatchActions([eventUsageLogic.actionTypes.reportRecording])
         })
-        it('send `recording viewed` and `recording analyzed` event on first contentful paint', async () => {
+        it('sends `recording viewed` and `recording analyzed` event on first contentful paint', async () => {
             await expectLogic(logic, () => {
                 logic.actions.loadRecordingSnapshots()
             })
@@ -271,6 +275,20 @@ describe('sessionRecordingDataLogic', () => {
                     eventUsageLogic.actionTypes.reportRecording, // analyzed
                 ])
         })
+        it('clears the cache after unmounting', async () => {
+            await expectLogic(logic, () => {
+                logic.actions.loadRecordingSnapshots()
+            })
+            expect(Object.keys(logic.cache)).toEqual(
+                expect.arrayContaining(['metaStartTime', 'snapshotsStartTime', 'eventsStartTime'])
+            )
+            expect(typeof logic.cache.metaStartTime).toBe('number')
+
+            logic.unmount()
+            expect(logic.cache.metaStartTime).toBeNull()
+            expect(logic.cache.snapshotsStartTime).toBeNull()
+            expect(logic.cache.eventsStartTime).toBeNull()
+        })
     })
 
     describe('prepareRecordingSnapshots', () => {
@@ -345,13 +363,13 @@ describe('sessionRecordingDataLogic', () => {
                     action.type === logic.actionTypes.loadRecordingSnapshots &&
                     action.payload.source?.source === 'blob',
                 'loadRecordingSnapshotsSuccess',
-                // the response to that triggers loading of the second item which is the realtime source
+                // and then we report having viewed the recording
+                'reportViewed',
+                // the response to the success action triggers loading of the second item which is the realtime source
                 (action) =>
                     action.type === logic.actionTypes.loadRecordingSnapshots &&
                     action.payload.source?.source === 'realtime',
                 'loadRecordingSnapshotsSuccess',
-                // and then we report having viewed the recording
-                'reportViewed',
                 // having loaded any real time data we start polling to check for more
                 'startRealTimePolling',
             ])

frontend/src/scenes/session-recordings/player/sessionRecordingDataLogic.ts

@@ -3,6 +3,7 @@ import { EventType, eventWithTime } from '@rrweb/types'
 import { captureException } from '@sentry/react'
 import {
     actions,
+    beforeUnmount,
     BreakPointFunction,
     connect,
     defaults,
@@ -148,28 +149,25 @@ export const prepareRecordingSnapshots = (
         .sort((a, b) => a.timestamp - b.timestamp)
 }
 
-const generateRecordingReportDurations = (
-    cache: Record<string, any>,
-    values: Record<string, any>
-): RecordingReportLoadTimes => {
-    // TODO: This any typing is super hard to manage - we should either type it or move it to a selector.
+const generateRecordingReportDurations = (cache: Record<string, any>): RecordingReportLoadTimes => {
     return {
-        metadata: {
-            size: values.segments.length,
-            duration: Math.round(performance.now() - cache.metaStartTime),
-        },
-        snapshots: {
-            size: (values.sessionPlayerSnapshotData?.segments ?? []).length,
-            duration: Math.round(performance.now() - cache.snapshotsStartTime),
-        },
-        events: {
-            size: values.sessionEventsData?.length ?? 0,
-            duration: Math.round(performance.now() - cache.eventsStartTime),
-        },
-        firstPaint: cache.firstPaintDurationRow,
+        metadata: cache.metadataLoadDuration || Math.round(performance.now() - cache.metaStartTime),
+        snapshots: cache.snapshotsLoadDuration || Math.round(performance.now() - cache.snapshotsStartTime),
+        events: cache.eventsLoadDuration || Math.round(performance.now() - cache.eventsStartTime),
+        firstPaint: cache.firstPaintDuration,
     }
 }
 
+const resetTimingsCache = (cache: Record<string, any>): void => {
+    cache.metaStartTime = null
+    cache.metadataLoadDuration = null
+    cache.snapshotsStartTime = null
+    cache.snapshotsLoadDuration = null
+    cache.eventsStartTime = null
+    cache.eventsLoadDuration = null
+    cache.firstPaintDuration = null
+}
+
 export interface SessionRecordingDataLogicProps {
     sessionRecordingId: SessionRecordingId
     realTimePollingIntervalMilliseconds?: number
@@ -321,62 +319,76 @@ export const sessionRecordingDataLogic = kea<sessionRecordingDataLogicType>([
         loadRecordingSnapshots: () => {
             actions.loadEvents()
         },
+        loadRecordingMetaSuccess: () => {
+            cache.metadataLoadDuration = Math.round(performance.now() - cache.metaStartTime)
+            actions.reportUsageIfFullyLoaded()
+        },
+        loadRecordingMetaFailure: () => {
+            cache.metadataLoadDuration = Math.round(performance.now() - cache.metaStartTime)
+        },
         loadRecordingSnapshotsSuccess: () => {
             const { snapshots, sources } = values.sessionPlayerSnapshotData ?? {}
-            if (snapshots && !snapshots.length && sources?.length === 1) {
-                // We got only a single source to load, loaded it successfully, but it had no snapshots.
-                posthog.capture('recording_snapshots_v2_empty_response', {
-                    source: sources[0],
-                })
+            if (snapshots) {
+                if (!snapshots.length && sources?.length === 1) {
+                    // We got only a single source to load, loaded it successfully, but it had no snapshots.
+                    posthog.capture('recording_snapshots_v2_empty_response', {
+                        source: sources[0],
+                    })
 
-                // If we only have a realtime source and its empty, start polling it anyway
-                if (sources[0].source === SnapshotSourceType.realtime) {
-                    actions.startRealTimePolling()
-                }
+                    // If we only have a realtime source and its empty, start polling it anyway
+                    if (sources[0].source === SnapshotSourceType.realtime) {
+                        actions.startRealTimePolling()
+                    }
 
-                return
-            }
+                    return
+                }
 
-            cache.firstPaintDurationRow = {
-                size: (values.sessionPlayerSnapshotData?.snapshots ?? []).length,
-                duration: Math.round(performance.now() - cache.snapshotsStartTime),
+                if (!cache.firstPaintDuration) {
+                    cache.firstPaintDuration = Math.round(performance.now() - cache.snapshotsStartTime)
+                    actions.reportViewed()
+                }
             }
 
-            actions.reportUsageIfFullyLoaded()
-
             const nextSourceToLoad = sources?.find((s) => !s.loaded)
 
             if (nextSourceToLoad) {
                 actions.loadRecordingSnapshots(nextSourceToLoad)
             } else {
-                actions.reportViewed()
+                cache.snapshotsLoadDuration = Math.round(performance.now() - cache.snapshotsStartTime)
+                actions.reportUsageIfFullyLoaded()
+
                 // If we have a realtime source, start polling it
                 const realTimeSource = sources?.find((s) => s.source === SnapshotSourceType.realtime)
                 if (realTimeSource) {
                     actions.startRealTimePolling()
                 }
             }
         },
+        loadRecordingSnapshotsFailure: () => {
+            cache.snapshotsLoadDuration = Math.round(performance.now() - cache.snapshotsStartTime)
+        },
         loadEventsSuccess: () => {
+            cache.eventsLoadDuration = Math.round(performance.now() - cache.eventsStartTime)
             actions.reportUsageIfFullyLoaded()
         },
-        reportUsageIfFullyLoaded: () => {
+        loadEventsFailure: () => {
+            cache.eventsLoadDuration = Math.round(performance.now() - cache.eventsStartTime)
+        },
+        reportUsageIfFullyLoaded: (_, breakpoint) => {
+            breakpoint()
             if (values.fullyLoaded) {
                 eventUsageLogic.actions.reportRecording(
                     values.sessionPlayerData,
-                    generateRecordingReportDurations(cache, values),
+                    generateRecordingReportDurations(cache),
                     SessionRecordingUsageType.LOADED,
                     0
                 )
                 // Reset cache now that final usage report has been sent
-                cache.metaStartTime = null
-                cache.snapshotsStartTime = null
-                cache.eventsStartTime = null
-                cache.firstPaintDurationRow = null
+                resetTimingsCache(cache)
             }
         },
         reportViewed: async (_, breakpoint) => {
-            const durations = generateRecordingReportDurations(cache, values)
+            const durations = generateRecordingReportDurations(cache)
             breakpoint()
             // Triggered on first paint
             eventUsageLogic.actions.reportRecording(
@@ -407,10 +419,12 @@ export const sessionRecordingDataLogic = kea<sessionRecordingDataLogicType>([
     loaders(({ values, props, cache, actions }) => ({
         sessionPlayerMetaData: {
             loadRecordingMeta: async (_, breakpoint) => {
-                cache.metaStartTime = performance.now()
                 if (!props.sessionRecordingId) {
                     return null
                 }
+
+                cache.metaStartTime = performance.now()
+
                 const response = await api.recordings.get(props.sessionRecordingId, {
                     save_view: true,
                 })
@@ -534,6 +548,10 @@ export const sessionRecordingDataLogic = kea<sessionRecordingDataLogicType>([
             null as null | RecordingEventType[],
             {
                 loadEvents: async () => {
+                    if (!cache.eventsStartTime) {
+                        cache.eventsStartTime = performance.now()
+                    }
+
                     const { start, end, person } = values.sessionPlayerData
 
                     if (!person || !start || !end) {
@@ -812,4 +830,7 @@ export const sessionRecordingDataLogic = kea<sessionRecordingDataLogicType>([
             },
         ],
     }),
+    beforeUnmount(({ cache }) => {
+        resetTimingsCache(cache)
+    }),
 ])

frontend/src/types.ts

@@ -3316,16 +3316,11 @@ export interface OrganizationResourcePermissionType {
     created_by: UserBaseType | null
 }
 
-export interface RecordingReportLoadTimeRow {
-    size?: number
-    duration: number
-}
-
 export interface RecordingReportLoadTimes {
-    metadata: RecordingReportLoadTimeRow
-    snapshots: RecordingReportLoadTimeRow
-    events: RecordingReportLoadTimeRow
-    firstPaint: RecordingReportLoadTimeRow
+    metadata: number
+    snapshots: number
+    events: number
+    firstPaint: number
 }
 
 export type JsonType = string | number | boolean | null | { [key: string]: JsonType } | Array<JsonType>