From 5e2014756189415e04fb796e9e6c6e1d18f26c1a Mon Sep 17 00:00:00 2001 From: Paul D'Ambra Date: Tue, 15 Oct 2024 14:44:59 +0200 Subject: [PATCH] feat: report reason for recording start (#1452) Co-authored-by: Manoel Aranda Neto <5731772+marandaneto@users.noreply.github.com> --- cypress/e2e/session-recording.cy.ts | 122 ++++++++++++------ .../replay/sessionrecording.test.ts | 15 ++- src/extensions/replay/sessionrecording.ts | 73 ++++++++--- src/posthog-core.ts | 22 ++-- 4 files changed, 162 insertions(+), 70 deletions(-) diff --git a/cypress/e2e/session-recording.cy.ts b/cypress/e2e/session-recording.cy.ts index 6ffa67f05..f247b383d 100644 --- a/cypress/e2e/session-recording.cy.ts +++ b/cypress/e2e/session-recording.cy.ts @@ -60,23 +60,25 @@ function ensureActivitySendsSnapshots(initial = true) { .wait('@session-recording') .then(() => { cy.phCaptures({ full: true }).then((captures) => { - expect(captures.map((c) => c.event)).to.deep.equal(['$snapshot']) - expect(captures[0]['properties']['$snapshot_data']).to.have.length.above(14).and.below(40) + const capturedSnapshot = captures.find((e) => e.event === '$snapshot') + expect(capturedSnapshot).not.to.be.undefined + + expect(capturedSnapshot['properties']['$snapshot_data']).to.have.length.above(14).and.below(40) // a meta and then a full snapshot - expect(captures[0]['properties']['$snapshot_data'][0].type).to.equal(4) // meta - expect(captures[0]['properties']['$snapshot_data'][1].type).to.equal(2) // full_snapshot + expect(capturedSnapshot['properties']['$snapshot_data'][0].type).to.equal(4) // meta + expect(capturedSnapshot['properties']['$snapshot_data'][1].type).to.equal(2) // full_snapshot if (initial) { - expectSessionOptionsCustomEvent(captures[0]['properties']['$snapshot_data'][2]) - expectPostHogConfigCustomEvent(captures[0]['properties']['$snapshot_data'][3]) + expectSessionOptionsCustomEvent(capturedSnapshot['properties']['$snapshot_data'][2]) + expectPostHogConfigCustomEvent(capturedSnapshot['properties']['$snapshot_data'][3]) } else { - expectSessionOptionsCustomEvent(captures[0]['properties']['$snapshot_data'][2]) - expectPostHogConfigCustomEvent(captures[0]['properties']['$snapshot_data'][3]) - expectSessionIdChangedCustomEvent(captures[0]['properties']['$snapshot_data'][4]) + expectSessionOptionsCustomEvent(capturedSnapshot['properties']['$snapshot_data'][2]) + expectPostHogConfigCustomEvent(capturedSnapshot['properties']['$snapshot_data'][3]) + expectSessionIdChangedCustomEvent(capturedSnapshot['properties']['$snapshot_data'][4]) } // Making a set from the rest should all be 3 - incremental snapshots - const remainder = captures[0]['properties']['$snapshot_data'].slice(initial ? 4 : 5) + const remainder = capturedSnapshot['properties']['$snapshot_data'].slice(initial ? 4 : 5) expect(Array.from(new Set(remainder.map((s) => s.type)))).to.deep.equal([3]) }) }) @@ -112,6 +114,9 @@ describe('Session recording', () => { describe('array.full.js', () => { it('captures session events', () => { start({ + options: { + session_recording: {}, + }, decideResponseOverrides: { isAuthenticated: false, sessionRecording: { @@ -128,9 +133,13 @@ describe('Session recording', () => { .type('hello posthog!') .wait('@session-recording') .then(() => { + cy.posthog().invoke('capture', 'test_registered_property') cy.phCaptures({ full: true }).then((captures) => { - // should be a pageview and a $snapshot - expect(captures.map((c) => c.event)).to.deep.equal(['$pageview', '$snapshot']) + expect(captures.map((c) => c.event)).to.deep.equal([ + '$pageview', + '$snapshot', + 'test_registered_property', + ]) expect(captures[1]['properties']['$snapshot_data']).to.have.length.above(33).and.below(40) // a meta and then a full snapshot @@ -141,6 +150,10 @@ describe('Session recording', () => { // Making a set from the rest should all be 3 - incremental snapshots const incrementalSnapshots = captures[1]['properties']['$snapshot_data'].slice(4) expect(Array.from(new Set(incrementalSnapshots.map((s) => s.type)))).to.deep.eq([3]) + + expect(captures[2]['properties']['$session_recording_start_reason']).to.equal( + 'recording_initialized' + ) }) }) }) @@ -180,6 +193,8 @@ describe('Session recording', () => { loaded: (ph) => { ph.sessionRecording._forceAllowLocalhostNetworkCapture = true }, + + session_recording: {}, }, }) @@ -271,6 +286,9 @@ describe('Session recording', () => { describe('array.js', () => { beforeEach(() => { start({ + options: { + session_recording: {}, + }, decideResponseOverrides: { isAuthenticated: false, sessionRecording: { @@ -386,10 +404,11 @@ describe('Session recording', () => { it('continues capturing to the same session when the page reloads', () => { let sessionId: string | null = null - // cypress time handling can confuse when to run full snapshot, let's force that to happen... cy.get('[data-cy-input]').type('hello world! ') cy.wait('@session-recording').then(() => { cy.phCaptures({ full: true }).then((captures) => { + expect(captures.map((c) => c.event)).to.deep.equal(['$pageview', '$snapshot']) + captures.forEach((c) => { if (isNull(sessionId)) { sessionId = c.properties['$session_id'] @@ -404,7 +423,9 @@ describe('Session recording', () => { cy.resetPhCaptures() // and refresh the page cy.reload() - cy.posthogInit({}) + cy.posthogInit({ + session_recording: {}, + }) cy.wait('@decide') cy.wait('@recorder-script') @@ -418,10 +439,13 @@ describe('Session recording', () => { cy.phCaptures({ full: true }).then((captures) => { // should be a $snapshot for the current session expect(captures.map((c) => c.event)).to.deep.equal(['$pageview', '$snapshot']) + expect(captures[0].properties['$session_id']).to.equal(sessionId) - expect(captures[1].properties['$session_id']).to.equal(sessionId) - expect(captures[1]['properties']['$snapshot_data']).to.have.length.above(0) + const capturedSnapshot = captures[1] + expect(capturedSnapshot.properties['$session_id']).to.equal(sessionId) + + expect(capturedSnapshot['properties']['$snapshot_data']).to.have.length.above(0) /** * the snapshots will look a little like: @@ -433,28 +457,28 @@ describe('Session recording', () => { // page reloaded so we will start with a full snapshot // a meta and then a full snapshot - expect(captures[1]['properties']['$snapshot_data'][0].type).to.equal(4) // meta - expect(captures[1]['properties']['$snapshot_data'][1].type).to.equal(2) // full_snapshot + expect(capturedSnapshot['properties']['$snapshot_data'][0].type).to.equal(4) // meta + expect(capturedSnapshot['properties']['$snapshot_data'][1].type).to.equal(2) // full_snapshot // these custom events should always be in the same order, but computers // we don't care if they are present and in a changing order const customEvents = sortByTag([ - captures[1]['properties']['$snapshot_data'][2], - captures[1]['properties']['$snapshot_data'][3], - captures[1]['properties']['$snapshot_data'][4], + capturedSnapshot['properties']['$snapshot_data'][2], + capturedSnapshot['properties']['$snapshot_data'][3], + capturedSnapshot['properties']['$snapshot_data'][4], ]) expectPageViewCustomEvent(customEvents[0]) expectPostHogConfigCustomEvent(customEvents[1]) expectSessionOptionsCustomEvent(customEvents[2]) const xPositions = [] - for (let i = 5; i < captures[1]['properties']['$snapshot_data'].length; i++) { - expect(captures[1]['properties']['$snapshot_data'][i].type).to.equal(3) - expect(captures[1]['properties']['$snapshot_data'][i].data.source).to.equal( + for (let i = 5; i < capturedSnapshot['properties']['$snapshot_data'].length; i++) { + expect(capturedSnapshot['properties']['$snapshot_data'][i].type).to.equal(3) + expect(capturedSnapshot['properties']['$snapshot_data'][i].data.source).to.equal( 6, - JSON.stringify(captures[1]['properties']['$snapshot_data'][i]) + JSON.stringify(capturedSnapshot['properties']['$snapshot_data'][i]) ) - xPositions.push(captures[1]['properties']['$snapshot_data'][i].data.positions[0].x) + xPositions.push(capturedSnapshot['properties']['$snapshot_data'][i].data.positions[0].x) } // even though we trigger 4 events, only 2 snapshots should be captured @@ -478,11 +502,20 @@ describe('Session recording', () => { .type('hello posthog!') .wait('@session-recording') .then(() => { + cy.posthog().invoke('capture', 'test_registered_property') cy.phCaptures({ full: true }).then((captures) => { - // should be a pageview and a $snapshot - expect(captures.map((c) => c.event)).to.deep.equal(['$pageview', '$snapshot']) + expect(captures.map((c) => c.event)).to.deep.equal([ + '$pageview', + '$snapshot', + 'test_registered_property', + ]) + expect(captures[1]['properties']['$session_id']).to.be.a('string') firstSessionId = captures[1]['properties']['$session_id'] + + expect(captures[2]['properties']['$session_recording_start_reason']).to.equal( + 'recording_initialized' + ) }) }) @@ -505,24 +538,29 @@ describe('Session recording', () => { .type('hello posthog!') .wait('@session-recording', { timeout: 10000 }) .then(() => { + cy.posthog().invoke('capture', 'test_registered_property') cy.phCaptures({ full: true }).then((captures) => { - // should be a pageview and a $snapshot - expect(captures[0].event).to.equal('$snapshot') + const capturedSnapshot = captures[0] + expect(capturedSnapshot.event).to.equal('$snapshot') - expect(captures[0]['properties']['$session_id']).to.be.a('string') - expect(captures[0]['properties']['$session_id']).not.to.eq(firstSessionId) + expect(capturedSnapshot['properties']['$session_id']).to.be.a('string') + expect(capturedSnapshot['properties']['$session_id']).not.to.eq(firstSessionId) - expect(captures[0]['properties']['$snapshot_data']).to.have.length.above(0) - expect(captures[0]['properties']['$snapshot_data'][0].type).to.equal(4) // meta - expect(captures[0]['properties']['$snapshot_data'][1].type).to.equal(2) // full_snapshot + expect(capturedSnapshot['properties']['$snapshot_data']).to.have.length.above(0) + expect(capturedSnapshot['properties']['$snapshot_data'][0].type).to.equal(4) // meta + expect(capturedSnapshot['properties']['$snapshot_data'][1].type).to.equal(2) // full_snapshot + + expect(captures[1].event).to.equal('test_registered_property') + expect(captures[1]['properties']['$session_recording_start_reason']).to.equal( + 'session_id_changed' + ) }) }) }) it('starts a new recording after calling reset', () => { cy.phCaptures({ full: true }).then((captures) => { - // should be a pageview at the beginning - expect(captures.map((c) => c.event)).to.deep.equal(['$pageview']) + expect(captures[0].event).to.eq('$pageview') }) cy.resetPhCaptures() @@ -553,6 +591,9 @@ describe('Session recording', () => { describe('with sampling', () => { beforeEach(() => { start({ + options: { + session_recording: {}, + }, decideResponseOverrides: { isAuthenticated: false, sessionRecording: { @@ -575,7 +616,6 @@ describe('Session recording', () => { .wait(200) // can't wait on call to session recording, it's not going to happen .then(() => { cy.phCaptures({ full: true }).then((captures) => { - // should be a pageview and a $snapshot expect(captures.map((c) => c.event)).to.deep.equal(['$pageview']) }) }) @@ -611,6 +651,12 @@ describe('Session recording', () => { // no call to session-recording yet }) + cy.posthog().invoke('capture', 'test_registered_property') + cy.phCaptures({ full: true }).then((captures) => { + expect((captures || []).map((c) => c.event)).to.deep.equal(['$pageview', 'test_registered_property']) + expect(captures[1]['properties']['$session_recording_start_reason']).to.equal('sampling_override') + }) + cy.resetPhCaptures() cy.get('[data-cy-input]').type('hello posthog!') diff --git a/src/__tests__/extensions/replay/sessionrecording.test.ts b/src/__tests__/extensions/replay/sessionrecording.test.ts index fc110b397..bbb709194 100644 --- a/src/__tests__/extensions/replay/sessionrecording.test.ts +++ b/src/__tests__/extensions/replay/sessionrecording.test.ts @@ -44,6 +44,7 @@ import { pluginEvent, } from '@rrweb/types' import Mock = jest.Mock +import { ConsentManager } from '../../../consent' // Type and source defined here designate a non-user-generated recording event @@ -243,14 +244,22 @@ describe('SessionRecording', () => { config: config, capture: jest.fn(), persistence: postHogPersistence, - onFeatureFlags: (cb: (flags: string[]) => void) => { + onFeatureFlags: ( + cb: (flags: string[], variants: Record) => void + ): (() => void) => { onFeatureFlagsCallback = cb + return () => {} }, sessionManager: sessionManager, requestRouter: new RequestRouter({ config } as any), _addCaptureHook: addCaptureHookMock, - consent: { isOptedOut: () => false }, - } as unknown as PostHog + consent: { + isOptedOut(): boolean { + return false + }, + } as unknown as ConsentManager, + register_for_session() {}, + } as Partial as PostHog loadScriptMock.mockImplementation((_ph, _path, callback) => { addRRwebToWindow() diff --git a/src/extensions/replay/sessionrecording.ts b/src/extensions/replay/sessionrecording.ts index 8c196c883..e7b62d34e 100644 --- a/src/extensions/replay/sessionrecording.ts +++ b/src/extensions/replay/sessionrecording.ts @@ -34,6 +34,14 @@ import { isLocalhost } from '../../utils/request-utils' import { MutationRateLimiter } from './mutation-rate-limiter' import { gzipSync, strFromU8, strToU8 } from 'fflate' +type SessionStartReason = + | 'sampling_override' + | 'recording_initialized' + | 'linked_flag_match' + | 'linked_flag_override' + | 'sampling' + | 'session_id_changed' + const BASE_ENDPOINT = '/s/' const FIVE_MINUTES = 1000 * 60 * 5 @@ -392,9 +400,9 @@ export class SessionRecording { } } - startIfEnabledOrStop() { + startIfEnabledOrStop(startReason?: SessionStartReason) { if (this.isRecordingEnabled) { - this._startCapture() + this._startCapture(startReason) // calling addEventListener multiple times is safe and will not add duplicates window?.addEventListener('beforeunload', this._onBeforeUnload) @@ -496,15 +504,21 @@ export class SessionRecording { shouldSample = storedIsSampled } - if (!shouldSample && makeDecision) { - logger.warn( - LOGGER_PREFIX + - ` Sample rate (${currentSampleRate}) has determined that this sessionId (${sessionId}) will not be sent to the server.` - ) + if (makeDecision) { + if (shouldSample) { + this._reportStarted('sampling') + } else { + logger.warn( + LOGGER_PREFIX + + ` Sample rate (${currentSampleRate}) has determined that this sessionId (${sessionId}) will not be sent to the server.` + ) + } + + this._tryAddCustomEvent('samplingDecisionMade', { + sampleRate: currentSampleRate, + isSampled: shouldSample, + }) } - this._tryAddCustomEvent('samplingDecisionMade', { - sampleRate: currentSampleRate, - }) this.instance.persistence?.register({ [SESSION_RECORDING_IS_SAMPLED]: shouldSample, @@ -536,6 +550,7 @@ export class SessionRecording { const tag = 'linked flag matched' logger.info(LOGGER_PREFIX + ' ' + tag, payload) this._tryAddCustomEvent(tag, payload) + this._reportStarted('linked_flag_match') } this._linkedFlagSeen = linkedFlagMatches }) @@ -609,7 +624,7 @@ export class SessionRecording { }) } - private _startCapture() { + private _startCapture(startReason?: SessionStartReason) { if (isUndefined(Object.assign)) { // According to the rrweb docs, rrweb is not supported on IE11 and below: // "rrweb does not support IE11 and below because it uses the MutationObserver API which was supported by these browsers." @@ -648,6 +663,11 @@ export class SessionRecording { } else { this._onScriptLoaded() } + + logger.info(LOGGER_PREFIX + ' starting') + if (this.status === 'active') { + this._reportStarted(startReason || 'recording_initialized') + } } private isInteractiveEvent(event: eventWithTime) { @@ -721,7 +741,7 @@ export class SessionRecording { if (sessionIdChanged || windowIdChanged) { this.stopRecording() - this.startIfEnabledOrStop() + this.startIfEnabledOrStop('session_id_changed') } else if (returningFromIdle) { this._scheduleFullSnapshot() } @@ -838,11 +858,6 @@ export class SessionRecording { this._tryAddCustomEvent('$posthog_config', { config: this.instance.config, }) - - logger.info(LOGGER_PREFIX + ' started', { - idleThreshold: this.sessionIdleThresholdMilliseconds, - maxIdleTime: this.sessionManager.sessionTimeoutMs, - }) } private _scheduleFullSnapshot(): void { @@ -1096,5 +1111,29 @@ export class SessionRecording { * */ public overrideLinkedFlag() { this._linkedFlagSeen = true + this._reportStarted('linked_flag_override') + } + + /** + * this ignores the sampling config and causes capture to start + * (if recording would have started had the flag been received i.e. it does not override other config). + * + * It is not usual to call this directly, + * instead call `posthog.startSessionRecording({sampling: true})` + * */ + public overrideSampling() { + this.instance.persistence?.register({ + // short-circuits the `makeSamplingDecision` function in the session recording module + [SESSION_RECORDING_IS_SAMPLED]: true, + }) + this._reportStarted('sampling_override') + } + + private _reportStarted(startReason: SessionStartReason, shouldReport: () => boolean = () => true) { + if (shouldReport()) { + this.instance.register_for_session({ + $session_recording_start_reason: startReason, + }) + } } } diff --git a/src/posthog-core.ts b/src/posthog-core.ts index e5fd4bf1c..6f9845ff7 100644 --- a/src/posthog-core.ts +++ b/src/posthog-core.ts @@ -17,7 +17,6 @@ import { ALIAS_ID_KEY, FLAG_CALL_REPORTED, PEOPLE_DISTINCT_ID_KEY, - SESSION_RECORDING_IS_SAMPLED, USER_STATE, ENABLE_PERSON_PROCESSING, } from './constants' @@ -320,7 +319,7 @@ export class PostHog { }, } - this.on('eventCaptured', (data) => logger.info('send', data)) + this.on('eventCaptured', (data) => logger.info(`send "${data?.event}"`, data)) } // Initialization methods @@ -1792,18 +1791,17 @@ export class PostHog { */ startSessionRecording(override?: { sampling?: boolean; linked_flag?: boolean } | true): void { const overrideAll = isBoolean(override) && override - if (overrideAll || override?.sampling) { + if (overrideAll || override?.sampling || override?.linked_flag) { // allow the session id check to rotate session id if necessary const ids = this.sessionManager?.checkAndGetSessionAndWindowId() - this.persistence?.register({ - // short-circuits the `makeSamplingDecision` function in the session recording module - [SESSION_RECORDING_IS_SAMPLED]: true, - }) - logger.info('Session recording started with sampling override for session: ', ids?.sessionId) - } - if (overrideAll || override?.linked_flag) { - this.sessionRecording?.overrideLinkedFlag() - logger.info('Session recording started with linked_flags override') + if (overrideAll || override?.sampling) { + this.sessionRecording?.overrideSampling() + logger.info('Session recording started with sampling override for session: ', ids?.sessionId) + } + if (overrideAll || override?.linked_flag) { + this.sessionRecording?.overrideLinkedFlag() + logger.info('Session recording started with linked_flags override') + } } this.set_config({ disable_session_recording: false }) }