fix: Clear activeTransaction from the scope and always start idle timers (#3215)

Author: kamilogorek

packages/tracing/src/browser/browsertracing.ts

@@ -208,6 +208,8 @@ export class BrowserTracing implements Integration {
       logger.log(`[Tracing] Will not send ${finalContext.op} transaction because of beforeNavigate.`);
     }
 
+    logger.log(`[Tracing] Starting ${finalContext.op} transaction on scope`);
+
     const hub = this._getCurrentHub();
     const { location } = getGlobalObject() as WindowOrWorkerGlobalScope & { location: Location };
 
@@ -218,7 +220,6 @@ export class BrowserTracing implements Integration {
       true,
       { location }, // for use in the tracesSampler
     );
-    logger.log(`[Tracing] Starting ${finalContext.op} transaction on scope`);
     idleTransaction.registerBeforeFinishCallback((transaction, endTimestamp) => {
       this._metrics.addPerformanceEntries(transaction);
       adjustTransactionDuration(secToMs(maxTransactionDuration), transaction, endTimestamp);

packages/tracing/src/idletransaction.ts

@@ -93,6 +93,12 @@ export class IdleTransaction extends Transaction {
       logger.log(`Setting idle transaction on scope. Span ID: ${this.spanId}`);
       _idleHub.configureScope(scope => scope.setSpan(this));
     }
+
+    this._initTimeout = setTimeout(() => {
+      if (!this._finished) {
+        this.finish();
+      }
+    }, this._idleTimeout);
   }
 
   /** {@inheritDoc} */
@@ -130,16 +136,16 @@ export class IdleTransaction extends Transaction {
         return keepSpan;
       });
 
-      // this._onScope is true if the transaction was previously on the scope.
-      if (this._onScope) {
-        clearActiveTransaction(this._idleHub);
-      }
-
       logger.log('[Tracing] flushing IdleTransaction');
     } else {
       logger.log('[Tracing] No active IdleTransaction');
     }
 
+    // this._onScope is true if the transaction was previously on the scope.
+    if (this._onScope) {
+      clearActiveTransaction(this._idleHub);
+    }
+
     return super.finish(endTimestamp);
   }
 
@@ -159,12 +165,6 @@ export class IdleTransaction extends Transaction {
    */
   public initSpanRecorder(maxlen?: number): void {
     if (!this.spanRecorder) {
-      this._initTimeout = setTimeout(() => {
-        if (!this._finished) {
-          this.finish();
-        }
-      }, this._idleTimeout);
-
       const pushActivity = (id: string): void => {
         if (this._finished) {
           return;

packages/tracing/test/idletransaction.test.ts

@@ -30,7 +30,7 @@ describe('IdleTransaction', () => {
       });
     });
 
-    it('removes transaction from scope on finish if onScope is true', () => {
+    it('removes sampled transaction from scope on finish if onScope is true', () => {
       const transaction = new IdleTransaction({ name: 'foo' }, hub, 1000, true);
       transaction.initSpanRecorder(10);
 
@@ -41,6 +41,17 @@ describe('IdleTransaction', () => {
         expect(s.getTransaction()).toBe(undefined);
       });
     });
+
+    it('removes unsampled transaction from scope on finish if onScope is true', () => {
+      const transaction = new IdleTransaction({ name: 'foo', sampled: false }, hub, 1000, true);
+
+      transaction.finish();
+      jest.runAllTimers();
+
+      hub.configureScope(s => {
+        expect(s.getTransaction()).toBe(undefined);
+      });
+    });
   });
 
   beforeEach(() => {
@@ -150,7 +161,7 @@ describe('IdleTransaction', () => {
       const transaction = new IdleTransaction({ name: 'foo', startTimestamp: 1234 }, hub, 1000);
       transaction.initSpanRecorder(10);
 
-      jest.runTimersToTime(DEFAULT_IDLE_TIMEOUT);
+      jest.advanceTimersByTime(DEFAULT_IDLE_TIMEOUT);
       expect(transaction.endTimestamp).toBeDefined();
     });
 
@@ -159,28 +170,34 @@ describe('IdleTransaction', () => {
       transaction.initSpanRecorder(10);
       transaction.startChild({});
 
-      jest.runTimersToTime(DEFAULT_IDLE_TIMEOUT);
+      jest.advanceTimersByTime(DEFAULT_IDLE_TIMEOUT);
       expect(transaction.endTimestamp).toBeUndefined();
     });
   });
 
   describe('heartbeat', () => {
-    it('does not start heartbeat if there is no span recorder', () => {
-      const transaction = new IdleTransaction({ name: 'foo' }, hub, 1000);
+    it('does not mark transaction as `DeadlineExceeded` if idle timeout has not been reached', () => {
+      const HEARTBEAT_INTERVAL = 5000;
+      // 20s to exceed 3 heartbeats
+      const transaction = new IdleTransaction({ name: 'foo' }, hub, 20000);
       const mockFinish = jest.spyOn(transaction, 'finish');
 
+      expect(transaction.status).not.toEqual(SpanStatus.DeadlineExceeded);
       expect(mockFinish).toHaveBeenCalledTimes(0);
 
       // Beat 1
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
+      expect(transaction.status).not.toEqual(SpanStatus.DeadlineExceeded);
       expect(mockFinish).toHaveBeenCalledTimes(0);
 
       // Beat 2
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
+      expect(transaction.status).not.toEqual(SpanStatus.DeadlineExceeded);
       expect(mockFinish).toHaveBeenCalledTimes(0);
 
       // Beat 3
-      jest.runOnlyPendingTimers();
+      jest.advanceTimersByTime(HEARTBEAT_INTERVAL);
+      expect(transaction.status).not.toEqual(SpanStatus.DeadlineExceeded);
       expect(mockFinish).toHaveBeenCalledTimes(0);
     });