From cbddc47078077e9614520ea2ef2a34a53842a38a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Kamil=20Og=C3=B3rek?= Date: Thu, 28 Jan 2021 16:47:30 +0100 Subject: [PATCH 1/3] fix: Clear activeTransaction from the scope and always start idle timers --- .../tracing/src/browser/browsertracing.ts | 3 ++- packages/tracing/src/idletransaction.ts | 22 +++++++++---------- packages/tracing/test/idletransaction.test.ts | 18 ++++++++++----- 3 files changed, 25 insertions(+), 18 deletions(-) diff --git a/packages/tracing/src/browser/browsertracing.ts b/packages/tracing/src/browser/browsertracing.ts index 921204bf33bd..05370b8e384d 100644 --- a/packages/tracing/src/browser/browsertracing.ts +++ b/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); diff --git a/packages/tracing/src/idletransaction.ts b/packages/tracing/src/idletransaction.ts index 4c3debf2da6d..c30f8170769c 100644 --- a/packages/tracing/src/idletransaction.ts +++ b/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; diff --git a/packages/tracing/test/idletransaction.test.ts b/packages/tracing/test/idletransaction.test.ts index aa68c90d6b73..e55cdfd82f0b 100644 --- a/packages/tracing/test/idletransaction.test.ts +++ b/packages/tracing/test/idletransaction.test.ts @@ -150,7 +150,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 +159,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); + 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); }); From 841bbccbd5ac01755fa300579a82bf08bf798cee Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Kamil=20Og=C3=B3rek?= Date: Mon, 1 Feb 2021 12:03:37 +0100 Subject: [PATCH 2/3] Test description reworded --- packages/tracing/test/idletransaction.test.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/tracing/test/idletransaction.test.ts b/packages/tracing/test/idletransaction.test.ts index e55cdfd82f0b..8adc831f2a2f 100644 --- a/packages/tracing/test/idletransaction.test.ts +++ b/packages/tracing/test/idletransaction.test.ts @@ -165,7 +165,7 @@ describe('IdleTransaction', () => { }); describe('heartbeat', () => { - it('does not start heartbeat if there is no span recorder', () => { + 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); From be2cce9a95c5f6ff989bad506736528d0e32e17e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Kamil=20Og=C3=B3rek?= Date: Mon, 1 Feb 2021 14:34:34 +0100 Subject: [PATCH 3/3] test: Add tests for removing unsampled transaction from scope --- packages/tracing/test/idletransaction.test.ts | 13 ++++++++++++- 1 file changed, 12 insertions(+), 1 deletion(-) diff --git a/packages/tracing/test/idletransaction.test.ts b/packages/tracing/test/idletransaction.test.ts index 8adc831f2a2f..d9a4f4cbe791 100644 --- a/packages/tracing/test/idletransaction.test.ts +++ b/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(() => {