From 039b61d8283eacc54bb0ac405bd4aeb222a357dc Mon Sep 17 00:00:00 2001 From: Lukas Stracke Date: Tue, 5 Nov 2024 15:23:32 +0100 Subject: [PATCH 1/2] fix(browser): Avoid recording long animation frame spans starting before their parent span --- .../init.js | 17 ++++++++++ .../subject.js | 18 +++++++++++ .../template.html | 13 ++++++++ .../test.ts | 31 +++++++++++++++++++ .../long-tasks-before-navigation/init.js | 1 - .../long-tasks-before-navigation/subject.js | 2 +- .../long-tasks-before-navigation/test.ts | 4 ++- .../src/metrics/browserMetrics.ts | 20 ++++++++---- 8 files changed, 97 insertions(+), 9 deletions(-) create mode 100644 dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/init.js create mode 100644 dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/subject.js create mode 100644 dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/template.html create mode 100644 dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/test.ts diff --git a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/init.js b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/init.js new file mode 100644 index 000000000000..f00d680435bb --- /dev/null +++ b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/init.js @@ -0,0 +1,17 @@ +import * as Sentry from '@sentry/browser'; + +window.Sentry = Sentry; + +Sentry.init({ + dsn: 'https://public@dsn.ingest.sentry.io/1337', + integrations: [ + Sentry.browserTracingIntegration({ + idleTimeout: 9000, + enableLongTask: false, + enableLongAnimationFrame: true, + instrumentPageLoad: false, + enableInp: false, + }), + ], + tracesSampleRate: 1, +}); diff --git a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/subject.js b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/subject.js new file mode 100644 index 000000000000..b02ed6efa33b --- /dev/null +++ b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/subject.js @@ -0,0 +1,18 @@ +function getElapsed(startTime) { + const time = Date.now(); + return time - startTime; +} + +function handleClick() { + const startTime = Date.now(); + while (getElapsed(startTime) < 105) { + // + } + window.history.pushState({}, '', `#myHeading`); +} + +const button = document.getElementById('clickme'); + +console.log('button', button); + +button.addEventListener('click', handleClick); diff --git a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/template.html b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/template.html new file mode 100644 index 000000000000..1d883292beb0 --- /dev/null +++ b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/template.html @@ -0,0 +1,13 @@ + + + + + + + + +

My Heading

+ + diff --git a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/test.ts b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/test.ts new file mode 100644 index 000000000000..e6fb88232d63 --- /dev/null +++ b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-animation-frame-before-navigation/test.ts @@ -0,0 +1,31 @@ +import { expect } from '@playwright/test'; +import type { Event } from '@sentry/types'; + +import { sentryTest } from '../../../../utils/fixtures'; +import { getFirstSentryEnvelopeRequest, shouldSkipTracingTest } from '../../../../utils/helpers'; + +sentryTest( + "doesn't capture long animation frame that starts before a navigation.", + async ({ browserName, getLocalTestPath, page }) => { + // Long animation frames only work on chrome + if (shouldSkipTracingTest() || browserName !== 'chromium') { + sentryTest.skip(); + } + + const url = await getLocalTestPath({ testDir: __dirname }); + + await page.goto(url); + + const navigationTransactionEventPromise = getFirstSentryEnvelopeRequest(page); + + await page.locator('#clickme').click(); + + const navigationTransactionEvent = await navigationTransactionEventPromise; + + expect(navigationTransactionEvent.contexts?.trace?.op).toBe('navigation'); + + const loafSpans = navigationTransactionEvent.spans?.filter(s => s.op?.startsWith('ui.long-animation-frame')); + + expect(loafSpans?.length).toEqual(0); + }, +); diff --git a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-tasks-before-navigation/init.js b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-tasks-before-navigation/init.js index 1f396416d855..5986089e5aa4 100644 --- a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-tasks-before-navigation/init.js +++ b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-tasks-before-navigation/init.js @@ -15,5 +15,4 @@ Sentry.init({ }), ], tracesSampleRate: 1, - debug: true, }); diff --git a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-tasks-before-navigation/subject.js b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-tasks-before-navigation/subject.js index 2c477161b9f4..d814f8875715 100644 --- a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-tasks-before-navigation/subject.js +++ b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-tasks-before-navigation/subject.js @@ -13,5 +13,5 @@ longTaskButton?.addEventListener('click', () => { } // trigger a navigation in the same event loop tick - window.history.pushState({}, '', '/#myHeading'); + window.history.pushState({}, '', '#myHeading'); }); diff --git a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-tasks-before-navigation/test.ts b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-tasks-before-navigation/test.ts index fe2efb6b3565..d7504eba840c 100644 --- a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-tasks-before-navigation/test.ts +++ b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/long-tasks-before-navigation/test.ts @@ -15,9 +15,11 @@ sentryTest( await page.goto(url); + const navigationTransactionEventPromise = getFirstSentryEnvelopeRequest(page); + await page.locator('#myButton').click(); - const navigationTransactionEvent = await getFirstSentryEnvelopeRequest(page, url); + const navigationTransactionEvent = await navigationTransactionEventPromise; expect(navigationTransactionEvent.contexts?.trace?.op).toBe('navigation'); diff --git a/packages/browser-utils/src/metrics/browserMetrics.ts b/packages/browser-utils/src/metrics/browserMetrics.ts index 670b1ce4ae25..53751711044b 100644 --- a/packages/browser-utils/src/metrics/browserMetrics.ts +++ b/packages/browser-utils/src/metrics/browserMetrics.ts @@ -143,7 +143,8 @@ export function startTrackingLongAnimationFrames(): void { // we directly observe `long-animation-frame` events instead of through the web-vitals // `observe` helper function. const observer = new PerformanceObserver(list => { - if (!getActiveSpan()) { + const parent = getActiveSpan(); + if (!parent) { return; } for (const entry of list.getEntries() as PerformanceLongAnimationFrameTiming[]) { @@ -152,6 +153,17 @@ export function startTrackingLongAnimationFrames(): void { } const startTime = msToSec((browserPerformanceTimeOrigin as number) + entry.startTime); + + const { start_timestamp: parentStartTimestamp, op: parentOp } = spanToJSON(parent); + + if (parentOp === 'navigation' && parentStartTimestamp && startTime < parentStartTimestamp) { + // Skip adding the span if the long task started before the navigation started. + // `startAndEndSpan` will otherwise adjust the parent's start time to the span's start + // time, potentially skewing the duration of the actual navigation as reported via our + // routing instrumentations + continue; + } + const duration = msToSec(entry.duration); const attributes: SpanAttributes = { @@ -172,15 +184,11 @@ export function startTrackingLongAnimationFrames(): void { attributes['browser.script.source_char_position'] = sourceCharPosition; } - const span = startInactiveSpan({ + startAndEndSpan(parent, startTime, startTime + duration, { name: 'Main UI thread blocked', op: 'ui.long-animation-frame', - startTime, attributes, }); - if (span) { - span.end(startTime + duration); - } } }); From 931e3a352fd5a909eb4a858a53a8fbe294b47805 Mon Sep 17 00:00:00 2001 From: Lukas Stracke Date: Tue, 5 Nov 2024 15:31:46 +0100 Subject: [PATCH 2/2] fix comment --- packages/browser-utils/src/metrics/browserMetrics.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/browser-utils/src/metrics/browserMetrics.ts b/packages/browser-utils/src/metrics/browserMetrics.ts index 53751711044b..f12e5c154ae8 100644 --- a/packages/browser-utils/src/metrics/browserMetrics.ts +++ b/packages/browser-utils/src/metrics/browserMetrics.ts @@ -157,7 +157,7 @@ export function startTrackingLongAnimationFrames(): void { const { start_timestamp: parentStartTimestamp, op: parentOp } = spanToJSON(parent); if (parentOp === 'navigation' && parentStartTimestamp && startTime < parentStartTimestamp) { - // Skip adding the span if the long task started before the navigation started. + // Skip adding the span if the long animation frame started before the navigation started. // `startAndEndSpan` will otherwise adjust the parent's start time to the span's start // time, potentially skewing the duration of the actual navigation as reported via our // routing instrumentations