From d7af0a9d4fc02d354f65f2b7425a6deeade4916a Mon Sep 17 00:00:00 2001 From: Billy Vong Date: Wed, 9 Oct 2024 12:47:41 -0400 Subject: [PATCH 1/3] debug(replay): Add debugging statements around event buffer This is not intended to be merged to prod, I would like to debug how/why we keep hitting EventBuffer limits on Sentry SaaS. Aside from debugging statements, there should be no other behavioral changes. --- .../EventBufferCompressionWorker.ts | 18 ++++- .../src/eventBuffer/EventBufferProxy.ts | 1 + packages/replay-internal/src/replay.ts | 72 ++++++++++++++----- .../src/util/handleRecordingEmit.ts | 13 +++- 4 files changed, 80 insertions(+), 24 deletions(-) diff --git a/packages/replay-internal/src/eventBuffer/EventBufferCompressionWorker.ts b/packages/replay-internal/src/eventBuffer/EventBufferCompressionWorker.ts index 90a54bbf07f3..246467180cdc 100644 --- a/packages/replay-internal/src/eventBuffer/EventBufferCompressionWorker.ts +++ b/packages/replay-internal/src/eventBuffer/EventBufferCompressionWorker.ts @@ -67,6 +67,12 @@ export class EventBufferCompressionWorker implements EventBuffer { this._totalSize += data.length; if (this._totalSize > REPLAY_MAX_EVENT_BUFFER_SIZE) { + DEBUG_BUILD && + logger.info( + `Cannot add new event with raw size of ${data.length} to existing buffer of size ${ + this._totalSize - data.length + }`, + ); return Promise.reject(new EventBufferSizeExceededError()); } @@ -82,14 +88,20 @@ export class EventBufferCompressionWorker implements EventBuffer { /** @inheritdoc */ public clear(): void { + DEBUG_BUILD && logger.info(`Clearing event buffer (${this._totalSize})`); this._earliestTimestamp = null; this._totalSize = 0; this.hasCheckout = false; // We do not wait on this, as we assume the order of messages is consistent for the worker - this._worker.postMessage('clear').then(null, e => { - DEBUG_BUILD && logger.exception(e, 'Sending "clear" message to worker failed', e); - }); + this._worker.postMessage('clear').then( + () => { + DEBUG_BUILD && logger.info('Event buffer cleared within worker'); + }, + e => { + DEBUG_BUILD && logger.exception(e, 'Sending "clear" message to worker failed', e); + }, + ); } /** @inheritdoc */ diff --git a/packages/replay-internal/src/eventBuffer/EventBufferProxy.ts b/packages/replay-internal/src/eventBuffer/EventBufferProxy.ts index ea81365b66a9..b311e2152a3d 100644 --- a/packages/replay-internal/src/eventBuffer/EventBufferProxy.ts +++ b/packages/replay-internal/src/eventBuffer/EventBufferProxy.ts @@ -115,6 +115,7 @@ export class EventBufferProxy implements EventBuffer { // Wait for original events to be re-added before resolving try { await Promise.all(addEventPromises); + DEBUG_BUILD && logger.info('Finished switching to compression worker'); // Can now clear fallback buffer as it's no longer necessary this._fallback.clear(); diff --git a/packages/replay-internal/src/replay.ts b/packages/replay-internal/src/replay.ts index 563938fe4d43..8c5090dfb84b 100644 --- a/packages/replay-internal/src/replay.ts +++ b/packages/replay-internal/src/replay.ts @@ -1,6 +1,13 @@ /* eslint-disable max-lines */ // TODO: We might want to split this file up import { EventType, record } from '@sentry-internal/rrweb'; -import { SEMANTIC_ATTRIBUTE_SENTRY_SOURCE, getActiveSpan, getClient, getRootSpan, spanToJSON } from '@sentry/core'; +import { + SEMANTIC_ATTRIBUTE_SENTRY_SOURCE, + getActiveSpan, + getClient, + getRootSpan, + setTag, + spanToJSON, +} from '@sentry/core'; import type { ReplayRecordingMode, Span } from '@sentry/types'; import { logger } from './util/logger'; @@ -1215,28 +1222,14 @@ export class ReplayContainer implements ReplayContainerInterface { return; } - const start = this.session.started; - const now = Date.now(); - const duration = now - start; - // A flush is about to happen, cancel any queued flushes this._debouncedFlush.cancel(); - // If session is too short, or too long (allow some wiggle room over maxReplayDuration), do not send it - // This _should_ not happen, but it may happen if flush is triggered due to a page activity change or similar - const tooShort = duration < this._options.minReplayDuration; - const tooLong = duration > this._options.maxReplayDuration + 5_000; - if (tooShort || tooLong) { - DEBUG_BUILD && - logger.info( - `Session duration (${Math.floor(duration / 1000)}s) is too ${ - tooShort ? 'short' : 'long' - }, not sending replay.`, - ); + const isValidDuration = this._checkReplayDurationDuringFlush(); - if (tooShort) { - this._debouncedFlush(); - } + // XXX: disregard durations for buffer mode for debug purposes + if (!isValidDuration && this.recordingMode !== 'buffer') { + DEBUG_BUILD && logger.info('Invalid duration while buffering'); return; } @@ -1272,6 +1265,47 @@ export class ReplayContainer implements ReplayContainerInterface { } }; + /** + * Checks to see if replay duration is within bounds during a flush. If it is + * too short, will queue up a new flush to prevent short replays. + * + * Returns true if duration is ok, false otherwise + */ + private _checkReplayDurationDuringFlush(): boolean { + if (!this.session) { + return false; + } + + const start = this.session.started; + const now = Date.now(); + const duration = now - start; + + // If session is too short, or too long (allow some wiggle room over maxReplayDuration), do not send it + // This _should_ not happen, but it may happen if flush is triggered due to a page activity change or similar + const tooShort = duration < this._options.minReplayDuration; + const tooLong = duration > this._options.maxReplayDuration + 5_000; + if (tooShort || tooLong) { + DEBUG_BUILD && + logger.info( + `Session duration (${Math.floor(duration / 1000)}s) is too ${ + tooShort ? 'short' : 'long' + }, not sending replay.`, + ); + + if (tooShort) { + this._debouncedFlush(); + } + + // XXX: disregard durations for buffer mode for debug purposes + if (this.recordingMode === 'buffer') { + setTag(`replay.${tooShort ? 'tooShort' : 'tooLong'}`, true); + } + return false; + } + + return true; + } + /** Save the session, if it is sticky */ private _maybeSaveSession(): void { if (this.session && this._options.stickySession) { diff --git a/packages/replay-internal/src/util/handleRecordingEmit.ts b/packages/replay-internal/src/util/handleRecordingEmit.ts index 4f4637276116..6d320fd1a8b8 100644 --- a/packages/replay-internal/src/util/handleRecordingEmit.ts +++ b/packages/replay-internal/src/util/handleRecordingEmit.ts @@ -43,6 +43,7 @@ export function getHandleRecordingEmit(replay: ReplayContainer): RecordingEmitCa // dependent on this reset. if (replay.recordingMode === 'buffer' && isCheckout) { replay.setInitialState(); + DEBUG_BUILD && logger.info(`Adding checkout event while in buffer mode (${JSON.stringify(event).length})`); } // If the event is not added (e.g. due to being paused, disabled, or out of the max replay duration), @@ -73,8 +74,13 @@ export function getHandleRecordingEmit(replay: ReplayContainer): RecordingEmitCa // When in buffer mode, make sure we adjust the session started date to the current earliest event of the buffer // this should usually be the timestamp of the checkout event, but to be safe... - if (replay.recordingMode === 'buffer' && session && replay.eventBuffer) { - const earliestEvent = replay.eventBuffer.getEarliestTimestamp(); + if (replay.recordingMode === 'buffer' && session) { + DEBUG_BUILD && + replay.eventBuffer && + logger.info('Attempting to fetch earliest event from event buffer type: ', replay.eventBuffer.type); + + const earliestEvent = replay.eventBuffer && replay.eventBuffer.getEarliestTimestamp(); + if (earliestEvent) { DEBUG_BUILD && logger.info(`Updating session start time to earliest event in buffer to ${new Date(earliestEvent)}`); @@ -84,6 +90,9 @@ export function getHandleRecordingEmit(replay: ReplayContainer): RecordingEmitCa if (replay.getOptions().stickySession) { saveSession(session); } + } else { + // XXX(billy): debugging + DEBUG_BUILD && logger.warn('Unable to find earliest event in event buffer'); } } From 5964c0f77fa7722d62bb5479426153571e1cb226 Mon Sep 17 00:00:00 2001 From: Billy Vong Date: Thu, 17 Oct 2024 17:05:19 -0400 Subject: [PATCH 2/3] Update packages/replay-internal/src/util/handleRecordingEmit.ts Co-authored-by: Catherine Lee <55311782+c298lee@users.noreply.github.com> --- packages/replay-internal/src/util/handleRecordingEmit.ts | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/packages/replay-internal/src/util/handleRecordingEmit.ts b/packages/replay-internal/src/util/handleRecordingEmit.ts index 6d320fd1a8b8..d5aa5826c9f4 100644 --- a/packages/replay-internal/src/util/handleRecordingEmit.ts +++ b/packages/replay-internal/src/util/handleRecordingEmit.ts @@ -74,12 +74,11 @@ export function getHandleRecordingEmit(replay: ReplayContainer): RecordingEmitCa // When in buffer mode, make sure we adjust the session started date to the current earliest event of the buffer // this should usually be the timestamp of the checkout event, but to be safe... - if (replay.recordingMode === 'buffer' && session) { + if (replay.recordingMode === 'buffer' && session && replay.eventBuffer) { DEBUG_BUILD && - replay.eventBuffer && logger.info('Attempting to fetch earliest event from event buffer type: ', replay.eventBuffer.type); - const earliestEvent = replay.eventBuffer && replay.eventBuffer.getEarliestTimestamp(); + const earliestEvent = replay.eventBuffer.getEarliestTimestamp(); if (earliestEvent) { DEBUG_BUILD && From 08cb6e74ccdf9a3dc6c7045a68bd18c4ddfd79f8 Mon Sep 17 00:00:00 2001 From: Billy Vong Date: Thu, 17 Oct 2024 17:06:10 -0400 Subject: [PATCH 3/3] size limit :( --- .size-limit.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.size-limit.js b/.size-limit.js index a244ccb2a2a3..a568c3e85539 100644 --- a/.size-limit.js +++ b/.size-limit.js @@ -79,7 +79,7 @@ module.exports = [ path: 'packages/browser/build/npm/esm/index.js', import: createImport('init', 'browserTracingIntegration', 'replayIntegration', 'replayCanvasIntegration'), gzip: true, - limit: '78 KB', + limit: '80 KB', }, { name: '@sentry/browser (incl. Tracing, Replay, Feedback)',