From 9c29c8a5b80a85f4c0755f8dee265e95a9f20105 Mon Sep 17 00:00:00 2001 From: Francesco Novy Date: Wed, 19 Jul 2023 10:26:35 +0200 Subject: [PATCH] fix(replay): Handle edge cases & more logging (#8558) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This is a PR to this feature branch: https://github.com/getsentry/sentry-javascript/pull/8407 * Handle edge case where we stop multiple times (honestly no idea how this should happen, but apparently it can 😬 ) * Add some more logging for state changes We can hopefully eventually remove the `traceInternals` checks, but for now this is an easy solution for debugging in the beta.... --- .../suites/replay/sessionMaxAge/init.js | 2 - .../suites/replay/sessionMaxAge/test.ts | 103 +++++++++++++++++- packages/replay/src/replay.ts | 26 ++++- 3 files changed, 126 insertions(+), 5 deletions(-) diff --git a/packages/browser-integration-tests/suites/replay/sessionMaxAge/init.js b/packages/browser-integration-tests/suites/replay/sessionMaxAge/init.js index 9ab8bbe47797..ece927ab71b3 100644 --- a/packages/browser-integration-tests/suites/replay/sessionMaxAge/init.js +++ b/packages/browser-integration-tests/suites/replay/sessionMaxAge/init.js @@ -11,8 +11,6 @@ Sentry.init({ sampleRate: 0, replaysSessionSampleRate: 1.0, replaysOnErrorSampleRate: 0.0, - debug: true, - integrations: [window.Replay], }); diff --git a/packages/browser-integration-tests/suites/replay/sessionMaxAge/test.ts b/packages/browser-integration-tests/suites/replay/sessionMaxAge/test.ts index 4e7a8b123eef..b3b8fdbc932a 100644 --- a/packages/browser-integration-tests/suites/replay/sessionMaxAge/test.ts +++ b/packages/browser-integration-tests/suites/replay/sessionMaxAge/test.ts @@ -13,8 +13,8 @@ import { const SESSION_MAX_AGE = 2000; -sentryTest('handles session that exceeds max age', async ({ getLocalTestPath, page }) => { - if (shouldSkipReplayTest()) { +sentryTest('handles session that exceeds max age', async ({ getLocalTestPath, page, browserName }) => { + if (shouldSkipReplayTest() || browserName === 'firefox') { sentryTest.skip(); } @@ -82,3 +82,102 @@ sentryTest('handles session that exceeds max age', async ({ getLocalTestPath, pa const stringifiedSnapshot2 = normalize(fullSnapshots2[0]); expect(stringifiedSnapshot2).toMatchSnapshot('snapshot-2.json'); }); + +sentryTest( + 'handles many consequitive events in session that exceeds max age', + async ({ getLocalTestPath, page, browserName }) => { + if (shouldSkipReplayTest() || browserName === 'firefox') { + sentryTest.skip(); + } + + const reqPromise0 = waitForReplayRequest(page, 0); + const reqPromise1 = waitForReplayRequest(page, 1); + + await page.route('https://dsn.ingest.sentry.io/**/*', route => { + return route.fulfill({ + status: 200, + contentType: 'application/json', + body: JSON.stringify({ id: 'test-id' }), + }); + }); + + const url = await getLocalTestPath({ testDir: __dirname }); + + await page.goto(url); + + const replay0 = await getReplaySnapshot(page); + // We use the `initialTimestamp` of the replay to do any time based calculations + const startTimestamp = replay0._context.initialTimestamp; + + const req0 = await reqPromise0; + + const replayEvent0 = getReplayEvent(req0); + expect(replayEvent0).toEqual(getExpectedReplayEvent({})); + + const fullSnapshots0 = getFullRecordingSnapshots(req0); + expect(fullSnapshots0.length).toEqual(1); + const stringifiedSnapshot = normalize(fullSnapshots0[0]); + expect(stringifiedSnapshot).toMatchSnapshot('snapshot-0.json'); + + // Wait again for a new segment 0 (=new session) + const reqPromise2 = waitForReplayRequest(page, 0); + + // Wait for an incremental snapshot + // Wait half of the session max age (after initial flush), but account for potentially slow runners + const timePassed1 = Date.now() - startTimestamp; + await new Promise(resolve => setTimeout(resolve, Math.max(SESSION_MAX_AGE / 2 - timePassed1, 0))); + + await page.click('#button1'); + + const req1 = await reqPromise1; + const replayEvent1 = getReplayEvent(req1); + + expect(replayEvent1).toEqual(getExpectedReplayEvent({ segment_id: 1, urls: [] })); + + const replay1 = await getReplaySnapshot(page); + const oldSessionId = replay1.session?.id; + + // Wait for session to expire + const timePassed2 = Date.now() - startTimestamp; + await new Promise(resolve => setTimeout(resolve, Math.max(SESSION_MAX_AGE - timePassed2, 0))); + + await page.evaluate(` + Object.defineProperty(document, 'visibilityState', { + configurable: true, + get: function () { + return 'hidden'; + }, + }); + document.dispatchEvent(new Event('visibilitychange')); +`); + + // Many things going on at the same time... + void page.evaluate(` + Object.defineProperty(document, 'visibilityState', { + configurable: true, + get: function () { + return 'visible'; + }, + }); + document.dispatchEvent(new Event('visibilitychange')); +`); + void page.click('#button1'); + void page.click('#button2'); + await new Promise(resolve => setTimeout(resolve, 1)); + void page.click('#button1'); + void page.click('#button2'); + + const req2 = await reqPromise2; + const replay2 = await getReplaySnapshot(page); + + expect(replay2.session?.id).not.toEqual(oldSessionId); + + const replayEvent2 = getReplayEvent(req2); + expect(replayEvent2).toEqual(getExpectedReplayEvent({})); + + const fullSnapshots2 = getFullRecordingSnapshots(req2); + expect(fullSnapshots2.length).toEqual(1); + const stringifiedSnapshot2 = normalize(fullSnapshots2[0]); + expect(stringifiedSnapshot2).toMatchSnapshot('snapshot-2.json'); + }, +); diff --git a/packages/replay/src/replay.ts b/packages/replay/src/replay.ts index 43d4f97cb1f5..3028ba00e05f 100644 --- a/packages/replay/src/replay.ts +++ b/packages/replay/src/replay.ts @@ -389,6 +389,12 @@ export class ReplayContainer implements ReplayContainerInterface { // Re-start recording, but in "session" recording mode + // When `traceInternals` is enabled, we want to log this to the console + // Else, use the regular debug output + // eslint-disable-next-line + const log = this.getOptions()._experiments.traceInternals ? console.warn : logger.log; + log('[Replay] An error was detected in buffer mode, starting to send replay...'); + // Reset all "capture on error" configuration before // starting a new recording this.recordingMode = 'session'; @@ -639,6 +645,11 @@ export class ReplayContainer implements ReplayContainerInterface { } void this.stop('session expired with refreshing').then(() => { + // Just to double-check we haven't started anywhere else + if (this.isEnabled()) { + return; + } + if (sampled === 'session') { return this.start(); } @@ -947,6 +958,17 @@ export class ReplayContainer implements ReplayContainerInterface { return; } + // Unless force is true (which is the case when stop() is called), + // _flush should never be called when not in session mode + // Apart from `stop()`, only debounced flush triggers `_flush()`, which shouldn't happen + if (this.recordingMode !== 'session' && !force) { + // When `traceInternals` is enabled, we want to log this to the console + // Else, use the regular debug output + // eslint-disable-next-line + const log = this.getOptions()._experiments.traceInternals ? console.warn : logger.warn; + log('[Replay] Flushing replay while not in session mode.'); + } + return new Promise(resolve => { if (!this.session) { resolve(); @@ -959,7 +981,9 @@ export class ReplayContainer implements ReplayContainerInterface { }, ensureResumed: () => this.resume(), onEnd: () => { - __DEBUG_BUILD__ && logger.error('[Replay] Attempting to finish replay event after session expired.'); + if (!force) { + __DEBUG_BUILD__ && logger.warn('[Replay] Attempting to finish replay event after session expired.'); + } this._refreshSession(); resolve(); },