From e98a356f24ae1fb78a2c9f341885498f1fb0be99 Mon Sep 17 00:00:00 2001 From: Francesco Novy Date: Wed, 10 May 2023 14:16:46 +0200 Subject: [PATCH 1/8] 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 | 134 ++++++++++++++++++ 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, 442 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..e71cc0a8bcf6 --- /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 = (run = 1) => { + return window.loaded.length === COUNT * 2 * run; +}; + +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..9fc1b0a669c8 --- /dev/null +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts @@ -0,0 +1,134 @@ +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, browserName }) => { + if (shouldSkipReplayTest() || browserName !== 'chromium') { + 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'); + }, + 10_000, + ); + const reqPromise1Breadcrumbs = waitForReplayRequest( + page, + (_event, res) => { + const { breadcrumbs } = getCustomRecordingEvents(res); + + return breadcrumbs.some(breadcrumb => breadcrumb.category === 'replay.throttled'); + }, + 10_000, + ); + + await page.click('[data-network]'); + await page.click('[data-fetch]'); + + await page.waitForFunction('window.__isLoaded()'); + await forceFlushReplay(); + + const { performanceSpans } = getCustomRecordingEvents(await reqPromise1); + const { breadcrumbs } = getCustomRecordingEvents(await reqPromise1Breadcrumbs); + + // 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 - 50); + + 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'); + }, + 10_000, + ); + const reqPromise2Breadcrumbs = waitForReplayRequest( + page, + (_event, res) => { + const { breadcrumbs } = getCustomRecordingEvents(res); + + return breadcrumbs.some(breadcrumb => breadcrumb.category === 'replay.throttled'); + }, + 10_000, + ); + + await page.click('[data-network]'); + await page.click('[data-fetch]'); + + await page.waitForFunction('window.__isLoaded(2)'); + await forceFlushReplay(); + + const { performanceSpans: performanceSpans2 } = getCustomRecordingEvents(await reqPromise2); + const { breadcrumbs: breadcrumbs2 } = getCustomRecordingEvents(await reqPromise2Breadcrumbs); + + // 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 - 50); + + 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 8d89aa0b2653..4bf911343c19 100644 --- a/packages/replay/src/replay.ts +++ b/packages/replay/src/replay.ts @@ -24,6 +24,7 @@ import type { EventBuffer, InternalEventContext, PopEventContext, + RecordingEvent, RecordingOptions, ReplayContainer as ReplayContainerInterface, ReplayPluginOptions, @@ -42,6 +43,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. @@ -75,6 +78,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()` */ @@ -136,6 +144,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. */ @@ -546,6 +562,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) @@ -784,7 +832,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); + }); +}); From 7231d2ac710f2b016ecb1325b373c1fac7772441 Mon Sep 17 00:00:00 2001 From: Francesco Novy Date: Wed, 10 May 2023 14:53:56 +0200 Subject: [PATCH 2/8] unflake? --- .../suites/replay/throttleBreadcrumbs/test.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts index 9fc1b0a669c8..9ad7cfae4ad9 100644 --- a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts @@ -89,7 +89,7 @@ sentryTest( 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 page.waitForTimeout(7_000); await forceFlushReplay(); const reqPromise2 = waitForReplayRequest( From 433da18558a88615e54856077db38995ba86252e Mon Sep 17 00:00:00 2001 From: Francesco Novy Date: Wed, 10 May 2023 16:11:29 +0200 Subject: [PATCH 3/8] refactor for less flakiness?? --- .../suites/replay/throttleBreadcrumbs/test.ts | 102 +++++++++--------- .../utils/replayHelpers.ts | 30 ++++-- 2 files changed, 72 insertions(+), 60 deletions(-) diff --git a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts index 9ad7cfae4ad9..75d208bd0936 100644 --- a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts @@ -1,7 +1,14 @@ import { expect } from '@playwright/test'; +import type { Breadcrumb } from '@sentry/types'; import { sentryTest } from '../../../utils/fixtures'; -import { getCustomRecordingEvents, shouldSkipReplayTest, waitForReplayRequest } from '../../../utils/replayHelpers'; +import type { PerformanceSpan } from '../../../utils/replayHelpers'; +import { + getCustomRecordingEvents, + getReplayEventFromRequest, + shouldSkipReplayTest, + waitForReplayRequest, +} from '../../../utils/replayHelpers'; const COUNT = 250; const THROTTLE_LIMIT = 300; @@ -49,24 +56,27 @@ sentryTest( await page.goto(url); await reqPromise0; - const reqPromise1 = waitForReplayRequest( - page, - (_event, res) => { - const { performanceSpans } = getCustomRecordingEvents(res); - - return performanceSpans.some(span => span.op === 'resource.script'); - }, - 10_000, - ); - const reqPromise1Breadcrumbs = waitForReplayRequest( - page, - (_event, res) => { - const { breadcrumbs } = getCustomRecordingEvents(res); - - return breadcrumbs.some(breadcrumb => breadcrumb.category === 'replay.throttled'); - }, - 10_000, - ); + let collectedSpans: PerformanceSpan[] = []; + let collectedBreadcrumbs: Breadcrumb[] = []; + + page.on('response', response => { + // We only capture sentry stuff + if (!response.url().includes('https://dsn.ingest.sentry')) { + return; + } + + // If this is undefined, this is not a replay request + if (!getReplayEventFromRequest(response.request())) { + return; + } + + const { performanceSpans, breadcrumbs } = getCustomRecordingEvents(response); + + collectedSpans.push( + ...performanceSpans.filter(span => span.op === 'resource.script' || span.op === 'resource.fetch'), + ); + collectedBreadcrumbs.push(...breadcrumbs.filter(breadcrumb => breadcrumb.category === 'replay.throttled')); + }); await page.click('[data-network]'); await page.click('[data-fetch]'); @@ -74,42 +84,25 @@ sentryTest( await page.waitForFunction('window.__isLoaded()'); await forceFlushReplay(); - const { performanceSpans } = getCustomRecordingEvents(await reqPromise1); - const { breadcrumbs } = getCustomRecordingEvents(await reqPromise1Breadcrumbs); + await waitForFunction(() => collectedBreadcrumbs.length === 1, 10_000, 100); // 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 - 50); - - expect(breadcrumbs.filter(({ category }) => category === 'replay.throttled').length).toBe(1); + // We give it some wiggle room to account for flakyness + expect(collectedSpans.length).toBeLessThanOrEqual(THROTTLE_LIMIT); + expect(collectedSpans.length).toBeGreaterThanOrEqual(THROTTLE_LIMIT - 50); + expect(collectedBreadcrumbs.length).toBe(1); // Now we wait for 6s (5s + some wiggle room), and make some requests again - await page.waitForTimeout(7_000); + 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'); - }, - 10_000, - ); - const reqPromise2Breadcrumbs = waitForReplayRequest( - page, - (_event, res) => { - const { breadcrumbs } = getCustomRecordingEvents(res); - - return breadcrumbs.some(breadcrumb => breadcrumb.category === 'replay.throttled'); - }, - 10_000, - ); + // Reset collectors + collectedSpans = []; + collectedBreadcrumbs = []; await page.click('[data-network]'); await page.click('[data-fetch]'); @@ -117,18 +110,23 @@ sentryTest( await page.waitForFunction('window.__isLoaded(2)'); await forceFlushReplay(); - const { performanceSpans: performanceSpans2 } = getCustomRecordingEvents(await reqPromise2); - const { breadcrumbs: breadcrumbs2 } = getCustomRecordingEvents(await reqPromise2Breadcrumbs); + await waitForFunction(() => collectedBreadcrumbs.length === 1, 10_000, 100); // 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 - 50); - - expect(breadcrumbs2.filter(({ category }) => category === 'replay.throttled').length).toBe(1); + // We give it some wiggle room to account for flakyness + expect(collectedSpans.length).toBeLessThanOrEqual(THROTTLE_LIMIT); + expect(collectedSpans.length).toBeGreaterThanOrEqual(THROTTLE_LIMIT - 50); + expect(collectedBreadcrumbs.length).toBe(1); }, ); + +async function waitForFunction(cb: () => boolean, timeout = 2000, increment = 100) { + while (timeout > 0 && !cb()) { + await new Promise(resolve => setTimeout(resolve, increment)); + await waitForFunction(cb, timeout - increment, increment); + } +} diff --git a/packages/browser-integration-tests/utils/replayHelpers.ts b/packages/browser-integration-tests/utils/replayHelpers.ts index 415dcd667414..ec332edea74d 100644 --- a/packages/browser-integration-tests/utils/replayHelpers.ts +++ b/packages/browser-integration-tests/utils/replayHelpers.ts @@ -34,6 +34,25 @@ export type IncrementalRecordingSnapshot = eventWithTime & { export type RecordingSnapshot = FullRecordingSnapshot | IncrementalRecordingSnapshot; +/** Returns the replay event from the given request, or undefined if this is not a replay request. */ +export function getReplayEventFromRequest(req: Request): ReplayEvent | undefined { + const postData = req.postData(); + if (!postData) { + return undefined; + } + + try { + const event = envelopeRequestParser(req); + + if (!isReplayEvent(event)) { + return undefined; + } + + return event; + } catch { + return undefined; + } +} /** * Waits for a replay request to be sent by the page and returns it. * @@ -58,18 +77,13 @@ export function waitForReplayRequest( res => { const req = res.request(); - const postData = req.postData(); - if (!postData) { + const event = getReplayEventFromRequest(req); + + if (!event) { return false; } try { - const event = envelopeRequestParser(req); - - if (!isReplayEvent(event)) { - return false; - } - if (callback) { return callback(event, res); } From f9eb6f525f2134e01922fca96cda5ddc8f9295a0 Mon Sep 17 00:00:00 2001 From: Francesco Novy Date: Wed, 10 May 2023 16:34:43 +0200 Subject: [PATCH 4/8] reduce max timeout --- .../suites/replay/throttleBreadcrumbs/test.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts index 75d208bd0936..f702d4e52150 100644 --- a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts @@ -84,7 +84,7 @@ sentryTest( await page.waitForFunction('window.__isLoaded()'); await forceFlushReplay(); - await waitForFunction(() => collectedBreadcrumbs.length === 1, 10_000, 100); + await waitForFunction(() => collectedBreadcrumbs.length === 1, 6_000, 100); // All assets have been _loaded_ expect(scriptsLoaded).toBe(COUNT); @@ -110,7 +110,7 @@ sentryTest( await page.waitForFunction('window.__isLoaded(2)'); await forceFlushReplay(); - await waitForFunction(() => collectedBreadcrumbs.length === 1, 10_000, 100); + await waitForFunction(() => collectedBreadcrumbs.length === 1, 6_000, 100); // All assets have been _loaded_ expect(scriptsLoaded).toBe(COUNT * 2); From 13bc40158413d69dd2703b53d8d641876b1763db Mon Sep 17 00:00:00 2001 From: Francesco Novy Date: Wed, 10 May 2023 16:35:43 +0200 Subject: [PATCH 5/8] reduce test time & complexity --- .../suites/replay/throttleBreadcrumbs/test.ts | 30 ++----------------- 1 file changed, 2 insertions(+), 28 deletions(-) diff --git a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts index f702d4e52150..b1d1a1516384 100644 --- a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts @@ -56,8 +56,8 @@ sentryTest( await page.goto(url); await reqPromise0; - let collectedSpans: PerformanceSpan[] = []; - let collectedBreadcrumbs: Breadcrumb[] = []; + const collectedSpans: PerformanceSpan[] = []; + const collectedBreadcrumbs: Breadcrumb[] = []; page.on('response', response => { // We only capture sentry stuff @@ -95,32 +95,6 @@ sentryTest( expect(collectedSpans.length).toBeLessThanOrEqual(THROTTLE_LIMIT); expect(collectedSpans.length).toBeGreaterThanOrEqual(THROTTLE_LIMIT - 50); expect(collectedBreadcrumbs.length).toBe(1); - - // Now we wait for 6s (5s + some wiggle room), and make some requests again - await page.waitForTimeout(6_000); - await forceFlushReplay(); - - // Reset collectors - collectedSpans = []; - collectedBreadcrumbs = []; - - await page.click('[data-network]'); - await page.click('[data-fetch]'); - - await page.waitForFunction('window.__isLoaded(2)'); - await forceFlushReplay(); - - await waitForFunction(() => collectedBreadcrumbs.length === 1, 6_000, 100); - - // All assets have been _loaded_ - expect(scriptsLoaded).toBe(COUNT * 2); - expect(fetchLoaded).toBe(COUNT * 2); - - // But only some have been captured by replay - // We give it some wiggle room to account for flakyness - expect(collectedSpans.length).toBeLessThanOrEqual(THROTTLE_LIMIT); - expect(collectedSpans.length).toBeGreaterThanOrEqual(THROTTLE_LIMIT - 50); - expect(collectedBreadcrumbs.length).toBe(1); }, ); From 7b3a957b9f88b3a7540d26d6771a9d4707ad4929 Mon Sep 17 00:00:00 2001 From: Billy Vong Date: Wed, 17 May 2023 15:26:43 -0400 Subject: [PATCH 6/8] change to use console.log --- .../replay/throttleBreadcrumbs/subject.js | 37 +------ .../replay/throttleBreadcrumbs/template.html | 3 +- .../suites/replay/throttleBreadcrumbs/test.ts | 101 ++++++------------ 3 files changed, 39 insertions(+), 102 deletions(-) diff --git a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/subject.js b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/subject.js index e71cc0a8bcf6..8c0be27bda41 100644 --- a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/subject.js +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/subject.js @@ -1,35 +1,8 @@ -window.loaded = []; -const head = document.querySelector('head'); +const COUNT = 600; -const COUNT = 250; - -window.__isLoaded = (run = 1) => { - return window.loaded.length === COUNT * 2 * run; -}; - -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}`); - }); +document.querySelector('[data-console]').addEventListener('click', () => { + // Call console.log() many times + for (let i = 0; i < COUNT; i++) { + console.log('testing'); } }); diff --git a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/template.html b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/template.html index e045a04653fc..07807a41f8c8 100644 --- a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/template.html +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/template.html @@ -4,7 +4,6 @@ - - + diff --git a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts index b1d1a1516384..80d4d6d49aa9 100644 --- a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts @@ -2,25 +2,26 @@ import { expect } from '@playwright/test'; import type { Breadcrumb } from '@sentry/types'; import { sentryTest } from '../../../utils/fixtures'; -import type { PerformanceSpan } from '../../../utils/replayHelpers'; -import { - getCustomRecordingEvents, - getReplayEventFromRequest, - shouldSkipReplayTest, - waitForReplayRequest, -} from '../../../utils/replayHelpers'; - -const COUNT = 250; +import { getCustomRecordingEvents, shouldSkipReplayTest, waitForReplayRequest } from '../../../utils/replayHelpers'; + const THROTTLE_LIMIT = 300; +function isConsole(breadcrumb: Breadcrumb) { + return breadcrumb.category === 'console'; +} + sentryTest( - 'throttles breadcrumbs when many requests are made at the same time', + 'throttles breadcrumbs when many `console.log` are made at the same time', async ({ getLocalTestUrl, page, forceFlushReplay, browserName }) => { if (shouldSkipReplayTest() || browserName !== 'chromium') { sentryTest.skip(); } const reqPromise0 = waitForReplayRequest(page, 0); + const reqPromise1 = waitForReplayRequest(page, 1); + const reqPromise2 = waitForReplayRequest(page, 2); + const reqPromise3 = waitForReplayRequest(page, 3); + const reqPromise4 = waitForReplayRequest(page, 4); await page.route('https://dsn.ingest.sentry.io/**/*', route => { return route.fulfill({ @@ -30,77 +31,41 @@ sentryTest( }); }); - 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 collectedSpans: PerformanceSpan[] = []; - const collectedBreadcrumbs: Breadcrumb[] = []; + await page.click('[data-console]'); + await forceFlushReplay(); - page.on('response', response => { - // We only capture sentry stuff - if (!response.url().includes('https://dsn.ingest.sentry')) { - return; - } + const { breadcrumbs } = getCustomRecordingEvents(await reqPromise1); - // If this is undefined, this is not a replay request - if (!getReplayEventFromRequest(response.request())) { - return; - } + // 1 click breadcrumb + 1 throttled breadcrumb is why console logs are less + // than throttle limit + expect(breadcrumbs.filter(isConsole).length).toBe(THROTTLE_LIMIT - 2); + expect(breadcrumbs.length).toBe(THROTTLE_LIMIT); + expect(breadcrumbs.filter(breadcrumb => breadcrumb.category === 'replay.throttled').length).toBe(1); - const { performanceSpans, breadcrumbs } = getCustomRecordingEvents(response); + await page.click('[data-console]'); + await forceFlushReplay(); - collectedSpans.push( - ...performanceSpans.filter(span => span.op === 'resource.script' || span.op === 'resource.fetch'), - ); - collectedBreadcrumbs.push(...breadcrumbs.filter(breadcrumb => breadcrumb.category === 'replay.throttled')); - }); + const { breadcrumbs: breadcrumbs2 } = getCustomRecordingEvents(await reqPromise2); - await page.click('[data-network]'); - await page.click('[data-fetch]'); + // No more breadcrumbs because we are still throttled + expect(breadcrumbs2.filter(isConsole).length).toBe(0); + expect(breadcrumbs2.filter(breadcrumb => breadcrumb.category === 'replay.throttled').length).toBe(0); - await page.waitForFunction('window.__isLoaded()'); - await forceFlushReplay(); + // XXX: This is potentially a bug? looks to be only a memory span + await reqPromise3; - await waitForFunction(() => collectedBreadcrumbs.length === 1, 6_000, 100); + await new Promise(resolve => setTimeout(resolve, 5500)); + await page.click('[data-console]'); - // All assets have been _loaded_ - expect(scriptsLoaded).toBe(COUNT); - expect(fetchLoaded).toBe(COUNT); + await forceFlushReplay(); + const { breadcrumbs: breadcrumbs3 } = getCustomRecordingEvents(await reqPromise4); - // But only some have been captured by replay - // We give it some wiggle room to account for flakyness - expect(collectedSpans.length).toBeLessThanOrEqual(THROTTLE_LIMIT); - expect(collectedSpans.length).toBeGreaterThanOrEqual(THROTTLE_LIMIT - 50); - expect(collectedBreadcrumbs.length).toBe(1); + expect(breadcrumbs3.filter(isConsole).length).toBe(THROTTLE_LIMIT - 1); + expect(breadcrumbs3.filter(breadcrumb => breadcrumb.category === 'replay.throttled').length).toBe(1); }, ); - -async function waitForFunction(cb: () => boolean, timeout = 2000, increment = 100) { - while (timeout > 0 && !cb()) { - await new Promise(resolve => setTimeout(resolve, increment)); - await waitForFunction(cb, timeout - increment, increment); - } -} From 5c894e378f12a8c7c50fe36388b12ede3281c322 Mon Sep 17 00:00:00 2001 From: Billy Vong Date: Wed, 17 May 2023 19:25:46 -0400 Subject: [PATCH 7/8] remove testing throttle --- .../replay/throttleBreadcrumbs/subject.js | 4 +-- .../suites/replay/throttleBreadcrumbs/test.ts | 30 ------------------- 2 files changed, 2 insertions(+), 32 deletions(-) diff --git a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/subject.js b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/subject.js index 8c0be27bda41..30ba4b350700 100644 --- a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/subject.js +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/subject.js @@ -1,8 +1,8 @@ -const COUNT = 600; +const COUNT = 400; document.querySelector('[data-console]').addEventListener('click', () => { // Call console.log() many times for (let i = 0; i < COUNT; i++) { - console.log('testing'); + console.log(`testing ${i}`); } }); diff --git a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts index 80d4d6d49aa9..17f4210624a0 100644 --- a/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts +++ b/packages/browser-integration-tests/suites/replay/throttleBreadcrumbs/test.ts @@ -1,15 +1,10 @@ import { expect } from '@playwright/test'; -import type { Breadcrumb } from '@sentry/types'; import { sentryTest } from '../../../utils/fixtures'; import { getCustomRecordingEvents, shouldSkipReplayTest, waitForReplayRequest } from '../../../utils/replayHelpers'; const THROTTLE_LIMIT = 300; -function isConsole(breadcrumb: Breadcrumb) { - return breadcrumb.category === 'console'; -} - sentryTest( 'throttles breadcrumbs when many `console.log` are made at the same time', async ({ getLocalTestUrl, page, forceFlushReplay, browserName }) => { @@ -19,9 +14,6 @@ sentryTest( const reqPromise0 = waitForReplayRequest(page, 0); const reqPromise1 = waitForReplayRequest(page, 1); - const reqPromise2 = waitForReplayRequest(page, 2); - const reqPromise3 = waitForReplayRequest(page, 3); - const reqPromise4 = waitForReplayRequest(page, 4); await page.route('https://dsn.ingest.sentry.io/**/*', route => { return route.fulfill({ @@ -43,29 +35,7 @@ sentryTest( // 1 click breadcrumb + 1 throttled breadcrumb is why console logs are less // than throttle limit - expect(breadcrumbs.filter(isConsole).length).toBe(THROTTLE_LIMIT - 2); expect(breadcrumbs.length).toBe(THROTTLE_LIMIT); expect(breadcrumbs.filter(breadcrumb => breadcrumb.category === 'replay.throttled').length).toBe(1); - - await page.click('[data-console]'); - await forceFlushReplay(); - - const { breadcrumbs: breadcrumbs2 } = getCustomRecordingEvents(await reqPromise2); - - // No more breadcrumbs because we are still throttled - expect(breadcrumbs2.filter(isConsole).length).toBe(0); - expect(breadcrumbs2.filter(breadcrumb => breadcrumb.category === 'replay.throttled').length).toBe(0); - - // XXX: This is potentially a bug? looks to be only a memory span - await reqPromise3; - - await new Promise(resolve => setTimeout(resolve, 5500)); - await page.click('[data-console]'); - - await forceFlushReplay(); - const { breadcrumbs: breadcrumbs3 } = getCustomRecordingEvents(await reqPromise4); - - expect(breadcrumbs3.filter(isConsole).length).toBe(THROTTLE_LIMIT - 1); - expect(breadcrumbs3.filter(breadcrumb => breadcrumb.category === 'replay.throttled').length).toBe(1); }, ); From 6e5fdc93ed74114bfabb301ded71842df90c31f5 Mon Sep 17 00:00:00 2001 From: Billy Vong Date: Fri, 26 May 2023 09:24:08 -0400 Subject: [PATCH 8/8] add metric flag for breadcrumb --- packages/replay/src/replay.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/packages/replay/src/replay.ts b/packages/replay/src/replay.ts index 4bf911343c19..9d3e787f1306 100644 --- a/packages/replay/src/replay.ts +++ b/packages/replay/src/replay.ts @@ -586,6 +586,7 @@ export class ReplayContainer implements ReplayContainerInterface { data: { tag: 'breadcrumb', payload: breadcrumb, + metric: true, }, }); });