From 333825cda49e3138acb5b32f5fd1c028bd292e41 Mon Sep 17 00:00:00 2001 From: Francesco Novy Date: Tue, 9 May 2023 17:07:05 +0200 Subject: [PATCH] feat(replay): Throttle breadcrumbs to max 300/5s --- .../suites/replay/throttleBreadcrumbs/init.js | 17 +++ .../replay/throttleBreadcrumbs/subject.js | 35 +++++ .../replay/throttleBreadcrumbs/template.html | 10 ++ .../suites/replay/throttleBreadcrumbs/test.ts | 115 ++++++++++++++++ packages/replay/.eslintrc.js | 4 +- .../coreHandlers/util/addBreadcrumbEvent.ts | 3 +- packages/replay/src/replay.ts | 50 ++++++- packages/replay/src/types.ts | 5 + .../replay/src/util/createPerformanceSpans.ts | 14 +- packages/replay/src/util/throttle.ts | 55 ++++++++ .../replay/test/unit/util/throttle.test.ts | 125 ++++++++++++++++++ 11 files changed, 423 insertions(+), 10 deletions(-) create mode 100644 packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/init.js create mode 100644 packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/subject.js create mode 100644 packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/template.html create mode 100644 packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts create mode 100644 packages/replay/src/util/throttle.ts create mode 100644 packages/replay/test/unit/util/throttle.test.ts diff --git a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/init.js b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/init.js new file mode 100644 index 000000000000..11207b23752d --- /dev/null +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/init.js @@ -0,0 +1,17 @@ +import * as Sentry from '@sentry/browser'; + +window.Sentry = Sentry; +window.Replay = new Sentry.Replay({ + flushMinDelay: 5000, + flushMaxDelay: 5000, + useCompression: false, +}); + +Sentry.init({ + dsn: 'https://public@dsn.ingest.sentry.io/1337', + sampleRate: 0, + replaysSessionSampleRate: 1.0, + replaysOnErrorSampleRate: 0.0, + + integrations: [window.Replay], +}); diff --git a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/subject.js b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/subject.js new file mode 100644 index 000000000000..d7ed01dd7f29 --- /dev/null +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/subject.js @@ -0,0 +1,35 @@ +window.loaded = []; +const head = document.querySelector('head'); + +const COUNT = 250; + +window.__isLoaded = () => { + return window.loaded.length === COUNT * 2; +}; + +document.querySelector('[data-network]').addEventListener('click', () => { + const offset = window.loaded.length; + + // Create many scripts + for (let i = offset; i < offset + COUNT; i++) { + const script = document.createElement('script'); + script.src = `/virtual-assets/script-${i}.js`; + script.setAttribute('crossorigin', 'anonymous'); + head.appendChild(script); + + script.addEventListener('load', () => { + window.loaded.push(`script-${i}`); + }); + } +}); + +document.querySelector('[data-fetch]').addEventListener('click', () => { + const offset = window.loaded.length; + + // Make many fetch requests + for (let i = offset; i < offset + COUNT; i++) { + fetch(`/virtual-assets/fetch-${i}.json`).then(() => { + window.loaded.push(`fetch-${i}`); + }); + } +}); diff --git a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/template.html b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/template.html new file mode 100644 index 000000000000..e045a04653fc --- /dev/null +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/template.html @@ -0,0 +1,10 @@ + + + + + + + + + + diff --git a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts new file mode 100644 index 000000000000..3f1ae9b1fb05 --- /dev/null +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts @@ -0,0 +1,115 @@ +import { expect } from '@playwright/test'; + +import { sentryTest } from '../../../utils/fixtures'; +import { getCustomRecordingEvents, shouldSkipReplayTest, waitForReplayRequest } from '../../../utils/replayHelpers'; + +const COUNT = 250; +const THROTTLE_LIMIT = 300; + +sentryTest( + 'throttles breadcrumbs when many requests are made at the same time', + async ({ getLocalTestUrl, page, forceFlushReplay }) => { + if (shouldSkipReplayTest()) { + sentryTest.skip(); + } + + const reqPromise0 = waitForReplayRequest(page, 0); + + await page.route('https://dsn.ingest.sentry.io/**/*', route => { + return route.fulfill({ + status: 200, + contentType: 'application/json', + body: JSON.stringify({ id: 'test-id' }), + }); + }); + + let scriptsLoaded = 0; + let fetchLoaded = 0; + + await page.route('**/virtual-assets/script-**', route => { + scriptsLoaded++; + return route.fulfill({ + status: 200, + contentType: 'text/javascript', + body: `const aha = ${'xx'.repeat(20_000)};`, + }); + }); + + await page.route('**/virtual-assets/fetch-**', route => { + fetchLoaded++; + return route.fulfill({ + status: 200, + contentType: 'application/json', + body: JSON.stringify({ fetchResponse: 'aa'.repeat(20_000) }), + }); + }); + + const url = await getLocalTestUrl({ testDir: __dirname }); + + await page.goto(url); + await reqPromise0; + + const reqPromise1 = waitForReplayRequest( + page, + (_event, res) => { + const { performanceSpans } = getCustomRecordingEvents(res); + + return performanceSpans.some(span => span.op === 'resource.script'); + }, + 5_000, + ); + + await page.click('[data-network]'); + await page.click('[data-fetch]'); + + await page.waitForFunction('window.__isLoaded()'); + await forceFlushReplay(); + + const { performanceSpans, breadcrumbs } = getCustomRecordingEvents(await reqPromise1); + + // All assets have been _loaded_ + expect(scriptsLoaded).toBe(COUNT); + expect(fetchLoaded).toBe(COUNT); + + // But only some have been captured by replay + // We check for <= THROTTLE_LIMIT, as there have been some captured before, which take up some of the throttle limit + expect(performanceSpans.length).toBeLessThanOrEqual(THROTTLE_LIMIT); + expect(performanceSpans.length).toBeGreaterThan(THROTTLE_LIMIT - 10); + + expect(breadcrumbs.filter(({ category }) => category === 'replay.throttled').length).toBe(1); + + // Now we wait for 6s (5s + some wiggle room), and make some requests again + await page.waitForTimeout(6_000); + await forceFlushReplay(); + + const reqPromise2 = waitForReplayRequest( + page, + (_event, res) => { + const { performanceSpans } = getCustomRecordingEvents(res); + + return performanceSpans.some(span => span.op === 'resource.script'); + }, + 5_000, + ); + + await page.click('[data-network]'); + await page.click('[data-fetch]'); + + await forceFlushReplay(); + + const { performanceSpans: performanceSpans2, breadcrumbs: breadcrumbs2 } = getCustomRecordingEvents( + await reqPromise2, + ); + + // All assets have been _loaded_ + expect(scriptsLoaded).toBe(COUNT * 2); + expect(fetchLoaded).toBe(COUNT * 2); + + // But only some have been captured by replay + // We check for <= THROTTLE_LIMIT, as there have been some captured before, which take up some of the throttle limit + expect(performanceSpans2.length).toBeLessThanOrEqual(THROTTLE_LIMIT); + expect(performanceSpans2.length).toBeGreaterThan(THROTTLE_LIMIT - 10); + + expect(breadcrumbs2.filter(({ category }) => category === 'replay.throttled').length).toBe(1); + }, +); diff --git a/packages/replay/.eslintrc.js b/packages/replay/.eslintrc.js index da006cf432a2..6db928fcb1b9 100644 --- a/packages/replay/.eslintrc.js +++ b/packages/replay/.eslintrc.js @@ -8,7 +8,9 @@ module.exports = { overrides: [ { files: ['src/**/*.ts'], - rules: {}, + rules: { + '@sentry-internal/sdk/no-unsupported-es6-methods': 'off', + }, }, { files: ['jest.setup.ts', 'jest.config.ts'], diff --git a/packages/replay/src/coreHandlers/util/addBreadcrumbEvent.ts b/packages/replay/src/coreHandlers/util/addBreadcrumbEvent.ts index cbb998d499d4..947fb12f1ae4 100644 --- a/packages/replay/src/coreHandlers/util/addBreadcrumbEvent.ts +++ b/packages/replay/src/coreHandlers/util/addBreadcrumbEvent.ts @@ -3,7 +3,6 @@ import type { Breadcrumb } from '@sentry/types'; import { normalize } from '@sentry/utils'; import type { ReplayContainer } from '../../types'; -import { addEvent } from '../../util/addEvent'; /** * Add a breadcrumb event to replay. @@ -20,7 +19,7 @@ export function addBreadcrumbEvent(replay: ReplayContainer, breadcrumb: Breadcru } replay.addUpdate(() => { - void addEvent(replay, { + void replay.throttledAddEvent({ type: EventType.Custom, // TODO: We were converting from ms to seconds for breadcrumbs, spans, // but maybe we should just keep them as milliseconds diff --git a/packages/replay/src/replay.ts b/packages/replay/src/replay.ts index 3d2fe4a6d7af..a7699823bc7e 100644 --- a/packages/replay/src/replay.ts +++ b/packages/replay/src/replay.ts @@ -23,6 +23,7 @@ import type { EventBuffer, InternalEventContext, PopEventContext, + RecordingEvent, RecordingOptions, ReplayContainer as ReplayContainerInterface, ReplayPluginOptions, @@ -41,6 +42,8 @@ import { getHandleRecordingEmit } from './util/handleRecordingEmit'; import { isExpired } from './util/isExpired'; import { isSessionExpired } from './util/isSessionExpired'; import { sendReplay } from './util/sendReplay'; +import type { SKIPPED } from './util/throttle'; +import { throttle, THROTTLED } from './util/throttle'; /** * The main replay container class, which holds all the state and methods for recording and sending replays. @@ -74,6 +77,11 @@ export class ReplayContainer implements ReplayContainerInterface { maxSessionLife: MAX_SESSION_LIFE, } as const; + private _throttledAddEvent: ( + event: RecordingEvent, + isCheckout?: boolean, + ) => typeof THROTTLED | typeof SKIPPED | Promise; + /** * Options to pass to `rrweb.record()` */ @@ -135,6 +143,14 @@ export class ReplayContainer implements ReplayContainerInterface { this._debouncedFlush = debounce(() => this._flush(), this._options.flushMinDelay, { maxWait: this._options.flushMaxDelay, }); + + this._throttledAddEvent = throttle( + (event: RecordingEvent, isCheckout?: boolean) => addEvent(this, event, isCheckout), + // Max 300 events... + 300, + // ... per 5s + 5, + ); } /** Get the event context. */ @@ -545,6 +561,38 @@ export class ReplayContainer implements ReplayContainerInterface { this._context.urls.push(url); } + /** + * Add a breadcrumb event, that may be throttled. + * If it was throttled, we add a custom breadcrumb to indicate that. + */ + public throttledAddEvent( + event: RecordingEvent, + isCheckout?: boolean, + ): typeof THROTTLED | typeof SKIPPED | Promise { + const res = this._throttledAddEvent(event, isCheckout); + + // If this is THROTTLED, it means we have throttled the event for the first time + // In this case, we want to add a breadcrumb indicating that something was skipped + if (res === THROTTLED) { + const breadcrumb = createBreadcrumb({ + category: 'replay.throttled', + }); + + this.addUpdate(() => { + void addEvent(this, { + type: EventType.Custom, + timestamp: breadcrumb.timestamp || 0, + data: { + tag: 'breadcrumb', + payload: breadcrumb, + }, + }); + }); + } + + return res; + } + /** * Initialize and start all listeners to varying events (DOM, * Performance Observer, Recording, Sentry SDK, etc) @@ -783,7 +831,7 @@ export class ReplayContainer implements ReplayContainerInterface { */ private _createCustomBreadcrumb(breadcrumb: Breadcrumb): void { this.addUpdate(() => { - void addEvent(this, { + void this.throttledAddEvent({ type: EventType.Custom, timestamp: breadcrumb.timestamp || 0, data: { diff --git a/packages/replay/src/types.ts b/packages/replay/src/types.ts index aef61f57a07a..94b601d3f05b 100644 --- a/packages/replay/src/types.ts +++ b/packages/replay/src/types.ts @@ -8,6 +8,7 @@ import type { } from '@sentry/types'; import type { eventWithTime, recordOptions } from './types/rrweb'; +import type { SKIPPED, THROTTLED } from './util/throttle'; export type RecordingEvent = eventWithTime; export type RecordingOptions = recordOptions; @@ -498,6 +499,10 @@ export interface ReplayContainer { session: Session | undefined; recordingMode: ReplayRecordingMode; timeouts: Timeouts; + throttledAddEvent: ( + event: RecordingEvent, + isCheckout?: boolean, + ) => typeof THROTTLED | typeof SKIPPED | Promise; isEnabled(): boolean; isPaused(): boolean; getContext(): InternalEventContext; diff --git a/packages/replay/src/util/createPerformanceSpans.ts b/packages/replay/src/util/createPerformanceSpans.ts index cd7a20ddf74a..86de4eb9f958 100644 --- a/packages/replay/src/util/createPerformanceSpans.ts +++ b/packages/replay/src/util/createPerformanceSpans.ts @@ -1,17 +1,16 @@ import { EventType } from '@sentry-internal/rrweb'; import type { AddEventResult, AllEntryData, ReplayContainer, ReplayPerformanceEntry } from '../types'; -import { addEvent } from './addEvent'; /** - * Create a "span" for each performance entry. The parent transaction is `this.replayEvent`. + * Create a "span" for each performance entry. */ export function createPerformanceSpans( replay: ReplayContainer, entries: ReplayPerformanceEntry[], ): Promise[] { - return entries.map(({ type, start, end, name, data }) => - addEvent(replay, { + return entries.map(({ type, start, end, name, data }) => { + const response = replay.throttledAddEvent({ type: EventType.Custom, timestamp: start, data: { @@ -24,6 +23,9 @@ export function createPerformanceSpans( data, }, }, - }), - ); + }); + + // If response is a string, it means its either THROTTLED or SKIPPED + return typeof response === 'string' ? Promise.resolve(null) : response; + }); } diff --git a/packages/replay/src/util/throttle.ts b/packages/replay/src/util/throttle.ts new file mode 100644 index 000000000000..66ce6ed0cdfb --- /dev/null +++ b/packages/replay/src/util/throttle.ts @@ -0,0 +1,55 @@ +export const THROTTLED = '__THROTTLED'; +export const SKIPPED = '__SKIPPED'; + +/** + * Create a throttled function off a given function. + * When calling the throttled function, it will call the original function only + * if it hasn't been called more than `maxCount` times in the last `durationSeconds`. + * + * Returns `THROTTLED` if throttled for the first time, after that `SKIPPED`, + * or else the return value of the original function. + */ +// eslint-disable-next-line @typescript-eslint/no-explicit-any +export function throttle any>( + fn: T, + maxCount: number, + durationSeconds: number, +): (...rest: Parameters) => ReturnType | typeof THROTTLED | typeof SKIPPED { + const counter = new Map(); + + const _cleanup = (now: number): void => { + const threshold = now - durationSeconds; + counter.forEach((_value, key) => { + if (key < threshold) { + counter.delete(key); + } + }); + }; + + const _getTotalCount = (): number => { + return [...counter.values()].reduce((a, b) => a + b, 0); + }; + + let isThrottled = false; + + return (...rest: Parameters): ReturnType | typeof THROTTLED | typeof SKIPPED => { + // Date in second-precision, which we use as basis for the throttling + const now = Math.floor(Date.now() / 1000); + + // First, make sure to delete any old entries + _cleanup(now); + + // If already over limit, do nothing + if (_getTotalCount() >= maxCount) { + const wasThrottled = isThrottled; + isThrottled = true; + return wasThrottled ? SKIPPED : THROTTLED; + } + + isThrottled = false; + const count = counter.get(now) || 0; + counter.set(now, count + 1); + + return fn(...rest); + }; +} diff --git a/packages/replay/test/unit/util/throttle.test.ts b/packages/replay/test/unit/util/throttle.test.ts new file mode 100644 index 000000000000..4f1c0bc9f6a2 --- /dev/null +++ b/packages/replay/test/unit/util/throttle.test.ts @@ -0,0 +1,125 @@ +import { BASE_TIMESTAMP } from '../..'; +import { SKIPPED, throttle, THROTTLED } from '../../../src/util/throttle'; + +jest.useFakeTimers(); + +describe('Unit | util | throttle', () => { + it('executes when not hitting the limit', () => { + const now = BASE_TIMESTAMP; + jest.setSystemTime(now); + + const callback = jest.fn(); + const fn = throttle(callback, 100, 60); + + fn(); + fn(); + fn(); + + expect(callback).toHaveBeenCalledTimes(3); + + jest.advanceTimersByTime(59_000); + + fn(); + fn(); + + expect(callback).toHaveBeenCalledTimes(5); + + jest.advanceTimersByTime(1_000); + + fn(); + + expect(callback).toHaveBeenCalledTimes(6); + + jest.advanceTimersByTime(1_000); + + fn(); + + expect(callback).toHaveBeenCalledTimes(7); + }); + + it('stops executing when hitting the limit', () => { + const now = BASE_TIMESTAMP; + jest.setSystemTime(now); + const callback = jest.fn(); + const fn = throttle(callback, 5, 60); + + fn(); + fn(); + fn(); + + expect(callback).toHaveBeenCalledTimes(3); + + jest.advanceTimersByTime(59_000); + + fn(); + fn(); + + expect(callback).toHaveBeenCalledTimes(5); + + jest.advanceTimersByTime(1_000); + + fn(); + fn(); + fn(); + fn(); + + expect(callback).toHaveBeenCalledTimes(5); + + // Now, the first three will "expire", so we can add three more + jest.advanceTimersByTime(1_000); + + fn(); + fn(); + fn(); + fn(); + + expect(callback).toHaveBeenCalledTimes(8); + }); + + it('has correct return value', () => { + const now = BASE_TIMESTAMP; + jest.setSystemTime(now); + + const callback = jest.fn(() => 'foo'); + const fn = throttle(callback, 5, 60); + + expect(fn()).toBe('foo'); + expect(fn()).toBe('foo'); + expect(fn()).toBe('foo'); + expect(fn()).toBe('foo'); + expect(fn()).toBe('foo'); + expect(fn()).toBe(THROTTLED); + expect(fn()).toBe(SKIPPED); + expect(fn()).toBe(SKIPPED); + + // After 61s, should be reset + jest.advanceTimersByTime(61_000); + + expect(fn()).toBe('foo'); + expect(fn()).toBe('foo'); + expect(fn()).toBe('foo'); + expect(fn()).toBe('foo'); + expect(fn()).toBe('foo'); + expect(fn()).toBe(THROTTLED); + expect(fn()).toBe(SKIPPED); + expect(fn()).toBe(SKIPPED); + }); + + it('passes args correctly', () => { + const now = BASE_TIMESTAMP; + jest.setSystemTime(now); + + const originalFunction = (a: number, b: number) => a + b; + const callback = jest.fn(originalFunction); + const fn = throttle(callback, 5, 60); + + expect(fn(1, 2)).toBe(3); + expect(fn(1, 2)).toBe(3); + expect(fn(1, 2)).toBe(3); + expect(fn(1, 2)).toBe(3); + expect(fn(1, 2)).toBe(3); + expect(fn(1, 2)).toBe(THROTTLED); + expect(fn(1, 2)).toBe(SKIPPED); + expect(fn(1, 2)).toBe(SKIPPED); + }); +});