diff --git a/.changeset/calm-coats-brake.md b/.changeset/calm-coats-brake.md new file mode 100644 index 0000000000..d9d8c5d061 --- /dev/null +++ b/.changeset/calm-coats-brake.md @@ -0,0 +1,5 @@ +--- +'posthog-js': patch +--- + +fix: session id rotation relied on in-memory cache which would be stale after log idle periods - particularly with multiple windows in play diff --git a/packages/browser/playwright/mocked/session-recording/lazy-session-recording.spec.ts b/packages/browser/playwright/mocked/session-recording/lazy-session-recording.spec.ts index 48ca09bf3e..7218dc34a3 100644 --- a/packages/browser/playwright/mocked/session-recording/lazy-session-recording.spec.ts +++ b/packages/browser/playwright/mocked/session-recording/lazy-session-recording.spec.ts @@ -56,6 +56,26 @@ function getSnapshotTimestamp(snapshot: any, position: 'first' | 'last'): number return snapshotData[index]?.timestamp || snapshotData[index]?.data?.timestamp } +async function simulateSessionExpiry(page: Page): Promise { + await page.evaluate(() => { + const ph = (window as WindowWithPostHog).posthog + const activityTs = ph?.sessionManager?.['_sessionActivityTimestamp'] + const startTs = ph?.sessionManager?.['_sessionStartTimestamp'] + const sessionId = ph?.sessionManager?.['_sessionId'] + const timeout = ph?.sessionManager?.['_sessionTimeoutMs'] + + const expiredActivityTs = activityTs! - timeout! - 1000 + const expiredStartTs = startTs! - timeout! - 1000 + + // @ts-expect-error - accessing private properties for test + ph.sessionManager['_sessionActivityTimestamp'] = expiredActivityTs + // @ts-expect-error - accessing private properties for test + ph.sessionManager['_sessionStartTimestamp'] = expiredStartTs + // @ts-expect-error - accessing private properties for test + ph.persistence.register({ $sesid: [expiredActivityTs, sessionId, expiredStartTs] }) + }) +} + const startOptions = { options: { session_recording: {}, @@ -254,22 +274,8 @@ test.describe('Session recording - array.js', () => { expect(capturedEvents[1]['properties']['$session_recording_start_reason']).toEqual('recording_initialized') await page.resetCapturedEvents() - const timestampBeforeRotation = await page.evaluate(() => { - const ph = (window as WindowWithPostHog).posthog - const activityTs = ph?.sessionManager?.['_sessionActivityTimestamp'] - const startTs = ph?.sessionManager?.['_sessionStartTimestamp'] - const timeout = ph?.sessionManager?.['_sessionTimeoutMs'] - - // move the session values back, - // so that the next event appears to be greater than timeout since those values - // @ts-expect-error can ignore that TS thinks these things might be null - ph.sessionManager['_sessionActivityTimestamp'] = activityTs - timeout - 1000 - // @ts-expect-error can ignore that TS thinks these things might be null - ph.sessionManager['_sessionStartTimestamp'] = startTs - timeout - 1000 - - return Date.now() - }) - + const timestampBeforeRotation = Date.now() + await simulateSessionExpiry(page) await page.waitForTimeout(100) await page.waitingForNetworkCausedBy({ diff --git a/packages/browser/playwright/mocked/session-recording/session-recording-idle-timeout.spec.ts b/packages/browser/playwright/mocked/session-recording/session-recording-idle-timeout.spec.ts index b3f1666325..0e3f8efeff 100644 --- a/packages/browser/playwright/mocked/session-recording/session-recording-idle-timeout.spec.ts +++ b/packages/browser/playwright/mocked/session-recording/session-recording-idle-timeout.spec.ts @@ -146,17 +146,149 @@ test.describe('Session recording - idle timeout behavior', () => { ph?.capture('test_after_idle_restart') }) - await page.expectCapturedEventsToBe(['$snapshot', '$snapshot', 'test_after_idle_restart']) const capturedEvents = await page.capturedEvents() + const snapshots = capturedEvents.filter((e) => e.event === '$snapshot') + const testEvent = capturedEvents.find((e) => e.event === 'test_after_idle_restart') - expect(capturedEvents[0]['properties']['$session_id']).toEqual(initialSessionId) - expect(getSnapshotTimestamp(capturedEvents[0], 'last')).toBeLessThan(timestampAfterRestart) + // Should have at least 2 snapshots (old session final, new session data) + expect(snapshots.length).toBeGreaterThanOrEqual(2) - expect(capturedEvents[1]['properties']['$session_id']).toEqual(newSessionId) - expect(getSnapshotTimestamp(capturedEvents[1], 'first')).toBeGreaterThan(timestampBeforeIdle) + // First snapshot should be old session final data + const oldSessionSnapshots = snapshots.filter((s) => s['properties']['$session_id'] === initialSessionId) + expect(oldSessionSnapshots.length).toBeGreaterThanOrEqual(1) + expect(getSnapshotTimestamp(oldSessionSnapshots[0], 'last')).toBeLessThan(timestampAfterRestart) - expect(capturedEvents[2]['properties']['$session_id']).toEqual(newSessionId) - expect(capturedEvents[2]['properties']['$session_recording_start_reason']).toEqual('session_id_changed') + // New session snapshots should exist + const newSessionSnapshots = snapshots.filter((s) => s['properties']['$session_id'] === newSessionId) + expect(newSessionSnapshots.length).toBeGreaterThanOrEqual(1) + expect(getSnapshotTimestamp(newSessionSnapshots[0], 'first')).toBeGreaterThan(timestampBeforeIdle) + + // Test event should be on new session with correct start reason + expect(testEvent?.['properties']['$session_id']).toEqual(newSessionId) + expect(testEvent?.['properties']['$session_recording_start_reason']).toEqual('session_id_changed') + }) + + test('rotates session when event timestamp shows idle timeout exceeded (frozen tab scenario)', async ({ page }) => { + // This tests the scenario where: + // 1. A browser tab is frozen/backgrounded for a long time + // 2. The forcedIdleReset timer never fires (because JS timers don't run when tab is frozen) + // 3. When the tab unfreezes, rrweb emits events with timestamps far in the future + // 4. We should detect this via timestamp-based idle detection and rotate the session + + // Start recording normally + await ensureActivitySendsSnapshots(page) + + const initialSessionId = await page.evaluate(() => { + const ph = (window as WindowWithPostHog).posthog + return ph?.get_session_id() + }) + expect(initialSessionId).toBeDefined() + + await page.resetCapturedEvents() + + // Simulate "frozen tab" scenario: + // Make the session appear to have been inactive for 35+ minutes + // by manipulating the lastActivityTimestamp in persistence and clearing the in-memory cache + // This simulates what happens when a tab is frozen and the forcedIdleReset timer never fires + await page.evaluate(() => { + const ph = (window as WindowWithPostHog).posthog + const persistence = ph?.persistence as any + const sessionManager = ph?.sessionManager as any + + if (!persistence) { + throw new Error('Persistence not available') + } + + if (!sessionManager) { + throw new Error('SessionManager not available') + } + + // Get current session data (stored as [lastActivityTimestamp, sessionId, sessionStartTimestamp]) + const sessionIdKey = '$sesid' + const currentSessionData = persistence.props[sessionIdKey] + + if (!currentSessionData) { + throw new Error('Session data not found') + } + + // Set the lastActivityTimestamp to 35 minutes ago + // This simulates a frozen tab where no activity was recorded + const thirtyFiveMinutesAgo = Date.now() - 35 * 60 * 1000 + currentSessionData[0] = thirtyFiveMinutesAgo + + // Write back the modified session data + persistence.register({ [sessionIdKey]: currentSessionData }) + + // Also clear the session manager's in-memory cache so it reads from persistence + // This simulates what happens when a tab unfreezes and state needs to be re-read + sessionManager._sessionActivityTimestamp = null + }) + + // Now trigger user activity + // This should detect that the session has been idle too long and rotate + await page.waitingForNetworkCausedBy({ + urlPatternsToWaitFor: ['**/ses/*'], + action: async () => { + await page.locator('[data-cy-input]').type('activity after simulated freeze!') + }, + }) + + const newSessionId = await page.evaluate(() => { + const ph = (window as WindowWithPostHog).posthog + return ph?.get_session_id() + }) + + // The session should have rotated because we exceeded the idle timeout + expect(newSessionId).not.toEqual(initialSessionId) + + // Capture all snapshot data to see exactly what happened + const capturedEvents = await page.capturedEvents() + const snapshots = capturedEvents.filter((e) => e.event === '$snapshot') + + // Collapse to essential fields: session_id, type, tag (for custom events) + // We don't assert on timestamps as they vary, but we assert on the exact sequence + const snapshotSummary = snapshots.flatMap((snapshot) => { + const sessionId = snapshot['properties']['$session_id'] + const snapshotData = snapshot['properties']['$snapshot_data'] as any[] + return snapshotData.map((event) => ({ + sessionId: sessionId === initialSessionId ? 'initial' : sessionId === newSessionId ? 'new' : 'unknown', + type: event.type, + tag: event.data?.tag || null, + })) + }) + + // Filter to just the significant events (not the many incremental snapshots from typing) + const significantEvents = snapshotSummary.filter( + (e) => e.type !== 3 // exclude IncrementalSnapshot (type 3) which are just typing mutations + ) + + // Assert on the exact expected sequence of events + // This is a solid record of what we expect to happen: + // 1. Old session gets final flush (type 6 = Plugin data) AND the $session_ending event + // 2. New session gets rrweb bootup events, then config and lifecycle custom events + expect(significantEvents).toEqual([ + // Final flush from old session before rotation + { sessionId: 'initial', type: 6, tag: null }, // Plugin data (network timing etc) + + // $session_ending is emitted during the callback, before new session starts + // It MUST go to the initial/old session, not the new one + { sessionId: 'initial', type: 5, tag: '$session_ending' }, // CustomEvent: marks end of old session + + // New session bootup sequence - rrweb emits these immediately on start() + // CRITICAL: these MUST be on new session, not initial (the bug we're fixing) + { sessionId: 'new', type: 4, tag: null }, // Meta event (page metadata) + { sessionId: 'new', type: 2, tag: null }, // FullSnapshot (DOM state) + { sessionId: 'new', type: 6, tag: null }, // Plugin data + + // Config custom events emitted during bootup + { sessionId: 'new', type: 5, tag: '$remote_config_received' }, // CustomEvent: config + { sessionId: 'new', type: 5, tag: '$session_options' }, // CustomEvent: recording options + { sessionId: 'new', type: 5, tag: '$posthog_config' }, // CustomEvent: posthog config + + // Session lifecycle events + { sessionId: 'new', type: 5, tag: '$session_id_change' }, // CustomEvent: session rotation marker + { sessionId: 'new', type: 5, tag: '$session_starting' }, // CustomEvent: marks start of new session + ]) }) }) diff --git a/packages/browser/playwright/mocked/session-recording/session-recording.spec.ts b/packages/browser/playwright/mocked/session-recording/session-recording.spec.ts index ddc26e8449..f14d481aa1 100644 --- a/packages/browser/playwright/mocked/session-recording/session-recording.spec.ts +++ b/packages/browser/playwright/mocked/session-recording/session-recording.spec.ts @@ -56,6 +56,26 @@ function getSnapshotTimestamp(snapshot: any, position: 'first' | 'last'): number return snapshotData[index]?.timestamp || snapshotData[index]?.data?.timestamp } +async function simulateSessionExpiry(page: Page): Promise { + await page.evaluate(() => { + const ph = (window as WindowWithPostHog).posthog + const activityTs = ph?.sessionManager?.['_sessionActivityTimestamp'] + const startTs = ph?.sessionManager?.['_sessionStartTimestamp'] + const sessionId = ph?.sessionManager?.['_sessionId'] + const timeout = ph?.sessionManager?.['_sessionTimeoutMs'] + + const expiredActivityTs = activityTs! - timeout! - 1000 + const expiredStartTs = startTs! - timeout! - 1000 + + // @ts-expect-error - accessing private properties for test + ph.sessionManager['_sessionActivityTimestamp'] = expiredActivityTs + // @ts-expect-error - accessing private properties for test + ph.sessionManager['_sessionStartTimestamp'] = expiredStartTs + // @ts-expect-error - accessing private properties for test + ph.persistence.register({ $sesid: [expiredActivityTs, sessionId, expiredStartTs] }) + }) +} + const startOptions = { options: { session_recording: { @@ -256,22 +276,8 @@ test.describe('Session recording - array.js', () => { expect(capturedEvents[1]['properties']['$session_recording_start_reason']).toEqual('recording_initialized') await page.resetCapturedEvents() - const timestampBeforeRotation = await page.evaluate(() => { - const ph = (window as WindowWithPostHog).posthog - const activityTs = ph?.sessionManager?.['_sessionActivityTimestamp'] - const startTs = ph?.sessionManager?.['_sessionStartTimestamp'] - const timeout = ph?.sessionManager?.['_sessionTimeoutMs'] - - // move the session values back, - // so that the next event appears to be greater than timeout since those values - // @ts-expect-error can ignore that TS thinks these things might be null - ph.sessionManager['_sessionActivityTimestamp'] = activityTs - timeout - 1000 - // @ts-expect-error can ignore that TS thinks these things might be null - ph.sessionManager['_sessionStartTimestamp'] = startTs - timeout - 1000 - - return Date.now() - }) - + const timestampBeforeRotation = Date.now() + await simulateSessionExpiry(page) await page.waitForTimeout(100) await page.waitingForNetworkCausedBy({ diff --git a/packages/browser/src/__tests__/extensions/replay/lazy-sessionrecording.test.ts b/packages/browser/src/__tests__/extensions/replay/lazy-sessionrecording.test.ts index f6e6394144..c8321b0e03 100644 --- a/packages/browser/src/__tests__/extensions/replay/lazy-sessionrecording.test.ts +++ b/packages/browser/src/__tests__/extensions/replay/lazy-sessionrecording.test.ts @@ -3036,6 +3036,8 @@ describe('Lazy SessionRecording', () => { }) expect(tryAddCustomEvent).toHaveBeenCalledWith('$session_ending', { + currentSessionId: sessionId, + currentWindowId: 'windowId', nextSessionId: newSessionId, nextWindowId: newWindowId, changeReason: { @@ -3087,6 +3089,8 @@ describe('Lazy SessionRecording', () => { }) expect(tryAddCustomEvent).toHaveBeenCalledWith('$session_ending', { + currentSessionId: sessionId, + currentWindowId: 'windowId', nextSessionId: newSessionId, nextWindowId: newWindowId, changeReason: { @@ -3143,6 +3147,8 @@ describe('Lazy SessionRecording', () => { // should capture the flushed size from the ending session expect(tryAddCustomEvent).toHaveBeenCalledWith('$session_ending', { + currentSessionId: sessionId, + currentWindowId: 'windowId', nextSessionId: newSessionId, nextWindowId: newWindowId, changeReason: { diff --git a/packages/browser/src/__tests__/sessionid.test.ts b/packages/browser/src/__tests__/sessionid.test.ts index cf5815d053..76b57bcde4 100644 --- a/packages/browser/src/__tests__/sessionid.test.ts +++ b/packages/browser/src/__tests__/sessionid.test.ts @@ -524,6 +524,52 @@ describe('Session ID manager', () => { }) }) + describe('persistence is source of truth over in-memory cache', () => { + // This test verifies that when persistence is updated (e.g., by another tab or after a frozen tab thaws), + // the session manager reads from persistence rather than trusting stale in-memory cache + + const memoryConfig = { + persistence_name: 'test-session-memory', + persistence: 'memory', + token: 'test-token', + } as PostHogConfig + + it.each([ + { description: 'with stale timestamp from simulated frozen tab', offsetMs: 1000 }, + { description: 'with exactly expired timestamp', offsetMs: 1 }, + ])('should detect activity timeout $description', ({ offsetMs }) => { + const realPersistence = new PostHogPersistence(memoryConfig) + const testTimestamp = 1603107479471 + + const sessionIdManager = new SessionIdManager( + createMockPostHog({ + config: memoryConfig, + persistence: realPersistence, + register: jest.fn(), + }), + () => 'newUUID', + () => 'newUUID' + ) + + // First call establishes the session + const firstResult = sessionIdManager.checkAndGetSessionAndWindowId(false, testTimestamp) + expect(firstResult.sessionId).toBe('newUUID') + + // Simulate persistence being updated externally to have a stale timestamp + // In a frozen tab scenario, another tab might have updated persistence, + // or time passed while the tab was frozen + const staleTimestamp = testTimestamp - (DEFAULT_SESSION_IDLE_TIMEOUT_SECONDS * 1000 + offsetMs) + realPersistence.register({ [SESSION_ID]: [staleTimestamp, 'oldSessionID', staleTimestamp] }) + + // Second call should read from persistence and detect the activity timeout + const secondResult = sessionIdManager.checkAndGetSessionAndWindowId(false, testTimestamp) + + // The session SHOULD rotate because persistence shows idle timeout exceeded + expect(secondResult.changeReason?.activityTimeout).toBe(true) + expect(secondResult.sessionId).not.toBe('oldSessionID') + }) + }) + describe('destroy()', () => { it('clears the idle timeout timer', () => { jest.useFakeTimers() diff --git a/packages/browser/src/extensions/replay/external/lazy-loaded-session-recorder.ts b/packages/browser/src/extensions/replay/external/lazy-loaded-session-recorder.ts index 2de88b6d63..42bd4a5432 100644 --- a/packages/browser/src/extensions/replay/external/lazy-loaded-session-recorder.ts +++ b/packages/browser/src/extensions/replay/external/lazy-loaded-session-recorder.ts @@ -233,10 +233,20 @@ function isSessionIdleEvent(e: eventWithTime): e is eventWithTime & customEvent return isCustomEvent(e, 'sessionIdle') } +type SessionEndingPayload = { + lastActivityTimestamp?: number + currentSessionId?: string + currentWindowId?: string +} + function isSessionEndingEvent(e: eventWithTime): e is eventWithTime & customEvent { return isCustomEvent(e, '$session_ending') } +function getSessionEndingPayload(e: eventWithTime): SessionEndingPayload | null { + return isSessionEndingEvent(e) ? (e.data.payload as SessionEndingPayload) : null +} + function isSessionStartingEvent(e: eventWithTime): e is eventWithTime & customEvent { return isCustomEvent(e, '$session_starting') } @@ -794,16 +804,23 @@ export class LazyLoadedSessionRecording implements LazyLoadedSessionRecordingInt private _onSessionIdCallback: SessionIdChangedCallback = (sessionId, windowId, changeReason) => { if (!changeReason) return + // Skip if session hasn't actually changed (callback might fire multiple times) + if (sessionId === this._sessionId && windowId === this._windowId) { + return + } + const wasLikelyReset = changeReason.noSessionId const shouldLinkSessions = !wasLikelyReset && (changeReason.activityTimeout || changeReason.sessionPastMaximumLength) - let oldSessionId, oldWindowId + // Capture old IDs before start() updates them + const oldSessionId = this._sessionId + const oldWindowId = this._windowId if (shouldLinkSessions) { - oldSessionId = this._sessionId - oldWindowId = this._windowId this._tryAddCustomEvent('$session_ending', { + currentSessionId: oldSessionId, + currentWindowId: oldWindowId, nextSessionId: sessionId, nextWindowId: windowId, changeReason, @@ -823,9 +840,10 @@ export class LazyLoadedSessionRecording implements LazyLoadedSessionRecordingInt this._clearConditionalRecordingPersistence() - if (!this._stopRrweb) { - this.start('session_id_changed') - } + // Note: We don't call stop()/start() here because _updateWindowAndSessionIds + // already handles the restart. This callback fires synchronously during + // checkAndGetSessionAndWindowId(), so _updateWindowAndSessionIds will detect + // the session change and handle the restart after this callback returns. if (shouldLinkSessions) { this._tryAddCustomEvent('$session_starting', { @@ -938,7 +956,28 @@ export class LazyLoadedSessionRecording implements LazyLoadedSessionRecordingInt // TODO: Re-add ensureMaxMessageSize once we are confident in it const event = truncateLargeConsoleLogs(throttledEvent) - this._updateWindowAndSessionIds(event) + // Session lifecycle events ($session_ending, $session_starting) carry their target session ID + // in the payload. We must extract this BEFORE _updateWindowAndSessionIds runs, because that + // method triggers checkAndGetSessionAndWindowId() which would update this._sessionId. + // This is critical for $session_ending which must go to the OLD session, not the new one. + const sessionEndingPayload = getSessionEndingPayload(event) + const sessionStarting = isSessionStartingEvent(event) + + if (sessionEndingPayload || sessionStarting) { + // Adjust timestamp from payload to avoid artificially extending session duration + const payload = (sessionEndingPayload ?? (event as customEvent).data.payload) as { + lastActivityTimestamp?: number + } + if (payload?.lastActivityTimestamp) { + event.timestamp = payload.lastActivityTimestamp + } + } else { + this._updateWindowAndSessionIds(event) + } + + // $session_ending uses session ID from payload (the old session), others use current session + const targetSessionId = sessionEndingPayload?.currentSessionId ?? this._sessionId + const targetWindowId = sessionEndingPayload?.currentWindowId ?? this._windowId // When in an idle state we keep recording but don't capture the events, // we don't want to return early if idle is 'unknown' @@ -958,16 +997,6 @@ export class LazyLoadedSessionRecording implements LazyLoadedSessionRecordingInt } } - if (isSessionEndingEvent(event) || isSessionStartingEvent(event)) { - // session ending/starting events have a timestamp when rrweb sees them - // which can artificially lengthen a session - // we know when the last activity was based on the payload and can correct the timestamp - const payload = event.data.payload as { lastActivityTimestamp?: number } - if (payload?.lastActivityTimestamp) { - event.timestamp = payload.lastActivityTimestamp - } - } - const eventToSend = (this._instance.config.session_recording.compress_events ?? true) ? compressEvent(event) : event const size = estimateSize(eventToSend) @@ -975,8 +1004,8 @@ export class LazyLoadedSessionRecording implements LazyLoadedSessionRecordingInt const properties = { $snapshot_bytes: size, $snapshot_data: eventToSend, - $session_id: this._sessionId, - $window_id: this._windowId, + $session_id: targetSessionId, + $window_id: targetWindowId, } if (this.status === DISABLED) { diff --git a/packages/browser/src/sessionid.ts b/packages/browser/src/sessionid.ts index 21a998901f..dc87e0f799 100644 --- a/packages/browser/src/sessionid.ts +++ b/packages/browser/src/sessionid.ts @@ -180,9 +180,9 @@ export class SessionIdManager { } private _getSessionId(): [number, string, number] { - if (this._sessionId && this._sessionActivityTimestamp && this._sessionStartTimestamp) { - return [this._sessionActivityTimestamp, this._sessionId, this._sessionStartTimestamp] - } + // Always read from persistence - it's the source of truth + // The in-memory cache could become stale (e.g., in a frozen tab scenario where + // time passes but the cache isn't updated) const sessionIdInfo = this._persistence.props[SESSION_ID] if (isArray(sessionIdInfo) && sessionIdInfo.length === 2) {