Skip to content

ref(replay): Skip events being added too long after initial segment #8768

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

Merged
merged 1 commit into from
Aug 9, 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
10 changes: 10 additions & 0 deletions packages/replay/src/util/addEvent.ts
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ import { logger } from '@sentry/utils';

import { EventBufferSizeExceededError } from '../eventBuffer/error';
import type { AddEventResult, RecordingEvent, ReplayContainer, ReplayFrameEvent, ReplayPluginOptions } from '../types';
import { logInfo } from './log';
import { timestampToMs } from './timestamp';

function isCustomEvent(event: RecordingEvent): event is ReplayFrameEvent {
Expand Down Expand Up @@ -39,6 +40,15 @@ export async function addEvent(
return null;
}

// Throw out events that are +60min from the initial timestamp
if (timestampInMs > replay.getContext().initialTimestamp + replay.timeouts.maxSessionLife) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Will conflict with #8769

logInfo(
`[Replay] Skipping event with timestamp ${timestampInMs} because it is after maxSessionLife`,
replay.getOptions()._experiments.traceInternals,
);
return null;
}

try {
if (isCheckout && replay.recordingMode === 'buffer') {
replay.eventBuffer.clear();
Expand Down
44 changes: 44 additions & 0 deletions packages/replay/test/integration/errorSampleRate.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -883,6 +883,50 @@ describe('Integration | errorSampleRate', () => {
expect(mockRecord.takeFullSnapshot).toHaveBeenCalledTimes(0);
expect(replay.isEnabled()).toBe(false);
});

it('handles very long active buffer session', async () => {
const stepDuration = 10_000;
const steps = 5_000;

jest.setSystemTime(BASE_TIMESTAMP);

expect(replay).not.toHaveLastSentReplay();

let optionsEvent = createOptionsEvent(replay);

for (let i = 1; i <= steps; i++) {
jest.advanceTimersByTime(stepDuration);
optionsEvent = createOptionsEvent(replay);
mockRecord._emitter({ data: { step: i }, timestamp: BASE_TIMESTAMP + stepDuration * i, type: 2 }, true);
mockRecord._emitter({ data: { step: i }, timestamp: BASE_TIMESTAMP + stepDuration * i + 5, type: 3 });
}

expect(replay).not.toHaveLastSentReplay();

expect(replay.isEnabled()).toBe(true);
expect(replay.isPaused()).toBe(false);
expect(replay.recordingMode).toBe('buffer');

// Now capture an error
captureException(new Error('testing'));
await waitForBufferFlush();

expect(replay).toHaveLastSentReplay({
recordingData: JSON.stringify([
{ data: { step: steps }, timestamp: BASE_TIMESTAMP + stepDuration * steps, type: 2 },
optionsEvent,
{ data: { step: steps }, timestamp: BASE_TIMESTAMP + stepDuration * steps + 5, type: 3 },
]),
replayEventPayload: expect.objectContaining({
replay_start_timestamp: (BASE_TIMESTAMP + stepDuration * steps) / 1000,
error_ids: [expect.any(String)],
trace_ids: [],
urls: ['http://localhost/'],
replay_id: expect.any(String),
}),
recordingPayloadHeader: { segment_id: 0 },
});
});
});

/**
Expand Down
60 changes: 60 additions & 0 deletions packages/replay/test/integration/flush.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@ type MockFlush = jest.MockedFunction<ReplayContainer['_flush']>;
type MockRunFlush = jest.MockedFunction<ReplayContainer['_runFlush']>;

const prevLocation = WINDOW.location;
const prevBrowserPerformanceTimeOrigin = SentryUtils.browserPerformanceTimeOrigin;

describe('Integration | flush', () => {
let domHandler: (args: any) => any;
Expand Down Expand Up @@ -91,6 +92,11 @@ describe('Integration | flush', () => {
}
mockEventBufferFinish = replay.eventBuffer?.finish as MockEventBufferFinish;
mockEventBufferFinish.mockClear();

Object.defineProperty(SentryUtils, 'browserPerformanceTimeOrigin', {
value: BASE_TIMESTAMP,
writable: true,
});
});

afterEach(async () => {
Expand All @@ -102,6 +108,10 @@ describe('Integration | flush', () => {
value: prevLocation,
writable: true,
});
Object.defineProperty(SentryUtils, 'browserPerformanceTimeOrigin', {
value: prevBrowserPerformanceTimeOrigin,
writable: true,
});
});

afterAll(() => {
Expand Down Expand Up @@ -224,6 +234,7 @@ describe('Integration | flush', () => {
// flush #5 @ t=25s - debounced flush calls `flush`
// 20s + `flushMinDelay` which is 5 seconds
await advanceTimers(DEFAULT_FLUSH_MIN_DELAY);

expect(mockFlush).toHaveBeenCalledTimes(5);
expect(mockRunFlush).toHaveBeenCalledTimes(2);
expect(mockSendReplay).toHaveBeenLastCalledWith({
Expand Down Expand Up @@ -382,4 +393,53 @@ describe('Integration | flush', () => {

replay.getOptions()._experiments.traceInternals = false;
});

it('logs warning if adding event that is after maxSessionLife', async () => {
replay.getOptions()._experiments.traceInternals = true;

sessionStorage.clear();
clearSession(replay);
replay['_loadAndCheckSession']();
await new Promise(process.nextTick);
jest.setSystemTime(BASE_TIMESTAMP);

replay.eventBuffer!.clear();

// We do not care about this warning here
replay.eventBuffer!.hasCheckout = true;

// Add event that is too long after session start
const TEST_EVENT = { data: {}, timestamp: BASE_TIMESTAMP + MAX_SESSION_LIFE + 100, type: 2 };
mockRecord._emitter(TEST_EVENT);

// no checkout!
await advanceTimers(DEFAULT_FLUSH_MIN_DELAY);

expect(mockFlush).toHaveBeenCalledTimes(1);
expect(mockSendReplay).toHaveBeenCalledTimes(1);

const replayData = mockSendReplay.mock.calls[0][0];

expect(JSON.parse(replayData.recordingData)).toEqual([
{
type: 5,
timestamp: BASE_TIMESTAMP,
data: {
tag: 'breadcrumb',
payload: {
timestamp: BASE_TIMESTAMP / 1000,
type: 'default',
category: 'console',
data: { logger: 'replay' },
level: 'info',
message: `[Replay] Skipping event with timestamp ${
BASE_TIMESTAMP + MAX_SESSION_LIFE + 100
} because it is after maxSessionLife`,
},
},
},
]);

replay.getOptions()._experiments.traceInternals = false;
});
});