Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ref(replay): Improve status logging #8709

Merged
merged 1 commit into from
Aug 3, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
25 changes: 15 additions & 10 deletions packages/replay/jest.setup.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}

/**
Expand All @@ -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);
Expand Down Expand Up @@ -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];

Expand Down
3 changes: 2 additions & 1 deletion packages/replay/src/eventBuffer/EventBufferProxy.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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';

Expand Down Expand Up @@ -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;
}

Expand Down
3 changes: 2 additions & 1 deletion packages/replay/src/eventBuffer/WorkerHandler.ts
Original file line number Diff line number Diff line change
@@ -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.
Expand Down Expand Up @@ -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();
}

Expand Down
8 changes: 4 additions & 4 deletions packages/replay/src/eventBuffer/index.ts
Original file line number Diff line number Diff line change
@@ -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';

Expand All @@ -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();
}
54 changes: 31 additions & 23 deletions packages/replay/src/replay.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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';
Expand Down Expand Up @@ -239,6 +240,8 @@ export class ReplayContainer implements ReplayContainerInterface {
this.recordingMode = 'buffer';
}

logInfo(`[Replay] Starting replay in ${this.recordingMode} mode`, this._options._experiments.traceInternals);

this._initializeRecording();
}

Expand All @@ -258,6 +261,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({
Expand All @@ -267,6 +272,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;
Expand All @@ -284,6 +290,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({
Expand All @@ -292,6 +300,7 @@ export class ReplayContainer implements ReplayContainerInterface {
currentSession: this.session,
sessionSampleRate: 0,
allowBuffering: true,
traceInternals: this._options._experiments.traceInternals,
});

session.previousSessionId = previousSessionId;
Expand Down Expand Up @@ -352,15 +361,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.
Expand Down Expand Up @@ -393,8 +397,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);
}

/**
Expand All @@ -404,12 +414,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);
}

/**
Expand All @@ -426,9 +438,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.
Expand Down Expand Up @@ -736,6 +746,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
Expand All @@ -752,7 +763,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;
}

Expand Down Expand Up @@ -894,7 +905,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;
}

Expand All @@ -909,7 +920,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);
Expand Down Expand Up @@ -1111,13 +1122,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;
}

Expand Down
4 changes: 0 additions & 4 deletions packages/replay/src/session/createSession.ts
Original file line number Diff line number Diff line change
@@ -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';
Expand All @@ -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);
}
Expand Down
5 changes: 4 additions & 1 deletion packages/replay/src/session/fetchSession.ts
Original file line number Diff line number Diff line change
@@ -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;
}
Expand All @@ -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;
Expand Down
12 changes: 8 additions & 4 deletions packages/replay/src/session/getSession.ts
Original file line number Diff line number Diff line change
@@ -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';
Expand All @@ -13,6 +12,8 @@ interface GetSessionParams extends SessionOptions {
* The current session (e.g. if stickySession is off)
*/
currentSession?: Session;

traceInternals?: boolean;
}

/**
Expand All @@ -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
Expand All @@ -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
}
Expand All @@ -54,6 +57,7 @@ export function getSession({
sessionSampleRate,
allowBuffering,
});
logInfo('[Replay] Created new session', traceInternals);

return { type: 'new', session: newSession };
}
Loading