fix: Segmenter issue leading to paused playback (#17840)

PostHog · Oct 6, 2023 · 2183c6f · 2183c6f
1 parent 8e792de
commit 2183c6f
Show file tree

Hide file tree

Showing 6 changed files with 113 additions and 65 deletions.
diff --git a/...c/scenes/session-recordings/player/__snapshots__/sessionRecordingPlayerLogic.test.ts.snap b/...c/scenes/session-recordings/player/__snapshots__/sessionRecordingPlayerLogic.test.ts.snap
@@ -62,11 +62,11 @@ exports[`sessionRecordingPlayerLogic loading session core loads metadata and sna
       "windowId": "187d7c761a0525d-05f175487d4b65-1d525634-384000-187d7c761a149d0",
     },
     {
-      "durationMs": 525,
-      "endTimestamp": 1682952388658,
+      "durationMs": 527,
+      "endTimestamp": 1682952388659,
       "isActive": false,
       "kind": "gap",
-      "startTimestamp": 1682952388133,
+      "startTimestamp": 1682952388132,
       "windowId": "187d7c77dfe1d45-08bdcaf91135a2-1d525634-384000-187d7c77dff39a6",
     },
     {

diff --git a/frontend/src/scenes/session-recordings/player/controller/Seekbar.tsx b/frontend/src/scenes/session-recordings/player/controller/Seekbar.tsx
@@ -49,7 +49,7 @@ export function Seekbar(): JSX.Element {
                         <div className="PlayerSeekbar__segments">
                             {sessionPlayerData.segments?.map((segment: RecordingSegment) => (
                                 <div
-                                    key={`${segment.windowId}-${segment.startTimestamp}`}
+                                    key={`${segment.startTimestamp}-${segment.endTimestamp}`}
                                     className={clsx(
                                         'PlayerSeekbar__segments__item',
                                         segment.isActive && 'PlayerSeekbar__segments__item--active'

diff --git a/frontend/src/scenes/session-recordings/player/sessionRecordingPlayerLogic.ts b/frontend/src/scenes/session-recordings/player/sessionRecordingPlayerLogic.ts
@@ -490,6 +490,12 @@ export const sessionRecordingPlayerLogic = kea<sessionRecordingPlayerLogicType>(
                 plugins.push(CorsPlugin)
             }
 
+            cache.debug?.('tryInitReplayer', {
+                windowId,
+                rootFrame: values.rootFrame,
+                snapshots: values.sessionPlayerData.snapshotsByWindowId[windowId],
+            })
+
             const replayer = new Replayer(values.sessionPlayerData.snapshotsByWindowId[windowId], {
                 root: values.rootFrame,
                 ...COMMON_REPLAYER_CONFIG,
@@ -652,6 +658,11 @@ export const sessionRecordingPlayerLogic = kea<sessionRecordingPlayerLogicType>(
             actions.pauseIframePlayback()
             actions.syncPlayerSpeed() // hotfix: speed changes on player state change
             values.player?.replayer?.pause()
+
+            cache.debug?.('pause', {
+                currentTimestamp: values.currentTimestamp,
+                currentSegment: values.currentSegment,
+            })
         },
         setEndReached: ({ reached }) => {
             if (reached) {
@@ -776,14 +787,17 @@ export const sessionRecordingPlayerLogic = kea<sessionRecordingPlayerLogicType>(
                     values.currentPlayerState === SessionPlayerState.SKIP) &&
                 values.timestampChangeTracking.timestampMatchesPrevious > 10
             ) {
+                cache.debug?.('stuck session player detected', values.timestampChangeTracking)
                 actions.skipPlayerForward(rrwebPlayerTime, skip)
                 newTimestamp = newTimestamp + skip
             }
 
             if (newTimestamp == undefined && values.currentTimestamp) {
                 // This can happen if the player is not loaded due to us being in a "gap" segment
                 // In this case, we should progress time forward manually
+
                 if (values.currentSegment?.kind === 'gap') {
+                    cache.debug?.('gap segment: skipping forward')
                     newTimestamp = values.currentTimestamp + skip
                 }
             }
@@ -796,6 +810,12 @@ export const sessionRecordingPlayerLogic = kea<sessionRecordingPlayerLogicType>(
                     actions.setCurrentTimestamp(Math.max(newTimestamp, nextSegment.startTimestamp))
                     actions.setCurrentSegment(nextSegment)
                 } else {
+                    cache.debug('end of recording reached', {
+                        newTimestamp,
+                        segments: values.sessionPlayerData.segments,
+                        currentSegment: values.currentSegment,
+                        segmentIndex: values.sessionPlayerData.segments.indexOf(values.currentSegment),
+                    })
                     // At the end of the recording. Pause the player and set fully to the end
                     actions.setEndReached()
                 }
@@ -809,6 +829,7 @@ export const sessionRecordingPlayerLogic = kea<sessionRecordingPlayerLogicType>(
                 values.player?.replayer?.pause()
                 actions.startBuffer()
                 actions.setErrorPlayerState(false)
+                cache.debug('buffering')
                 return
             }
 
@@ -946,6 +967,8 @@ export const sessionRecordingPlayerLogic = kea<sessionRecordingPlayerLogicType>(
             return
         }
 
+        delete (window as any).__debug_player
+
         actions.stopAnimation()
         cache.resetConsoleWarn?.()
         cache.hasInitialized = false
@@ -975,7 +998,20 @@ export const sessionRecordingPlayerLogic = kea<sessionRecordingPlayerLogicType>(
         )
     }),
 
-    afterMount(({ props, actions, cache }) => {
+    afterMount(({ props, actions, cache, values }) => {
+        cache.debugging = localStorage.getItem('ph_debug_player') === 'true'
+        cache.debug = (...args: any[]) => {
+            if (cache.debugging) {
+                // eslint-disable-next-line no-console
+                console.log('[⏯️ PostHog Replayer]', ...args)
+            }
+        }
+        ;(window as any).__debug_player = () => {
+            cache.debugging = !cache.debugging
+            localStorage.setItem('ph_debug_player', JSON.stringify(cache.debugging))
+            cache.debug('player data', values.sessionPlayerData)
+        }
+
         if (props.mode === SessionRecordingPlayerMode.Preview) {
             return
         }

diff --git a/frontend/src/scenes/session-recordings/player/utils/__snapshots__/segmenter.test.ts.snap b/frontend/src/scenes/session-recordings/player/utils/__snapshots__/segmenter.test.ts.snap
@@ -1,5 +1,63 @@
 // Jest Snapshot v1, https://goo.gl/fbAQLP
 
+exports[`segmenter includes inactive events in the active segment until a threshold 1`] = `
+[
+  {
+    "durationMs": 4000,
+    "endTimestamp": 1672531204000,
+    "isActive": true,
+    "kind": "window",
+    "startTimestamp": 1672531200000,
+    "windowId": "A",
+  },
+  {
+    "durationMs": 2000,
+    "endTimestamp": 1672531206000,
+    "isActive": false,
+    "kind": "gap",
+    "startTimestamp": 1672531204000,
+    "windowId": "A",
+  },
+  {
+    "durationMs": 594000,
+    "endTimestamp": 1672531800000,
+    "isActive": false,
+    "kind": "window",
+    "startTimestamp": 1672531206000,
+    "windowId": "A",
+  },
+]
+`;
+
+exports[`segmenter inserts gaps inclusively 1`] = `
+[
+  {
+    "durationMs": 100,
+    "endTimestamp": 1672531200100,
+    "isActive": true,
+    "kind": "window",
+    "startTimestamp": 1672531200000,
+    "windowId": "A",
+  },
+  {
+    "durationMs": 599800,
+    "endTimestamp": 1672531799900,
+    "isActive": false,
+    "kind": "gap",
+    "startTimestamp": 1672531200100,
+    "windowId": undefined,
+  },
+  {
+    "durationMs": 100,
+    "endTimestamp": 1672531800000,
+    "isActive": false,
+    "kind": "window",
+    "startTimestamp": 1672531799900,
+    "windowId": "B",
+  },
+]
+`;
+
 exports[`segmenter matches snapshots 1`] = `
 [
   {
@@ -11,11 +69,11 @@ exports[`segmenter matches snapshots 1`] = `
     "windowId": "187d7c761a0525d-05f175487d4b65-1d525634-384000-187d7c761a149d0",
   },
   {
-    "durationMs": 525,
-    "endTimestamp": 1682952388658,
+    "durationMs": 527,
+    "endTimestamp": 1682952388659,
     "isActive": false,
     "kind": "gap",
-    "startTimestamp": 1682952388133,
+    "startTimestamp": 1682952388132,
     "windowId": "187d7c77dfe1d45-08bdcaf91135a2-1d525634-384000-187d7c77dff39a6",
   },
   {

diff --git a/frontend/src/scenes/session-recordings/player/utils/segmenter.test.ts b/frontend/src/scenes/session-recordings/player/utils/segmenter.test.ts
@@ -31,7 +31,9 @@ describe('segmenter', () => {
         ])
     })
 
-    it('inserts gaps', () => {
+    it('inserts gaps inclusively', () => {
+        // NOTE: It is important that the segments are "inclusive" of the start and end timestamps as the player logic
+        // depends on this to choose which segment should be played next
         const start = dayjs('2023-01-01T00:00:00.000Z')
         const end = dayjs('2023-01-01T00:10:00.000Z')
 
@@ -44,32 +46,7 @@ describe('segmenter', () => {
 
         const segments = createSegments(snapshots, start, end)
 
-        expect(segments).toEqual([
-            {
-                kind: 'window',
-                startTimestamp: 1672531200000,
-                windowId: 'A',
-                isActive: true,
-                endTimestamp: 1672531200100,
-                durationMs: 100,
-            },
-            {
-                durationMs: 599798,
-                endTimestamp: 1672531799899,
-                isActive: false,
-                kind: 'gap',
-                startTimestamp: 1672531200101,
-                windowId: undefined,
-            },
-            {
-                kind: 'window',
-                startTimestamp: 1672531799900,
-                windowId: 'B',
-                isActive: false,
-                endTimestamp: 1672531800000,
-                durationMs: 100,
-            },
-        ])
+        expect(segments).toMatchSnapshot()
     })
 
     it('includes inactive events in the active segment until a threshold', () => {
@@ -86,31 +63,6 @@ describe('segmenter', () => {
 
         const segments = createSegments(snapshots, start, end)
 
-        expect(segments).toEqual([
-            {
-                kind: 'window',
-                startTimestamp: start.valueOf(),
-                windowId: 'A',
-                isActive: true,
-                endTimestamp: start.valueOf() + 4000,
-                durationMs: 4000,
-            },
-            {
-                kind: 'gap',
-                startTimestamp: start.valueOf() + 4000 + 1,
-                endTimestamp: start.valueOf() + 6000 - 1,
-                windowId: 'A',
-                isActive: false,
-                durationMs: 1998,
-            },
-            {
-                kind: 'window',
-                startTimestamp: start.valueOf() + 6000,
-                windowId: 'A',
-                isActive: false,
-                endTimestamp: end.valueOf(),
-                durationMs: 594000,
-            },
-        ])
+        expect(segments).toMatchSnapshot()
     })
 })
diff --git a/frontend/src/scenes/session-recordings/player/utils/segmenter.ts b/frontend/src/scenes/session-recordings/player/utils/segmenter.ts
@@ -116,10 +116,12 @@ export const createSegments = (snapshots: RecordingSnapshot[], start?: Dayjs, en
         const previousSegment = segments[index - 1]
         const list = [...acc]
 
-        if (previousSegment && segment.startTimestamp - previousSegment.endTimestamp > 1) {
-            const startTimestamp = previousSegment.endTimestamp + 1
-            const endTimestamp = segment.startTimestamp - 1
-            const windowId = findWindowIdForTimestamp(startTimestamp, previousSegment.windowId)
+        if (previousSegment && segment.startTimestamp !== previousSegment.endTimestamp) {
+            // If the segments do not immediately follow each other then we add a "gap" segment
+            const startTimestamp = previousSegment.endTimestamp
+            const endTimestamp = segment.startTimestamp
+            // Offset the window ID check so we look for a subsequent segment
+            const windowId = findWindowIdForTimestamp(startTimestamp + 1, previousSegment.windowId)
             const gapSegment: Partial<RecordingSegment> = {
                 kind: 'gap',
                 startTimestamp,