From 0e9cddfa26ffff073ce31416b31c0cb2bca36582 Mon Sep 17 00:00:00 2001 From: edwardgou-sentry <83961295+edwardgou-sentry@users.noreply.github.com> Date: Tue, 19 Mar 2024 09:59:57 -0400 Subject: [PATCH] fix(webvitals): Fix mapping not being maintained properly and sometimes not sending INP spans (#11183) Fixes scenarios where interaction tracking wasn't properly recording up to 10 candidate INP interactions. Fixes `first-input` interaction not always tracked as INP candidates. Fixes INP candidates not always using the longest latency even in their interaction id grouping. Also fixes: #11156 --- .../interactions/assets/script.js | 9 ++- .../interactions/template.html | 1 + .../interactions/test.ts | 63 +++++++++++++++- .../interactions/assets/script.js | 9 ++- .../browsertracing/interactions/template.html | 1 + .../browsertracing/interactions/test.ts | 75 ++++++++++++++++++- .../src/browser/browserTracingIntegration.ts | 64 ++++++++++++---- .../src/browser/browsertracing.ts | 63 +++++++++++----- .../src/browser/instrument.ts | 10 ++- .../src/browser/metrics/index.ts | 18 ++--- .../src/browser/web-vitals/types.ts | 1 + 11 files changed, 254 insertions(+), 60 deletions(-) diff --git a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/interactions/assets/script.js b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/interactions/assets/script.js index a37a2c70ad27..a5f47c4cb251 100644 --- a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/interactions/assets/script.js +++ b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/interactions/assets/script.js @@ -1,4 +1,4 @@ -const delay = e => { +const createDelayFunction = (delay = 70) => e => { const startTime = Date.now(); function getElasped() { @@ -6,12 +6,13 @@ const delay = e => { return time - startTime; } - while (getElasped() < 70) { + while (getElasped() < delay) { // } e.target.classList.add('clicked'); }; -document.querySelector('[data-test-id=interaction-button]').addEventListener('click', delay); -document.querySelector('[data-test-id=annotated-button]').addEventListener('click', delay); +document.querySelector('[data-test-id=interaction-button]').addEventListener('click', createDelayFunction()); +document.querySelector('[data-test-id=annotated-button]').addEventListener('click', createDelayFunction()); +document.querySelector('[data-test-id=slow-interaction-button]').addEventListener('click', createDelayFunction(200)); diff --git a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/interactions/template.html b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/interactions/template.html index 3357fb20a94e..04df3b9c7c52 100644 --- a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/interactions/template.html +++ b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/interactions/template.html @@ -6,6 +6,7 @@
Rendered Before Long Task
+ diff --git a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/interactions/test.ts b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/interactions/test.ts index 94c3cb628ea9..505751d49302 100644 --- a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/interactions/test.ts +++ b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/interactions/test.ts @@ -113,8 +113,8 @@ sentryTest( }, ); -sentryTest('should capture an INP click event span. @firefox', async ({ browserName, getLocalTestPath, page }) => { - const supportedBrowsers = ['chromium', 'firefox']; +sentryTest('should capture an INP click event span.', async ({ browserName, getLocalTestPath, page }) => { + const supportedBrowsers = ['chromium']; if (shouldSkipTracingTest() || !supportedBrowsers.includes(browserName)) { sentryTest.skip(); @@ -160,3 +160,62 @@ sentryTest('should capture an INP click event span. @firefox', async ({ browserN expect(spanEnvelopes[0].measurements.inp.value).toBeGreaterThan(0); expect(spanEnvelopes[0].measurements.inp.unit).toBe('millisecond'); }); + +sentryTest( + 'should choose the slowest interaction click event when INP is triggered.', + async ({ browserName, getLocalTestPath, page }) => { + const supportedBrowsers = ['chromium']; + + if (shouldSkipTracingTest() || !supportedBrowsers.includes(browserName)) { + sentryTest.skip(); + } + + await page.route('**/path/to/script.js', (route: Route) => + route.fulfill({ path: `${__dirname}/assets/script.js` }), + ); + await page.route('https://dsn.ingest.sentry.io/**/*', route => { + return route.fulfill({ + status: 200, + contentType: 'application/json', + body: JSON.stringify({ id: 'test-id' }), + }); + }); + + const url = await getLocalTestPath({ testDir: __dirname }); + + await page.goto(url); + await getFirstSentryEnvelopeRequest(page); + + await page.locator('[data-test-id=interaction-button]').click(); + await page.locator('.clicked[data-test-id=interaction-button]').isVisible(); + + // Wait for the interaction transaction from the enableInteractions experiment + await getMultipleSentryEnvelopeRequests(page, 1); + + await page.locator('[data-test-id=slow-interaction-button]').click(); + await page.locator('.clicked[data-test-id=slow-interaction-button]').isVisible(); + + // Wait for the interaction transaction from the enableInteractions experiment + await getMultipleSentryEnvelopeRequests(page, 1); + + const spanEnvelopesPromise = getMultipleSentryEnvelopeRequests< + SpanJSON & { exclusive_time: number; measurements: Measurements } + >(page, 1, { + envelopeType: 'span', + }); + // Page hide to trigger INP + await page.evaluate(() => { + window.dispatchEvent(new Event('pagehide')); + }); + + // Get the INP span envelope + const spanEnvelopes = await spanEnvelopesPromise; + + expect(spanEnvelopes).toHaveLength(1); + expect(spanEnvelopes[0].op).toBe('ui.interaction.click'); + expect(spanEnvelopes[0].description).toBe('body > button.clicked'); + expect(spanEnvelopes[0].exclusive_time).toBeGreaterThan(150); + expect(spanEnvelopes[0].measurements.inp.value).toBeGreaterThan(150); + expect(spanEnvelopes[0].measurements.inp.unit).toBe('millisecond'); + }, +); diff --git a/dev-packages/browser-integration-tests/suites/tracing/browsertracing/interactions/assets/script.js b/dev-packages/browser-integration-tests/suites/tracing/browsertracing/interactions/assets/script.js index a37a2c70ad27..a5f47c4cb251 100644 --- a/dev-packages/browser-integration-tests/suites/tracing/browsertracing/interactions/assets/script.js +++ b/dev-packages/browser-integration-tests/suites/tracing/browsertracing/interactions/assets/script.js @@ -1,4 +1,4 @@ -const delay = e => { +const createDelayFunction = (delay = 70) => e => { const startTime = Date.now(); function getElasped() { @@ -6,12 +6,13 @@ const delay = e => { return time - startTime; } - while (getElasped() < 70) { + while (getElasped() < delay) { // } e.target.classList.add('clicked'); }; -document.querySelector('[data-test-id=interaction-button]').addEventListener('click', delay); -document.querySelector('[data-test-id=annotated-button]').addEventListener('click', delay); +document.querySelector('[data-test-id=interaction-button]').addEventListener('click', createDelayFunction()); +document.querySelector('[data-test-id=annotated-button]').addEventListener('click', createDelayFunction()); +document.querySelector('[data-test-id=slow-interaction-button]').addEventListener('click', createDelayFunction(200)); diff --git a/dev-packages/browser-integration-tests/suites/tracing/browsertracing/interactions/template.html b/dev-packages/browser-integration-tests/suites/tracing/browsertracing/interactions/template.html index 3357fb20a94e..04df3b9c7c52 100644 --- a/dev-packages/browser-integration-tests/suites/tracing/browsertracing/interactions/template.html +++ b/dev-packages/browser-integration-tests/suites/tracing/browsertracing/interactions/template.html @@ -6,6 +6,7 @@
Rendered Before Long Task
+ diff --git a/dev-packages/browser-integration-tests/suites/tracing/browsertracing/interactions/test.ts b/dev-packages/browser-integration-tests/suites/tracing/browsertracing/interactions/test.ts index eea1fbfff23b..438f051e1990 100644 --- a/dev-packages/browser-integration-tests/suites/tracing/browsertracing/interactions/test.ts +++ b/dev-packages/browser-integration-tests/suites/tracing/browsertracing/interactions/test.ts @@ -1,6 +1,14 @@ import type { Route } from '@playwright/test'; import { expect } from '@playwright/test'; -import type { Measurements, SerializedEvent, Span, SpanContext, SpanJSON, Transaction } from '@sentry/types'; +import type { + Event as SentryEvent, + Measurements, + SerializedEvent, + Span, + SpanContext, + SpanJSON, + Transaction, +} from '@sentry/types'; import { sentryTest } from '../../../../utils/fixtures'; import { @@ -113,8 +121,8 @@ sentryTest( }, ); -sentryTest('should capture an INP click event span. @firefox', async ({ browserName, getLocalTestPath, page }) => { - const supportedBrowsers = ['chromium', 'firefox']; +sentryTest('should capture an INP click event span.', async ({ browserName, getLocalTestPath, page }) => { + const supportedBrowsers = ['chromium']; if (shouldSkipTracingTest() || !supportedBrowsers.includes(browserName)) { sentryTest.skip(); @@ -132,7 +140,7 @@ sentryTest('should capture an INP click event span. @firefox', async ({ browserN const url = await getLocalTestPath({ testDir: __dirname }); await page.goto(url); - await getFirstSentryEnvelopeRequest(page); + await getFirstSentryEnvelopeRequest(page); await page.locator('[data-test-id=interaction-button]').click(); await page.locator('.clicked[data-test-id=interaction-button]').isVisible(); @@ -160,3 +168,62 @@ sentryTest('should capture an INP click event span. @firefox', async ({ browserN expect(spanEnvelopes[0].measurements.inp.value).toBeGreaterThan(0); expect(spanEnvelopes[0].measurements.inp.unit).toBe('millisecond'); }); + +sentryTest( + 'should choose the slowest interaction click event when INP is triggered.', + async ({ browserName, getLocalTestPath, page }) => { + const supportedBrowsers = ['chromium']; + + if (shouldSkipTracingTest() || !supportedBrowsers.includes(browserName)) { + sentryTest.skip(); + } + + await page.route('**/path/to/script.js', (route: Route) => + route.fulfill({ path: `${__dirname}/assets/script.js` }), + ); + await page.route('https://dsn.ingest.sentry.io/**/*', route => { + return route.fulfill({ + status: 200, + contentType: 'application/json', + body: JSON.stringify({ id: 'test-id' }), + }); + }); + + const url = await getLocalTestPath({ testDir: __dirname }); + + await page.goto(url); + await getFirstSentryEnvelopeRequest(page); + + await page.locator('[data-test-id=interaction-button]').click(); + await page.locator('.clicked[data-test-id=interaction-button]').isVisible(); + + // Wait for the interaction transaction from the enableInteractions experiment + await getMultipleSentryEnvelopeRequests(page, 1); + + await page.locator('[data-test-id=slow-interaction-button]').click(); + await page.locator('.clicked[data-test-id=slow-interaction-button]').isVisible(); + + // Wait for the interaction transaction from the enableInteractions experiment + await getMultipleSentryEnvelopeRequests(page, 1); + + const spanEnvelopesPromise = getMultipleSentryEnvelopeRequests< + SpanJSON & { exclusive_time: number; measurements: Measurements } + >(page, 1, { + envelopeType: 'span', + }); + // Page hide to trigger INP + await page.evaluate(() => { + window.dispatchEvent(new Event('pagehide')); + }); + + // Get the INP span envelope + const spanEnvelopes = await spanEnvelopesPromise; + + expect(spanEnvelopes).toHaveLength(1); + expect(spanEnvelopes[0].op).toBe('ui.interaction.click'); + expect(spanEnvelopes[0].description).toBe('body > button.clicked'); + expect(spanEnvelopes[0].exclusive_time).toBeGreaterThan(150); + expect(spanEnvelopes[0].measurements.inp.value).toBeGreaterThan(150); + expect(spanEnvelopes[0].measurements.inp.unit).toBe('millisecond'); + }, +); diff --git a/packages/tracing-internal/src/browser/browserTracingIntegration.ts b/packages/tracing-internal/src/browser/browserTracingIntegration.ts index 01dda5bcdcfc..574dca4c5131 100644 --- a/packages/tracing-internal/src/browser/browserTracingIntegration.ts +++ b/packages/tracing-internal/src/browser/browserTracingIntegration.ts @@ -194,9 +194,9 @@ export const browserTracingIntegration = ((_options: Partial { + const handleEntries = ({ entries }: { entries: PerformanceEntry[] }): void => { const client = getClient(); // We need to get the replay, user, and activeTransaction from the current scope // so that we can associate replay id, profile id, and a user display to the span @@ -560,40 +560,72 @@ function registerInpInteractionListener( const activeTransaction = getActiveTransaction(); const currentScope = getCurrentScope(); const user = currentScope !== undefined ? currentScope.getUser() : undefined; - for (const entry of entries) { + entries.forEach(entry => { if (isPerformanceEventTiming(entry)) { + const interactionId = entry.interactionId; + if (interactionId === undefined) { + return; + } + const existingInteraction = interactionIdToRouteNameMapping[interactionId]; const duration = entry.duration; - const keys = Object.keys(interactionIdtoRouteNameMapping); + const startTime = entry.startTime; + const keys = Object.keys(interactionIdToRouteNameMapping); const minInteractionId = keys.length > 0 ? keys.reduce((a, b) => { - return interactionIdtoRouteNameMapping[a].duration < interactionIdtoRouteNameMapping[b].duration + return interactionIdToRouteNameMapping[a].duration < interactionIdToRouteNameMapping[b].duration ? a : b; }) : undefined; - if (minInteractionId === undefined || duration > interactionIdtoRouteNameMapping[minInteractionId].duration) { - const interactionId = entry.interactionId; + // For a first input event to be considered, we must check that an interaction event does not already exist with the same duration and start time. + // This is also checked in the web-vitals library. + if (entry.entryType === 'first-input') { + const matchingEntry = keys + .map(key => interactionIdToRouteNameMapping[key]) + .some(interaction => { + return interaction.duration === duration && interaction.startTime === startTime; + }); + if (matchingEntry) { + return; + } + } + // Interactions with an id of 0 and are not first-input are not valid. + if (!interactionId) { + return; + } + // If the interaction already exists, we want to use the duration of the longest entry, since that is what the INP metric uses. + if (existingInteraction) { + existingInteraction.duration = Math.max(existingInteraction.duration, duration); + } else if ( + keys.length < MAX_INTERACTIONS || + minInteractionId === undefined || + duration > interactionIdToRouteNameMapping[minInteractionId].duration + ) { + // If the interaction does not exist, we want to add it to the mapping if there is space, or if the duration is longer than the shortest entry. const routeName = latestRoute.name; const parentContext = latestRoute.context; - if (interactionId && routeName && parentContext) { - if (minInteractionId && Object.keys(interactionIdtoRouteNameMapping).length >= MAX_INTERACTIONS) { + if (routeName && parentContext) { + if (minInteractionId && Object.keys(interactionIdToRouteNameMapping).length >= MAX_INTERACTIONS) { // eslint-disable-next-line @typescript-eslint/no-dynamic-delete - delete interactionIdtoRouteNameMapping[minInteractionId]; + delete interactionIdToRouteNameMapping[minInteractionId]; } - interactionIdtoRouteNameMapping[interactionId] = { + interactionIdToRouteNameMapping[interactionId] = { routeName, duration, parentContext, user, activeTransaction, replayId, + startTime, }; } } } - } - }); + }); + }; + addPerformanceInstrumentationHandler('event', handleEntries); + addPerformanceInstrumentationHandler('first-input', handleEntries); } function getSource(context: TransactionContext): TransactionSource | undefined { diff --git a/packages/tracing-internal/src/browser/browsertracing.ts b/packages/tracing-internal/src/browser/browsertracing.ts index 7a32b5768886..3a16598c04f1 100644 --- a/packages/tracing-internal/src/browser/browsertracing.ts +++ b/packages/tracing-internal/src/browser/browsertracing.ts @@ -193,7 +193,7 @@ export class BrowserTracing implements Integration { private _collectWebVitals: () => void; private _hasSetTracePropagationTargets: boolean; - private _interactionIdtoRouteNameMapping: InteractionRouteNameMapping; + private _interactionIdToRouteNameMapping: InteractionRouteNameMapping; private _latestRoute: { name: string | undefined; context: TransactionContext | undefined; @@ -235,10 +235,10 @@ export class BrowserTracing implements Integration { this._collectWebVitals = startTrackingWebVitals(); /** Stores a mapping of interactionIds from PerformanceEventTimings to the origin interaction path */ - this._interactionIdtoRouteNameMapping = {}; + this._interactionIdToRouteNameMapping = {}; if (this.options.enableInp) { - startTrackingINP(this._interactionIdtoRouteNameMapping); + startTrackingINP(this._interactionIdToRouteNameMapping); } if (this.options.enableLongTask) { startTrackingLongTasks(); @@ -489,7 +489,7 @@ export class BrowserTracing implements Integration { /** Creates a listener on interaction entries, and maps interactionIds to the origin path of the interaction */ private _registerInpInteractionListener(): void { - addPerformanceInstrumentationHandler('event', ({ entries }) => { + const handleEntries = ({ entries }: { entries: PerformanceEntry[] }): void => { const client = getClient(); // We need to get the replay, user, and activeTransaction from the current scope // so that we can associate replay id, profile id, and a user display to the span @@ -502,44 +502,73 @@ export class BrowserTracing implements Integration { const activeTransaction = getActiveTransaction(); const currentScope = getCurrentScope(); const user = currentScope !== undefined ? currentScope.getUser() : undefined; - for (const entry of entries) { + entries.forEach(entry => { if (isPerformanceEventTiming(entry)) { + const interactionId = entry.interactionId; + if (interactionId === undefined) { + return; + } + const existingInteraction = this._interactionIdToRouteNameMapping[interactionId]; const duration = entry.duration; - const keys = Object.keys(this._interactionIdtoRouteNameMapping); + const startTime = entry.startTime; + const keys = Object.keys(this._interactionIdToRouteNameMapping); const minInteractionId = keys.length > 0 ? keys.reduce((a, b) => { - return this._interactionIdtoRouteNameMapping[a].duration < - this._interactionIdtoRouteNameMapping[b].duration + return this._interactionIdToRouteNameMapping[a].duration < + this._interactionIdToRouteNameMapping[b].duration ? a : b; }) : undefined; - if ( + // For a first input event to be considered, we must check that an interaction event does not already exist with the same duration and start time. + // This is also checked in the web-vitals library. + if (entry.entryType === 'first-input') { + const matchingEntry = keys + .map(key => this._interactionIdToRouteNameMapping[key]) + .some(interaction => { + return interaction.duration === duration && interaction.startTime === startTime; + }); + if (matchingEntry) { + return; + } + } + // Interactions with an id of 0 and are not first-input are not valid. + if (!interactionId) { + return; + } + // If the interaction already exists, we want to use the duration of the longest entry, since that is what the INP metric uses. + if (existingInteraction) { + existingInteraction.duration = Math.max(existingInteraction.duration, duration); + } else if ( + keys.length < MAX_INTERACTIONS || minInteractionId === undefined || - duration > this._interactionIdtoRouteNameMapping[minInteractionId].duration + duration > this._interactionIdToRouteNameMapping[minInteractionId].duration ) { - const interactionId = entry.interactionId; + // If the interaction does not exist, we want to add it to the mapping if there is space, or if the duration is longer than the shortest entry. const routeName = this._latestRoute.name; const parentContext = this._latestRoute.context; - if (interactionId && routeName && parentContext) { - if (minInteractionId && Object.keys(this._interactionIdtoRouteNameMapping).length >= MAX_INTERACTIONS) { + if (routeName && parentContext) { + if (minInteractionId && Object.keys(this._interactionIdToRouteNameMapping).length >= MAX_INTERACTIONS) { // eslint-disable-next-line @typescript-eslint/no-dynamic-delete - delete this._interactionIdtoRouteNameMapping[minInteractionId]; + delete this._interactionIdToRouteNameMapping[minInteractionId]; } - this._interactionIdtoRouteNameMapping[interactionId] = { + this._interactionIdToRouteNameMapping[interactionId] = { routeName, duration, parentContext, user, activeTransaction, replayId, + startTime, }; } } } - } - }); + }); + }; + addPerformanceInstrumentationHandler('event', handleEntries); + addPerformanceInstrumentationHandler('first-input', handleEntries); } } diff --git a/packages/tracing-internal/src/browser/instrument.ts b/packages/tracing-internal/src/browser/instrument.ts index 10c96a0c5aa3..3441d730f0b2 100644 --- a/packages/tracing-internal/src/browser/instrument.ts +++ b/packages/tracing-internal/src/browser/instrument.ts @@ -7,7 +7,13 @@ import { onINP } from './web-vitals/getINP'; import { onLCP } from './web-vitals/getLCP'; import { observe } from './web-vitals/lib/observe'; -type InstrumentHandlerTypePerformanceObserver = 'longtask' | 'event' | 'navigation' | 'paint' | 'resource'; +type InstrumentHandlerTypePerformanceObserver = + | 'longtask' + | 'event' + | 'navigation' + | 'paint' + | 'resource' + | 'first-input'; type InstrumentHandlerTypeMetric = 'cls' | 'lcp' | 'fid' | 'inp'; @@ -144,7 +150,7 @@ export function addInpInstrumentationHandler( } export function addPerformanceInstrumentationHandler( - type: 'event', + type: 'event' | 'first-input', callback: (data: { entries: ((PerformanceEntry & { target?: unknown | null }) | PerformanceEventTiming)[] }) => void, ): CleanupHandlerCallback; export function addPerformanceInstrumentationHandler( diff --git a/packages/tracing-internal/src/browser/metrics/index.ts b/packages/tracing-internal/src/browser/metrics/index.ts index 3a0e15c08989..d7d52dc4bf90 100644 --- a/packages/tracing-internal/src/browser/metrics/index.ts +++ b/packages/tracing-internal/src/browser/metrics/index.ts @@ -231,7 +231,7 @@ const INP_ENTRY_MAP: Record = { }; /** Starts tracking the Interaction to Next Paint on the current page. */ -function _trackINP(interactionIdtoRouteNameMapping: InteractionRouteNameMapping): () => void { +function _trackINP(interactionIdToRouteNameMapping: InteractionRouteNameMapping): () => void { return addInpInstrumentationHandler(({ metric }) => { if (metric.value === undefined) { return; @@ -248,16 +248,12 @@ function _trackINP(interactionIdtoRouteNameMapping: InteractionRouteNameMapping) /** Build the INP span, create an envelope from the span, and then send the envelope */ const startTime = msToSec((browserPerformanceTimeOrigin as number) + entry.startTime); const duration = msToSec(metric.value); - const { routeName, parentContext, activeTransaction, user, replayId } = - entry.interactionId !== undefined - ? interactionIdtoRouteNameMapping[entry.interactionId] - : { - routeName: undefined, - parentContext: undefined, - activeTransaction: undefined, - user: undefined, - replayId: undefined, - }; + const interaction = + entry.interactionId !== undefined ? interactionIdToRouteNameMapping[entry.interactionId] : undefined; + if (interaction === undefined) { + return; + } + const { routeName, parentContext, activeTransaction, user, replayId } = interaction; const userDisplay = user !== undefined ? user.email || user.id || user.ip_address : undefined; // eslint-disable-next-line deprecation/deprecation const profileId = activeTransaction !== undefined ? activeTransaction.getProfileId() : undefined; diff --git a/packages/tracing-internal/src/browser/web-vitals/types.ts b/packages/tracing-internal/src/browser/web-vitals/types.ts index adc95084bda9..32afe0722191 100644 --- a/packages/tracing-internal/src/browser/web-vitals/types.ts +++ b/packages/tracing-internal/src/browser/web-vitals/types.ts @@ -172,5 +172,6 @@ export type InteractionRouteNameMapping = { user?: User; activeTransaction?: Transaction; replayId?: string; + startTime: number; }; };