fix(tracing-internal): Delay pageload transaction finish until document is interactive (#10215)

Author: Luca Forstner

dev-packages/browser-integration-tests/suites/tracing/browsertracing/pageloadWithHeartbeatTimeout/init.js

@@ -0,0 +1,15 @@
+import * as Sentry from '@sentry/browser';
+import { startSpanManual } from '@sentry/browser';
+import { Integrations } from '@sentry/tracing';
+
+window.Sentry = Sentry;
+
+Sentry.init({
+  dsn: 'https://[email protected]/1337',
+  integrations: [new Integrations.BrowserTracing()],
+  tracesSampleRate: 1,
+});
+
+setTimeout(() => {
+  startSpanManual({ name: 'pageload-child-span' }, () => {});
+}, 200);

dev-packages/browser-integration-tests/suites/tracing/browsertracing/pageloadWithHeartbeatTimeout/test.ts

@@ -0,0 +1,27 @@
+import { expect } from '@playwright/test';
+import type { Event } from '@sentry/types';
+
+import { sentryTest } from '../../../../utils/fixtures';
+import { getFirstSentryEnvelopeRequest, shouldSkipTracingTest } from '../../../../utils/helpers';
+
+// This tests asserts that the pageload transaction will finish itself after about 15 seconds (3x5s of heartbeats) if it
+// has a child span without adding any additional ones or finishing any of them finishing. All of the child spans that
+// are still running should have the status "cancelled".
+sentryTest(
+  'should send a pageload transaction terminated via heartbeat timeout',
+  async ({ getLocalTestPath, page }) => {
+    if (shouldSkipTracingTest()) {
+      sentryTest.skip();
+    }
+
+    const url = await getLocalTestPath({ testDir: __dirname });
+
+    const eventData = await getFirstSentryEnvelopeRequest<Event>(page, url);
+
+    expect(eventData.contexts?.trace?.op).toBe('pageload');
+    expect(
+      // eslint-disable-next-line deprecation/deprecation
+      eventData.spans?.find(span => span.description === 'pageload-child-span' && span.status === 'cancelled'),
+    ).toBeDefined();
+  },
+);

packages/core/src/tracing/hubextensions.ts

@@ -89,13 +89,22 @@ export function startIdleTransaction(
   onScope?: boolean,
   customSamplingContext?: CustomSamplingContext,
   heartbeatInterval?: number,
+  delayAutoFinishUntilSignal: boolean = false,
 ): IdleTransaction {
   // eslint-disable-next-line deprecation/deprecation
   const client = hub.getClient();
   const options: Partial<ClientOptions> = (client && client.getOptions()) || {};
 
   // eslint-disable-next-line deprecation/deprecation
-  let transaction = new IdleTransaction(transactionContext, hub, idleTimeout, finalTimeout, heartbeatInterval, onScope);
+  let transaction = new IdleTransaction(
+    transactionContext,
+    hub,
+    idleTimeout,
+    finalTimeout,
+    heartbeatInterval,
+    onScope,
+    delayAutoFinishUntilSignal,
+  );
   transaction = sampleTransaction(transaction, options, {
     parentSampled: transactionContext.parentSampled,
     transactionContext,

packages/core/src/tracing/idletransaction.ts

@@ -95,6 +95,8 @@ export class IdleTransaction extends Transaction {
 
   private _finishReason: (typeof IDLE_TRANSACTION_FINISH_REASONS)[number];
 
+  private _autoFinishAllowed: boolean;
+
   /**
    * @deprecated Transactions will be removed in v8. Use spans instead.
    */
@@ -113,6 +115,15 @@ export class IdleTransaction extends Transaction {
     private readonly _heartbeatInterval: number = TRACING_DEFAULTS.heartbeatInterval,
     // Whether or not the transaction should put itself on the scope when it starts and pop itself off when it ends
     private readonly _onScope: boolean = false,
+    /**
+     * When set to `true`, will disable the idle timeout (`_idleTimeout` option) and heartbeat mechanisms (`_heartbeatInterval`
+     * option) until the `sendAutoFinishSignal()` method is called. The final timeout mechanism (`_finalTimeout` option)
+     * will not be affected by this option, meaning the transaction will definitely be finished when the final timeout is
+     * reached, no matter what this option is configured to.
+     *
+     * Defaults to `false`.
+     */
+    delayAutoFinishUntilSignal: boolean = false,
   ) {
     super(transactionContext, _idleHub);
 
@@ -122,6 +133,7 @@ export class IdleTransaction extends Transaction {
     this._idleTimeoutCanceledPermanently = false;
     this._beforeFinishCallbacks = [];
     this._finishReason = IDLE_TRANSACTION_FINISH_REASONS[4];
+    this._autoFinishAllowed = !delayAutoFinishUntilSignal;
 
     if (_onScope) {
       // We set the transaction here on the scope so error events pick up the trace
@@ -131,7 +143,10 @@ export class IdleTransaction extends Transaction {
       _idleHub.getScope().setSpan(this);
     }
 
-    this._restartIdleTimeout();
+    if (!delayAutoFinishUntilSignal) {
+      this._restartIdleTimeout();
+    }
+
     setTimeout(() => {
       if (!this._finished) {
         this.setStatus('deadline_exceeded');
@@ -217,7 +232,7 @@ export class IdleTransaction extends Transaction {
   }
 
   /**
-   * Register a callback function that gets excecuted before the transaction finishes.
+   * Register a callback function that gets executed before the transaction finishes.
    * Useful for cleanup or if you want to add any additional spans based on current context.
    *
    * This is exposed because users have no other way of running something before an idle transaction
@@ -298,6 +313,17 @@ export class IdleTransaction extends Transaction {
     this._finishReason = reason;
   }
 
+  /**
+   * Permits the IdleTransaction to automatically end itself via the idle timeout and heartbeat mechanisms when the `delayAutoFinishUntilSignal` option was set to `true`.
+   */
+  public sendAutoFinishSignal(): void {
+    if (!this._autoFinishAllowed) {
+      DEBUG_BUILD && logger.log('[Tracing] Received finish signal for idle transaction.');
+      this._restartIdleTimeout();
+      this._autoFinishAllowed = true;
+    }
+  }
+
   /**
    * Restarts idle timeout, if there is no running idle timeout it will start one.
    */
@@ -337,8 +363,10 @@ export class IdleTransaction extends Transaction {
     if (Object.keys(this.activities).length === 0) {
       const endTimestamp = timestampInSeconds();
       if (this._idleTimeoutCanceledPermanently) {
-        this._finishReason = IDLE_TRANSACTION_FINISH_REASONS[5];
-        this.end(endTimestamp);
+        if (this._autoFinishAllowed) {
+          this._finishReason = IDLE_TRANSACTION_FINISH_REASONS[5];
+          this.end(endTimestamp);
+        }
       } else {
         // We need to add the timeout here to have the real endtimestamp of the transaction
         // Remember timestampInSeconds is in seconds, timeout is in ms
@@ -368,10 +396,12 @@ export class IdleTransaction extends Transaction {
     this._prevHeartbeatString = heartbeatString;
 
     if (this._heartbeatCounter >= 3) {
-      DEBUG_BUILD && logger.log('[Tracing] Transaction finished because of no change for 3 heart beats');
-      this.setStatus('deadline_exceeded');
-      this._finishReason = IDLE_TRANSACTION_FINISH_REASONS[0];
-      this.end();
+      if (this._autoFinishAllowed) {
+        DEBUG_BUILD && logger.log('[Tracing] Transaction finished because of no change for 3 heart beats');
+        this.setStatus('deadline_exceeded');
+        this._finishReason = IDLE_TRANSACTION_FINISH_REASONS[0];
+        this.end();
+      }
     } else {
       this._pingHeartbeat();
     }

packages/tracing-internal/src/browser/browsertracing.ts

@@ -368,8 +368,21 @@ export class BrowserTracing implements Integration {
       true,
       { location }, // for use in the tracesSampler
       heartbeatInterval,
+      isPageloadTransaction, // should wait for finish signal if it's a pageload transaction
     );
 
+    if (isPageloadTransaction) {
+      WINDOW.document.addEventListener('readystatechange', () => {
+        if (['interactive', 'complete'].includes(WINDOW.document.readyState)) {
+          idleTransaction.sendAutoFinishSignal();
+        }
+      });
+
+      if (['interactive', 'complete'].includes(WINDOW.document.readyState)) {
+        idleTransaction.sendAutoFinishSignal();
+      }
+    }
+
     // eslint-disable-next-line deprecation/deprecation
     const scope = hub.getScope();
 

packages/tracing-internal/test/browser/browsertracing.test.ts

@@ -411,6 +411,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => {
         expect.any(Boolean),
         expect.any(Object),
         expect.any(Number),
+        true,
       );
     });
 
@@ -419,6 +420,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => {
         createBrowserTracing(true, { routingInstrumentation: customInstrumentRouting });
         const mockFinish = jest.fn();
         const transaction = getActiveTransaction(hub) as IdleTransaction;
+        transaction.sendAutoFinishSignal();
         transaction.end = mockFinish;
 
         const span = transaction.startChild(); // activities = 1
@@ -433,6 +435,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => {
         createBrowserTracing(true, { idleTimeout: 2000, routingInstrumentation: customInstrumentRouting });
         const mockFinish = jest.fn();
         const transaction = getActiveTransaction(hub) as IdleTransaction;
+        transaction.sendAutoFinishSignal();
         transaction.end = mockFinish;
 
         const span = transaction.startChild(); // activities = 1
@@ -461,6 +464,7 @@ conditionalTest({ min: 10 })('BrowserTracing', () => {
         createBrowserTracing(true, { heartbeatInterval: interval, routingInstrumentation: customInstrumentRouting });
         const mockFinish = jest.fn();
         const transaction = getActiveTransaction(hub) as IdleTransaction;
+        transaction.sendAutoFinishSignal();
         transaction.end = mockFinish;
 
         const span = transaction.startChild(); // activities = 1