ref(replay): Improve status logging (#8709)

This streamlines & improves logging for replay status, adding more logs
for certain things to be better able to see what's going on, and
adapting the `traceInternals` setting to result in console breadcrumbs
being added (which should show up both in replay and for e.g. sentry
errors etc).

While at it I also fixed some `any` eslint warnings in replay.

ref: #8400

Author: mydea

packages/replay/jest.setup.ts

@@ -129,21 +129,24 @@ function checkCallForSentReplay(
 }
 
 /**
-* Only want calls that send replay events, i.e. ignore error events
-*/
+ * Only want calls that send replay events, i.e. ignore error events
+ */
+// eslint-disable-next-line @typescript-eslint/no-explicit-any
 function getReplayCalls(calls: any[][][]): any[][][] {
-  return calls.map(call => {
-    const arg = call[0];
+  return calls
+    .map(call => {
+      const arg = call[0];
       if (arg.length !== 2) {
         return [];
       }
 
-      if (!arg[1][0].find(({type}: {type: string}) => ['replay_event', 'replay_recording'].includes(type))) {
+      if (!arg[1][0].find(({ type }: { type: string }) => ['replay_event', 'replay_recording'].includes(type))) {
         return [];
       }
 
-      return [ arg ];
-  }).filter(Boolean);
+      return [arg];
+    })
+    .filter(Boolean);
 }
 
 /**
@@ -159,9 +162,11 @@ const toHaveSentReplay = function (
 
   let result: CheckCallForSentReplayResult;
 
-  const expectedKeysLength = expected ? ('sample' in expected ? Object.keys(expected.sample) : Object.keys(expected)).length : 0;
+  const expectedKeysLength = expected
+    ? ('sample' in expected ? Object.keys(expected.sample) : Object.keys(expected)).length
+    : 0;
 
-  const replayCalls = getReplayCalls(calls)
+  const replayCalls = getReplayCalls(calls);
 
   for (const currentCall of replayCalls) {
     result = checkCallForSentReplay.call(this, currentCall[0], expected);
@@ -213,7 +218,7 @@ const toHaveLastSentReplay = function (
   expected?: SentReplayExpected | { sample: SentReplayExpected; inverse: boolean },
 ) {
   const { calls } = (getCurrentHub().getClient()?.getTransport()?.send as MockTransport).mock;
-  const replayCalls = getReplayCalls(calls)
+  const replayCalls = getReplayCalls(calls);
 
   const lastCall = replayCalls[calls.length - 1]?.[0];
 

packages/replay/src/eventBuffer/EventBufferProxy.ts

@@ -2,6 +2,7 @@ import type { ReplayRecordingData } from '@sentry/types';
 import { logger } from '@sentry/utils';
 
 import type { AddEventResult, EventBuffer, EventBufferType, RecordingEvent } from '../types';
+import { logInfo } from '../util/log';
 import { EventBufferArray } from './EventBufferArray';
 import { EventBufferCompressionWorker } from './EventBufferCompressionWorker';
 
@@ -79,7 +80,7 @@ export class EventBufferProxy implements EventBuffer {
     } catch (error) {
       // If the worker fails to load, we fall back to the simple buffer.
       // Nothing more to do from our side here
-      __DEBUG_BUILD__ && logger.log('[Replay] Failed to load the compression worker, falling back to simple buffer');
+      logInfo('[Replay] Failed to load the compression worker, falling back to simple buffer');
       return;
     }
 

packages/replay/src/eventBuffer/WorkerHandler.ts

@@ -1,6 +1,7 @@
 import { logger } from '@sentry/utils';
 
 import type { WorkerRequest, WorkerResponse } from '../types';
+import { logInfo } from '../util/log';
 
 /**
  * Event buffer that uses a web worker to compress events.
@@ -55,7 +56,7 @@ export class WorkerHandler {
    * Destroy the worker.
    */
   public destroy(): void {
-    __DEBUG_BUILD__ && logger.log('[Replay] Destroying compression worker');
+    logInfo('[Replay] Destroying compression worker');
     this._worker.terminate();
   }
 

packages/replay/src/eventBuffer/index.ts

@@ -1,7 +1,7 @@
 import { getWorkerURL } from '@sentry-internal/replay-worker';
-import { logger } from '@sentry/utils';
 
 import type { EventBuffer } from '../types';
+import { logInfo } from '../util/log';
 import { EventBufferArray } from './EventBufferArray';
 import { EventBufferProxy } from './EventBufferProxy';
 
@@ -18,15 +18,15 @@ export function createEventBuffer({ useCompression }: CreateEventBufferParams):
     try {
       const workerUrl = getWorkerURL();
 
-      __DEBUG_BUILD__ && logger.log('[Replay] Using compression worker');
+      logInfo('[Replay] Using compression worker');
       const worker = new Worker(workerUrl);
       return new EventBufferProxy(worker);
     } catch (error) {
-      __DEBUG_BUILD__ && logger.log('[Replay] Failed to create compression worker');
+      logInfo('[Replay] Failed to create compression worker');
       // Fall back to use simple event buffer array
     }
   }
 
-  __DEBUG_BUILD__ && logger.log('[Replay] Using simple buffer');
+  logInfo('[Replay] Using simple buffer');
   return new EventBufferArray();
 }

packages/replay/src/replay.ts

@@ -47,6 +47,7 @@ import { debounce } from './util/debounce';
 import { getHandleRecordingEmit } from './util/handleRecordingEmit';
 import { isExpired } from './util/isExpired';
 import { isSessionExpired } from './util/isSessionExpired';
+import { logInfo } from './util/log';
 import { sendReplay } from './util/sendReplay';
 import type { SKIPPED } from './util/throttle';
 import { throttle, THROTTLED } from './util/throttle';
@@ -249,6 +250,8 @@ export class ReplayContainer implements ReplayContainerInterface {
       this.recordingMode = 'buffer';
     }
 
+    logInfo(`[Replay] Starting replay in ${this.recordingMode} mode`, this._options._experiments.traceInternals);
+
     this._initializeRecording();
   }
 
@@ -268,6 +271,8 @@ export class ReplayContainer implements ReplayContainerInterface {
       throw new Error('Replay buffering is in progress, call `flush()` to save the replay');
     }
 
+    logInfo('[Replay] Starting replay in session mode', this._options._experiments.traceInternals);
+
     const previousSessionId = this.session && this.session.id;
 
     const { session } = getSession({
@@ -277,6 +282,7 @@ export class ReplayContainer implements ReplayContainerInterface {
       // This is intentional: create a new session-based replay when calling `start()`
       sessionSampleRate: 1,
       allowBuffering: false,
+      traceInternals: this._options._experiments.traceInternals,
     });
 
     session.previousSessionId = previousSessionId;
@@ -294,6 +300,8 @@ export class ReplayContainer implements ReplayContainerInterface {
       throw new Error('Replay recording is already in progress');
     }
 
+    logInfo('[Replay] Starting replay in buffer mode', this._options._experiments.traceInternals);
+
     const previousSessionId = this.session && this.session.id;
 
     const { session } = getSession({
@@ -302,6 +310,7 @@ export class ReplayContainer implements ReplayContainerInterface {
       currentSession: this.session,
       sessionSampleRate: 0,
       allowBuffering: true,
+      traceInternals: this._options._experiments.traceInternals,
     });
 
     session.previousSessionId = previousSessionId;
@@ -362,15 +371,10 @@ export class ReplayContainer implements ReplayContainerInterface {
     }
 
     try {
-      if (__DEBUG_BUILD__) {
-        const msg = `[Replay] Stopping Replay${reason ? ` triggered by ${reason}` : ''}`;
-
-        // 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(msg);
-      }
+      logInfo(
+        `[Replay] Stopping Replay${reason ? ` triggered by ${reason}` : ''}`,
+        this._options._experiments.traceInternals,
+      );
 
       // We can't move `_isEnabled` after awaiting a flush, otherwise we can
       // enter into an infinite loop when `stop()` is called while flushing.
@@ -403,8 +407,14 @@ export class ReplayContainer implements ReplayContainerInterface {
    * not as thorough of a shutdown as `stop()`.
    */
   public pause(): void {
+    if (this._isPaused) {
+      return;
+    }
+
     this._isPaused = true;
     this.stopRecording();
+
+    logInfo('[Replay] Pausing replay', this._options._experiments.traceInternals);
   }
 
   /**
@@ -414,12 +424,14 @@ export class ReplayContainer implements ReplayContainerInterface {
    * new DOM checkout.`
    */
   public resume(): void {
-    if (!this._loadAndCheckSession()) {
+    if (!this._isPaused || !this._loadAndCheckSession()) {
       return;
     }
 
     this._isPaused = false;
     this.startRecording();
+
+    logInfo('[Replay] Resuming replay', this._options._experiments.traceInternals);
   }
 
   /**
@@ -436,9 +448,7 @@ export class ReplayContainer implements ReplayContainerInterface {
 
     const activityTime = Date.now();
 
-    // eslint-disable-next-line no-console
-    const log = this.getOptions()._experiments.traceInternals ? console.info : logger.info;
-    __DEBUG_BUILD__ && log(`[Replay] Converting buffer to session, starting at ${activityTime}`);
+    logInfo('[Replay] Converting buffer to session', this._options._experiments.traceInternals);
 
     // Allow flush to complete before resuming as a session recording, otherwise
     // the checkout from `startRecording` may be included in the payload.
@@ -746,6 +756,7 @@ export class ReplayContainer implements ReplayContainerInterface {
       currentSession: this.session,
       sessionSampleRate: this._options.sessionSampleRate,
       allowBuffering: this._options.errorSampleRate > 0 || this.recordingMode === 'buffer',
+      traceInternals: this._options._experiments.traceInternals,
     });
 
     // If session was newly created (i.e. was not loaded from storage), then
@@ -762,7 +773,7 @@ export class ReplayContainer implements ReplayContainerInterface {
     this.session = session;
 
     if (!this.session.sampled) {
-      void this.stop('session unsampled');
+      void this.stop('session not refreshed');
       return false;
     }
 
@@ -904,7 +915,7 @@ export class ReplayContainer implements ReplayContainerInterface {
       // If the user has come back to the page within SESSION_IDLE_PAUSE_DURATION
       // ms, we will re-use the existing session, otherwise create a new
       // session
-      __DEBUG_BUILD__ && logger.log('[Replay] Document has become active, but session has expired');
+      logInfo('[Replay] Document has become active, but session has expired');
       return;
     }
 
@@ -919,7 +930,7 @@ export class ReplayContainer implements ReplayContainerInterface {
    */
   private _triggerFullSnapshot(checkout = true): void {
     try {
-      __DEBUG_BUILD__ && logger.log('[Replay] Taking full rrweb snapshot');
+      logInfo('[Replay] Taking full rrweb snapshot');
       record.takeFullSnapshot(checkout);
     } catch (err) {
       this._handleException(err);
@@ -1121,13 +1132,10 @@ export class ReplayContainer implements ReplayContainerInterface {
     // If session is too short, or too long (allow some wiggle room over maxSessionLife), do not send it
     // This _should_ not happen, but it may happen if flush is triggered due to a page activity change or similar
     if (duration < this._options.minReplayDuration || duration > this.timeouts.maxSessionLife + 5_000) {
-      // eslint-disable-next-line no-console
-      const log = this.getOptions()._experiments.traceInternals ? console.warn : logger.warn;
-      __DEBUG_BUILD__ &&
-        log(
-          `[Replay] Session duration (${Math.floor(duration / 1000)}s) is too short or too long, not sending replay.`,
-        );
-
+      logInfo(
+        `[Replay] Session duration (${Math.floor(duration / 1000)}s) is too short or too long, not sending replay.`,
+        this._options._experiments.traceInternals,
+      );
       return;
     }
 

packages/replay/src/session/createSession.ts

@@ -1,5 +1,3 @@
-import { logger } from '@sentry/utils';
-
 import type { Sampled, Session, SessionOptions } from '../types';
 import { isSampled } from '../util/isSampled';
 import { saveSession } from './saveSession';
@@ -23,8 +21,6 @@ export function createSession({ sessionSampleRate, allowBuffering, stickySession
     sampled,
   });
 
-  __DEBUG_BUILD__ && logger.log(`[Replay] Creating new session: ${session.id}`);
-
   if (stickySession) {
     saveSession(session);
   }

packages/replay/src/session/fetchSession.ts

@@ -1,12 +1,13 @@
 import { REPLAY_SESSION_KEY, WINDOW } from '../constants';
 import type { Session } from '../types';
 import { hasSessionStorage } from '../util/hasSessionStorage';
+import { logInfo } from '../util/log';
 import { makeSession } from './Session';
 
 /**
  * Fetches a session from storage
  */
-export function fetchSession(): Session | null {
+export function fetchSession(traceInternals?: boolean): Session | null {
   if (!hasSessionStorage()) {
     return null;
   }
@@ -21,6 +22,8 @@ export function fetchSession(): Session | null {
 
     const sessionObj = JSON.parse(sessionStringFromStorage) as Session;
 
+    logInfo('[Replay] Loading existing session', traceInternals);
+
     return makeSession(sessionObj);
   } catch {
     return null;

packages/replay/src/session/getSession.ts

@@ -1,7 +1,6 @@
-import { logger } from '@sentry/utils';
-
 import type { Session, SessionOptions, Timeouts } from '../types';
 import { isSessionExpired } from '../util/isSessionExpired';
+import { logInfo } from '../util/log';
 import { createSession } from './createSession';
 import { fetchSession } from './fetchSession';
 import { makeSession } from './Session';
@@ -13,6 +12,8 @@ interface GetSessionParams extends SessionOptions {
    * The current session (e.g. if stickySession is off)
    */
   currentSession?: Session;
+
+  traceInternals?: boolean;
 }
 
 /**
@@ -24,9 +25,10 @@ export function getSession({
   stickySession,
   sessionSampleRate,
   allowBuffering,
+  traceInternals,
 }: GetSessionParams): { type: 'new' | 'saved'; session: Session } {
   // If session exists and is passed, use it instead of always hitting session storage
-  const session = currentSession || (stickySession && fetchSession());
+  const session = currentSession || (stickySession && fetchSession(traceInternals));
 
   if (session) {
     // If there is a session, check if it is valid (e.g. "last activity" time
@@ -42,9 +44,10 @@ export function getSession({
       // and when this session is expired, it will not be renewed until user
       // reloads.
       const discardedSession = makeSession({ sampled: false });
+      logInfo('[Replay] Session should not be refreshed', traceInternals);
       return { type: 'new', session: discardedSession };
     } else {
-      __DEBUG_BUILD__ && logger.log('[Replay] Session has expired');
+      logInfo('[Replay] Session has expired', traceInternals);
     }
     // Otherwise continue to create a new session
   }
@@ -54,6 +57,7 @@ export function getSession({
     sessionSampleRate,
     allowBuffering,
   });
+  logInfo('[Replay] Created new session', traceInternals);
 
   return { type: 'new', session: newSession };
 }