feat(tracing): Reset IdleTimeout based on activities count

AbhiPrasad · AbhiPrasad · commit 3dacee46af39 · 2022-02-11T09:32:22.000-05:00
diff --git a/packages/tracing/src/browser/browsertracing.ts b/packages/tracing/src/browser/browsertracing.ts
@@ -3,7 +3,7 @@ import { EventProcessor, Integration, Transaction, TransactionContext } from '@s
 import { getGlobalObject, logger } from '@sentry/utils';
 
 import { startIdleTransaction } from '../hubextensions';
-import { DEFAULT_IDLE_TIMEOUT, IdleTransaction } from '../idletransaction';
+import { DEFAULT_FINAL_TIMEOUT, DEFAULT_IDLE_TIMEOUT, IdleTransaction } from '../idletransaction';
 import { extractTraceparentData, secToMs } from '../utils';
 import { registerBackgroundTabDetection } from './backgroundtab';
 import { MetricsInstrumentation } from './metrics';
@@ -21,12 +21,23 @@ export interface BrowserTracingOptions extends RequestInstrumentationOptions {
   /**
    * The time to wait in ms until the transaction will be finished. The transaction will use the end timestamp of
    * the last finished span as the endtime for the transaction.
+   *
    * Time is in ms.
    *
    * Default: 1000
    */
   idleTimeout: number;
 
+  /**
+   * The max transaction duration for a transaction. If a transaction duration hits the `finalTimeout` value, it
+   * will be finished.
+   *
+   * Time is in ms.
+   *
+   * Default: 30000
+   */
+  finalTimeout: number;
+
   /**
    * Flag to enable/disable creation of `navigation` transaction on history changes.
    *
@@ -93,6 +104,7 @@ export interface BrowserTracingOptions extends RequestInstrumentationOptions {
 
 const DEFAULT_BROWSER_TRACING_OPTIONS = {
   idleTimeout: DEFAULT_IDLE_TIMEOUT,
+  finalTimeout: DEFAULT_FINAL_TIMEOUT,
   markBackgroundTransactions: true,
   maxTransactionDuration: DEFAULT_MAX_TRANSACTION_DURATION_SECONDS,
   routingInstrumentation: instrumentRoutingWithDefaults,
diff --git a/packages/tracing/src/constants.ts b/packages/tracing/src/constants.ts
@@ -2,4 +2,9 @@
 // Readonly type should enforce that this is not mutated.
 export const FINISH_REASON_TAG = 'finishReason';
 
-export const IDLE_TRANSACTION_FINISH_REASONS = ['heartbeatFailed', 'idleTimeout', 'documentHidden'] as const;
+export const IDLE_TRANSACTION_FINISH_REASONS = [
+  'heartbeatFailed',
+  'idleTimeout',
+  'documentHidden',
+  'finalTimeout',
+] as const;
diff --git a/packages/tracing/src/idletransaction.ts b/packages/tracing/src/idletransaction.ts
@@ -1,3 +1,4 @@
+/* eslint-disable max-lines */
 import { Hub } from '@sentry/hub';
 import { TransactionContext } from '@sentry/types';
 import { getGlobalObject, logger, timestampWithMs } from '@sentry/utils';
@@ -7,6 +8,7 @@ import { Span, SpanRecorder } from './span';
 import { Transaction } from './transaction';
 
 export const DEFAULT_IDLE_TIMEOUT = 1000;
+export const DEFAULT_FINAL_TIMEOUT = 30000;
 export const HEARTBEAT_INTERVAL = 5000;
 
 const global = getGlobalObject<Window>();
@@ -73,18 +75,29 @@ export class IdleTransaction extends Transaction {
    * If a transaction is created and no activities are added, we want to make sure that
    * it times out properly. This is cleared and not used when activities are added.
    */
-  private _initTimeout: ReturnType<typeof global.setTimeout> | undefined;
+  private _idleTimeoutID: ReturnType<typeof global.setTimeout> | undefined;
 
   public constructor(
     transactionContext: TransactionContext,
     private readonly _idleHub?: Hub,
     /**
      * The time to wait in ms until the idle transaction will be finished.
      * @default 1000
+     *
+     * TODO: Make _idleTimeout and _finalTimeout required to reduce duplication when setting the options
+     * in `BrowserTracing`. This is considered a breaking change to the IdleTransaction API,
+     * so we need to make sure we communicate it with react native.
      */
     private readonly _idleTimeout: number = DEFAULT_IDLE_TIMEOUT,
     // 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,
+    /**
+     * The final value that a transaction cannot exceed
+     * @default 15000
+     * @experimental
+     * @internal
+     */
+    private readonly _finalTimeout: number = DEFAULT_FINAL_TIMEOUT,
   ) {
     super(transactionContext, _idleHub);
 
@@ -98,11 +111,13 @@ export class IdleTransaction extends Transaction {
       _idleHub.configureScope(scope => scope.setSpan(this));
     }
 
-    this._initTimeout = global.setTimeout(() => {
+    this._startIdleTimeout();
+    global.setTimeout(() => {
       if (!this._finished) {
+        this.setTag(FINISH_REASON_TAG, IDLE_TRANSACTION_FINISH_REASONS[3]);
         this.finish();
       }
-    }, this._idleTimeout);
+    }, this._finalTimeout);
   }
 
   /** {@inheritDoc} */
@@ -191,15 +206,35 @@ export class IdleTransaction extends Transaction {
     this.spanRecorder.add(this);
   }
 
+  /**
+   * Creates an idletimeout
+   */
+  private _cancelIdleTimeout(): void {
+    if (this._idleTimeoutID) {
+      global.clearTimeout(this._idleTimeoutID);
+      this._idleTimeoutID = undefined;
+    }
+  }
+
+  /**
+   * Creates an idletimeout
+   */
+  private _startIdleTimeout(end?: Parameters<IdleTransaction['finish']>[0]): void {
+    this._cancelIdleTimeout();
+    this._idleTimeoutID = global.setTimeout(() => {
+      if (!this._finished && Object.keys(this.activities).length === 0) {
+        this.setTag(FINISH_REASON_TAG, IDLE_TRANSACTION_FINISH_REASONS[1]);
+        this.finish(end);
+      }
+    }, this._idleTimeout);
+  }
+
   /**
    * Start tracking a specific activity.
    * @param spanId The span id that represents the activity
    */
   private _pushActivity(spanId: string): void {
-    if (this._initTimeout) {
-      clearTimeout(this._initTimeout);
-      this._initTimeout = undefined;
-    }
+    this._cancelIdleTimeout();
     logger.log(`[Tracing] pushActivity: ${spanId}`);
     this.activities[spanId] = true;
     logger.log('[Tracing] new activities count', Object.keys(this.activities).length);
@@ -222,13 +257,7 @@ export class IdleTransaction extends Transaction {
       // We need to add the timeout here to have the real endtimestamp of the transaction
       // Remember timestampWithMs is in seconds, timeout is in ms
       const end = timestampWithMs() + timeout / 1000;
-
-      global.setTimeout(() => {
-        if (!this._finished) {
-          this.setTag(FINISH_REASON_TAG, IDLE_TRANSACTION_FINISH_REASONS[1]);
-          this.finish(end);
-        }
-      }, timeout);
+      this._startIdleTimeout(end);
     }
   }
 
diff --git a/packages/tracing/test/browser/browsertracing.test.ts b/packages/tracing/test/browser/browsertracing.test.ts
@@ -14,7 +14,7 @@ import { MetricsInstrumentation } from '../../src/browser/metrics';
 import { defaultRequestInstrumentationOptions } from '../../src/browser/request';
 import { instrumentRoutingWithDefaults } from '../../src/browser/router';
 import * as hubExtensions from '../../src/hubextensions';
-import { DEFAULT_IDLE_TIMEOUT, IdleTransaction } from '../../src/idletransaction';
+import { DEFAULT_IDLE_TIMEOUT, IdleTransaction, DEFAULT_FINAL_TIMEOUT } from '../../src/idletransaction';
 import { getActiveTransaction, secToMs } from '../../src/utils';
 
 let mockChangeHistory: ({ to, from }: { to: string; from?: string }) => void = () => undefined;
@@ -83,6 +83,7 @@ describe('BrowserTracing', () => {
 
     expect(browserTracing.options).toEqual({
       idleTimeout: DEFAULT_IDLE_TIMEOUT,
+      finalTimeout: DEFAULT_FINAL_TIMEOUT,
       markBackgroundTransactions: true,
       maxTransactionDuration: DEFAULT_MAX_TRANSACTION_DURATION_SECONDS,
       routingInstrumentation: instrumentRoutingWithDefaults,
diff --git a/packages/tracing/test/idletransaction.test.ts b/packages/tracing/test/idletransaction.test.ts
@@ -9,7 +9,16 @@ import {
 } from '../src/idletransaction';
 import { Span } from '../src/span';
 
-export class SimpleTransport extends Transports.BaseTransport {}
+type TransportSendRequest = Transports.BaseTransport['_sendRequest'];
+
+export class SimpleTransport extends Transports.BaseTransport {
+  protected _sendRequest(
+    _req: Parameters<TransportSendRequest>[0],
+    _payload: Parameters<TransportSendRequest>[1],
+  ): ReturnType<TransportSendRequest> {
+    throw new Error('Method not implemented.');
+  }
+}
 
 const dsn = 'https://123@sentry.io/42';
 let hub: Hub;
@@ -103,7 +112,7 @@ describe('IdleTransaction', () => {
 
     expect(transaction.activities).toMatchObject({ [span.spanId]: true, [childSpan.spanId]: true });
     span.finish();
-    jest.runOnlyPendingTimers();
+    jest.advanceTimersByTime(DEFAULT_IDLE_TIMEOUT + 1);
 
     expect(mockFinish).toHaveBeenCalledTimes(0);
     expect(transaction.activities).toMatchObject({ [childSpan.spanId]: true });
@@ -229,63 +238,63 @@ describe('IdleTransaction', () => {
       transaction.startChild({});
 
       // Beat 1
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
       expect(mockFinish).toHaveBeenCalledTimes(0);
 
       // Beat 2
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
       expect(mockFinish).toHaveBeenCalledTimes(0);
 
       // Beat 3
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
       expect(mockFinish).toHaveBeenCalledTimes(1);
     });
 
     it('resets after new activities are added', () => {
-      const transaction = new IdleTransaction({ name: 'foo' }, hub, DEFAULT_IDLE_TIMEOUT);
+      const transaction = new IdleTransaction({ name: 'foo' }, hub, DEFAULT_IDLE_TIMEOUT, false, 50000);
       const mockFinish = jest.spyOn(transaction, 'finish');
       transaction.initSpanRecorder(10);
 
       expect(mockFinish).toHaveBeenCalledTimes(0);
       transaction.startChild({});
 
       // Beat 1
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
       expect(mockFinish).toHaveBeenCalledTimes(0);
 
       const span = transaction.startChild(); // push activity
 
       // Beat 1
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
       expect(mockFinish).toHaveBeenCalledTimes(0);
 
       // Beat 2
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
       expect(mockFinish).toHaveBeenCalledTimes(0);
 
       transaction.startChild(); // push activity
       transaction.startChild(); // push activity
 
       // Beat 1
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
       expect(mockFinish).toHaveBeenCalledTimes(0);
 
       // Beat 2
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
       expect(mockFinish).toHaveBeenCalledTimes(0);
 
       span.finish(); // pop activity
 
       // Beat 1
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
       expect(mockFinish).toHaveBeenCalledTimes(0);
 
       // Beat 2
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
       expect(mockFinish).toHaveBeenCalledTimes(0);
 
       // Beat 3
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
       expect(mockFinish).toHaveBeenCalledTimes(1);
 
       // Heartbeat does not keep going after finish has been called
