From b0c000440f1f8c04e7a075ef5fa9529c9b4b2918 Mon Sep 17 00:00:00 2001 From: Francesco Gringl-Novy Date: Thu, 9 Jan 2025 11:44:44 +0100 Subject: [PATCH] feat(core): Emit client reports for unsampled root spans on span start (#14936) With this PR, the `sample_rate`,`transaction` client report is now consistently emitted at the time when the root span is sampled. Previously, in Node (OTEL) we did not emit this at all, while in browser we emit it at span end time. This is inconsistent and not ideal. Emitting it in OTEL at span end time is difficult because `span.end()` is a no-op there and you do not get access to it anywhere. So doing it at span start (=sample time) is easier, and also makes more sense as this is also actually the time when the span is dropped. --- .../tracing/requests/http-unsampled/test.ts | 1 + packages/core/src/tracing/idleSpan.ts | 6 + packages/core/src/tracing/sentrySpan.ts | 9 -- packages/core/src/tracing/trace.ts | 6 + packages/opentelemetry/src/sampler.ts | 5 + .../opentelemetry/test/helpers/TestClient.ts | 3 +- .../test/integration/breadcrumbs.test.ts | 10 +- .../test/integration/scope.test.ts | 6 +- .../test/integration/transactions.test.ts | 14 +- .../opentelemetry/test/propagator.test.ts | 2 +- packages/opentelemetry/test/sampler.test.ts | 136 ++++++++++++++++++ .../opentelemetry/test/spanExporter.test.ts | 2 +- packages/opentelemetry/test/trace.test.ts | 10 +- .../test/utils/getActiveSpan.test.ts | 2 +- .../test/utils/setupEventContextTrace.test.ts | 2 +- 15 files changed, 181 insertions(+), 33 deletions(-) create mode 100644 packages/opentelemetry/test/sampler.test.ts diff --git a/dev-packages/node-integration-tests/suites/tracing/requests/http-unsampled/test.ts b/dev-packages/node-integration-tests/suites/tracing/requests/http-unsampled/test.ts index 3d2e0e421863..0574693d9961 100644 --- a/dev-packages/node-integration-tests/suites/tracing/requests/http-unsampled/test.ts +++ b/dev-packages/node-integration-tests/suites/tracing/requests/http-unsampled/test.ts @@ -27,6 +27,7 @@ test('outgoing http requests are correctly instrumented when not sampled', done .then(([SERVER_URL, closeTestServer]) => { createRunner(__dirname, 'scenario.ts') .withEnv({ SERVER_URL }) + .ignore('client_report') .expect({ event: { exception: { diff --git a/packages/core/src/tracing/idleSpan.ts b/packages/core/src/tracing/idleSpan.ts index 14bce971b5b0..c37ef7b388a1 100644 --- a/packages/core/src/tracing/idleSpan.ts +++ b/packages/core/src/tracing/idleSpan.ts @@ -124,6 +124,12 @@ export function startIdleSpan(startSpanOptions: StartSpanOptions, options: Parti beforeSpanEnd(span); } + // If the span is non-recording, nothing more to do here... + // This is the case if tracing is enabled but this specific span was not sampled + if (thisArg instanceof SentryNonRecordingSpan) { + return; + } + // Just ensuring that this keeps working, even if we ever have more arguments here const [definedEndTimestamp, ...rest] = args; const timestamp = definedEndTimestamp || timestampInSeconds(); diff --git a/packages/core/src/tracing/sentrySpan.ts b/packages/core/src/tracing/sentrySpan.ts index 309f46ff874c..acc14d37bc31 100644 --- a/packages/core/src/tracing/sentrySpan.ts +++ b/packages/core/src/tracing/sentrySpan.ts @@ -333,17 +333,8 @@ export class SentrySpan implements Span { } const { scope: capturedSpanScope, isolationScope: capturedSpanIsolationScope } = getCapturedScopesOnSpan(this); - const scope = capturedSpanScope || getCurrentScope(); - const client = scope.getClient() || getClient(); if (this._sampled !== true) { - // At this point if `sampled !== true` we want to discard the transaction. - DEBUG_BUILD && logger.log('[Tracing] Discarding transaction because its trace was not chosen to be sampled.'); - - if (client) { - client.recordDroppedEvent('sample_rate', 'transaction'); - } - return undefined; } diff --git a/packages/core/src/tracing/trace.ts b/packages/core/src/tracing/trace.ts index f17867a4e32d..455eb470be23 100644 --- a/packages/core/src/tracing/trace.ts +++ b/packages/core/src/tracing/trace.ts @@ -395,6 +395,12 @@ function _startRootSpan(spanArguments: SentrySpanArguments, scope: Scope, parent }, sampled, }); + + if (!sampled && client) { + DEBUG_BUILD && logger.log('[Tracing] Discarding root span because its trace was not chosen to be sampled.'); + client.recordDroppedEvent('sample_rate', 'transaction'); + } + if (sampleRate !== undefined) { rootSpan.setAttribute(SEMANTIC_ATTRIBUTE_SENTRY_SAMPLE_RATE, sampleRate); } diff --git a/packages/opentelemetry/src/sampler.ts b/packages/opentelemetry/src/sampler.ts index 2ce16d276e73..076fa64a1d37 100644 --- a/packages/opentelemetry/src/sampler.ts +++ b/packages/opentelemetry/src/sampler.ts @@ -120,6 +120,11 @@ export class SentrySampler implements Sampler { } if (!sampled) { + if (parentSampled === undefined) { + DEBUG_BUILD && logger.log('[Tracing] Discarding root span because its trace was not chosen to be sampled.'); + this._client.recordDroppedEvent('sample_rate', 'transaction'); + } + return { ...wrapSamplingDecision({ decision: SamplingDecision.NOT_RECORD, context, spanAttributes }), attributes, diff --git a/packages/opentelemetry/test/helpers/TestClient.ts b/packages/opentelemetry/test/helpers/TestClient.ts index a60ff8eee831..5089dd160768 100644 --- a/packages/opentelemetry/test/helpers/TestClient.ts +++ b/packages/opentelemetry/test/helpers/TestClient.ts @@ -33,7 +33,7 @@ export const TestClient = wrapClientClass(BaseTestClient); export type TestClientInterface = Client & OpenTelemetryClient; export function init(options: Partial = {}): void { - const client = new TestClient(getDefaultTestClientOptions(options)); + const client = new TestClient(getDefaultTestClientOptions({ tracesSampleRate: 1, ...options })); // The client is on the current scope, from where it generally is inherited getCurrentScope().setClient(client); @@ -42,7 +42,6 @@ export function init(options: Partial = {}): void { export function getDefaultTestClientOptions(options: Partial = {}): ClientOptions { return { - enableTracing: true, integrations: [], transport: () => createTransport({ recordDroppedEvent: () => undefined }, _ => resolvedSyncPromise({})), stackParser: () => [], diff --git a/packages/opentelemetry/test/integration/breadcrumbs.test.ts b/packages/opentelemetry/test/integration/breadcrumbs.test.ts index 9da0f4d6e240..aef5149b8920 100644 --- a/packages/opentelemetry/test/integration/breadcrumbs.test.ts +++ b/packages/opentelemetry/test/integration/breadcrumbs.test.ts @@ -98,7 +98,7 @@ describe('Integration | breadcrumbs', () => { const beforeSend = jest.fn(() => null); const beforeBreadcrumb = jest.fn(breadcrumb => breadcrumb); - mockSdkInit({ beforeSend, beforeBreadcrumb, beforeSendTransaction, enableTracing: true }); + mockSdkInit({ beforeSend, beforeBreadcrumb, beforeSendTransaction, tracesSampleRate: 1 }); const client = getClient() as TestClientInterface; @@ -143,7 +143,7 @@ describe('Integration | breadcrumbs', () => { const beforeSend = jest.fn(() => null); const beforeBreadcrumb = jest.fn(breadcrumb => breadcrumb); - mockSdkInit({ beforeSend, beforeBreadcrumb, beforeSendTransaction, enableTracing: true }); + mockSdkInit({ beforeSend, beforeBreadcrumb, beforeSendTransaction, tracesSampleRate: 1 }); const client = getClient() as TestClientInterface; @@ -195,7 +195,7 @@ describe('Integration | breadcrumbs', () => { const beforeSend = jest.fn(() => null); const beforeBreadcrumb = jest.fn(breadcrumb => breadcrumb); - mockSdkInit({ beforeSend, beforeBreadcrumb, beforeSendTransaction, enableTracing: true }); + mockSdkInit({ beforeSend, beforeBreadcrumb, beforeSendTransaction, tracesSampleRate: 1 }); const client = getClient() as TestClientInterface; @@ -236,7 +236,7 @@ describe('Integration | breadcrumbs', () => { const beforeSend = jest.fn(() => null); const beforeBreadcrumb = jest.fn(breadcrumb => breadcrumb); - mockSdkInit({ beforeSend, beforeBreadcrumb, beforeSendTransaction, enableTracing: true }); + mockSdkInit({ beforeSend, beforeBreadcrumb, beforeSendTransaction, tracesSampleRate: 1 }); const client = getClient() as TestClientInterface; @@ -294,7 +294,7 @@ describe('Integration | breadcrumbs', () => { const beforeSend = jest.fn(() => null); const beforeBreadcrumb = jest.fn(breadcrumb => breadcrumb); - mockSdkInit({ beforeSend, beforeBreadcrumb, beforeSendTransaction, enableTracing: true }); + mockSdkInit({ beforeSend, beforeBreadcrumb, beforeSendTransaction, tracesSampleRate: 1 }); const client = getClient() as TestClientInterface; diff --git a/packages/opentelemetry/test/integration/scope.test.ts b/packages/opentelemetry/test/integration/scope.test.ts index c2e3dcc86701..b7577aa36044 100644 --- a/packages/opentelemetry/test/integration/scope.test.ts +++ b/packages/opentelemetry/test/integration/scope.test.ts @@ -26,7 +26,11 @@ describe('Integration | Scope', () => { const beforeSend = jest.fn(() => null); const beforeSendTransaction = jest.fn(() => null); - mockSdkInit({ enableTracing, beforeSend, beforeSendTransaction }); + mockSdkInit({ + tracesSampleRate: enableTracing ? 1 : 0, + beforeSend, + beforeSendTransaction, + }); const client = getClient() as TestClientInterface; diff --git a/packages/opentelemetry/test/integration/transactions.test.ts b/packages/opentelemetry/test/integration/transactions.test.ts index fe24f49a9bf1..3e299574d51b 100644 --- a/packages/opentelemetry/test/integration/transactions.test.ts +++ b/packages/opentelemetry/test/integration/transactions.test.ts @@ -37,7 +37,7 @@ describe('Integration | Transactions', () => { }); mockSdkInit({ - enableTracing: true, + tracesSampleRate: 1, beforeSendTransaction, release: '8.0.0', }); @@ -178,7 +178,7 @@ describe('Integration | Transactions', () => { it('correctly creates concurrent transaction & spans', async () => { const beforeSendTransaction = jest.fn(() => null); - mockSdkInit({ enableTracing: true, beforeSendTransaction }); + mockSdkInit({ tracesSampleRate: 1, beforeSendTransaction }); const client = getClient() as TestClientInterface; @@ -339,7 +339,7 @@ describe('Integration | Transactions', () => { traceState, }; - mockSdkInit({ enableTracing: true, beforeSendTransaction }); + mockSdkInit({ tracesSampleRate: 1, beforeSendTransaction }); const client = getClient() as TestClientInterface; @@ -443,7 +443,7 @@ describe('Integration | Transactions', () => { const logs: unknown[] = []; jest.spyOn(logger, 'log').mockImplementation(msg => logs.push(msg)); - mockSdkInit({ enableTracing: true, beforeSendTransaction }); + mockSdkInit({ tracesSampleRate: 1, beforeSendTransaction }); const provider = getProvider(); const multiSpanProcessor = provider?.activeSpanProcessor as @@ -516,7 +516,7 @@ describe('Integration | Transactions', () => { const transactions: Event[] = []; mockSdkInit({ - enableTracing: true, + tracesSampleRate: 1, beforeSendTransaction: event => { transactions.push(event); return null; @@ -573,7 +573,7 @@ describe('Integration | Transactions', () => { const transactions: Event[] = []; mockSdkInit({ - enableTracing: true, + tracesSampleRate: 1, beforeSendTransaction: event => { transactions.push(event); return null; @@ -644,7 +644,7 @@ describe('Integration | Transactions', () => { }; mockSdkInit({ - enableTracing: true, + tracesSampleRate: 1, beforeSendTransaction, release: '7.0.0', }); diff --git a/packages/opentelemetry/test/propagator.test.ts b/packages/opentelemetry/test/propagator.test.ts index 4e7a68689a0e..13d90e963f8a 100644 --- a/packages/opentelemetry/test/propagator.test.ts +++ b/packages/opentelemetry/test/propagator.test.ts @@ -25,7 +25,7 @@ describe('SentryPropagator', () => { mockSdkInit({ environment: 'production', release: '1.0.0', - enableTracing: true, + tracesSampleRate: 1, dsn: 'https://abc@domain/123', }); }); diff --git a/packages/opentelemetry/test/sampler.test.ts b/packages/opentelemetry/test/sampler.test.ts new file mode 100644 index 000000000000..ece4cfd8b087 --- /dev/null +++ b/packages/opentelemetry/test/sampler.test.ts @@ -0,0 +1,136 @@ +import { SpanKind, context, trace } from '@opentelemetry/api'; +import { TraceState } from '@opentelemetry/core'; +import { SamplingDecision } from '@opentelemetry/sdk-trace-base'; +import { ATTR_HTTP_REQUEST_METHOD } from '@opentelemetry/semantic-conventions'; +import { generateSpanId, generateTraceId } from '@sentry/core'; +import { SENTRY_TRACE_STATE_SAMPLED_NOT_RECORDING } from '../src/constants'; +import { SentrySampler } from '../src/sampler'; +import { TestClient, getDefaultTestClientOptions } from './helpers/TestClient'; +import { cleanupOtel } from './helpers/mockSdkInit'; + +describe('SentrySampler', () => { + afterEach(() => { + cleanupOtel(); + }); + + it('works with tracesSampleRate=0', () => { + const client = new TestClient(getDefaultTestClientOptions({ tracesSampleRate: 0 })); + const spyOnDroppedEvent = jest.spyOn(client, 'recordDroppedEvent'); + const sampler = new SentrySampler(client); + + const ctx = context.active(); + const traceId = generateTraceId(); + const spanName = 'test'; + const spanKind = SpanKind.INTERNAL; + const spanAttributes = {}; + const links = undefined; + + const actual = sampler.shouldSample(ctx, traceId, spanName, spanKind, spanAttributes, links); + expect(actual).toEqual({ + decision: SamplingDecision.NOT_RECORD, + attributes: { 'sentry.sample_rate': 0 }, + traceState: new TraceState().set('sentry.sampled_not_recording', '1'), + }); + expect(spyOnDroppedEvent).toHaveBeenCalledTimes(1); + expect(spyOnDroppedEvent).toHaveBeenCalledWith('sample_rate', 'transaction'); + + spyOnDroppedEvent.mockReset(); + }); + + it('works with tracesSampleRate=0 & for a child span', () => { + const client = new TestClient(getDefaultTestClientOptions({ tracesSampleRate: 0 })); + const spyOnDroppedEvent = jest.spyOn(client, 'recordDroppedEvent'); + const sampler = new SentrySampler(client); + + const traceId = generateTraceId(); + const ctx = trace.setSpanContext(context.active(), { + spanId: generateSpanId(), + traceId, + traceFlags: 0, + traceState: new TraceState().set(SENTRY_TRACE_STATE_SAMPLED_NOT_RECORDING, '1'), + }); + const spanName = 'test'; + const spanKind = SpanKind.INTERNAL; + const spanAttributes = {}; + const links = undefined; + + const actual = sampler.shouldSample(ctx, traceId, spanName, spanKind, spanAttributes, links); + expect(actual).toEqual({ + decision: SamplingDecision.NOT_RECORD, + attributes: { 'sentry.sample_rate': 0 }, + traceState: new TraceState().set(SENTRY_TRACE_STATE_SAMPLED_NOT_RECORDING, '1'), + }); + expect(spyOnDroppedEvent).toHaveBeenCalledTimes(0); + + spyOnDroppedEvent.mockReset(); + }); + + it('works with tracesSampleRate=1', () => { + const client = new TestClient(getDefaultTestClientOptions({ tracesSampleRate: 1 })); + const spyOnDroppedEvent = jest.spyOn(client, 'recordDroppedEvent'); + const sampler = new SentrySampler(client); + + const ctx = context.active(); + const traceId = generateTraceId(); + const spanName = 'test'; + const spanKind = SpanKind.INTERNAL; + const spanAttributes = {}; + const links = undefined; + + const actual = sampler.shouldSample(ctx, traceId, spanName, spanKind, spanAttributes, links); + expect(actual).toEqual({ + decision: SamplingDecision.RECORD_AND_SAMPLED, + attributes: { 'sentry.sample_rate': 1 }, + traceState: new TraceState(), + }); + expect(spyOnDroppedEvent).toHaveBeenCalledTimes(0); + + spyOnDroppedEvent.mockReset(); + }); + + it('works with traceSampleRate=undefined', () => { + const client = new TestClient(getDefaultTestClientOptions({ tracesSampleRate: undefined })); + const spyOnDroppedEvent = jest.spyOn(client, 'recordDroppedEvent'); + const sampler = new SentrySampler(client); + + const ctx = context.active(); + const traceId = generateTraceId(); + const spanName = 'test'; + const spanKind = SpanKind.INTERNAL; + const spanAttributes = {}; + const links = undefined; + + const actual = sampler.shouldSample(ctx, traceId, spanName, spanKind, spanAttributes, links); + expect(actual).toEqual({ + decision: SamplingDecision.NOT_RECORD, + traceState: new TraceState(), + }); + expect(spyOnDroppedEvent).toHaveBeenCalledTimes(0); + + spyOnDroppedEvent.mockReset(); + }); + + it('ignores local http client root spans', () => { + const client = new TestClient(getDefaultTestClientOptions({ tracesSampleRate: 0 })); + const spyOnDroppedEvent = jest.spyOn(client, 'recordDroppedEvent'); + const sampler = new SentrySampler(client); + + const ctx = context.active(); + const traceId = generateTraceId(); + const spanName = 'test'; + const spanKind = SpanKind.CLIENT; + const spanAttributes = { + [ATTR_HTTP_REQUEST_METHOD]: 'GET', + }; + const links = undefined; + + const actual = sampler.shouldSample(ctx, traceId, spanName, spanKind, spanAttributes, links); + expect(actual).toEqual({ + decision: SamplingDecision.NOT_RECORD, + traceState: new TraceState(), + }); + expect(spyOnDroppedEvent).toHaveBeenCalledTimes(0); + + spyOnDroppedEvent.mockReset(); + }); +}); diff --git a/packages/opentelemetry/test/spanExporter.test.ts b/packages/opentelemetry/test/spanExporter.test.ts index 737171da8908..48ab8da060de 100644 --- a/packages/opentelemetry/test/spanExporter.test.ts +++ b/packages/opentelemetry/test/spanExporter.test.ts @@ -6,7 +6,7 @@ import { cleanupOtel, mockSdkInit } from './helpers/mockSdkInit'; describe('createTransactionForOtelSpan', () => { beforeEach(() => { mockSdkInit({ - enableTracing: true, + tracesSampleRate: 1, }); }); diff --git a/packages/opentelemetry/test/trace.test.ts b/packages/opentelemetry/test/trace.test.ts index cbded44a6139..293036a93964 100644 --- a/packages/opentelemetry/test/trace.test.ts +++ b/packages/opentelemetry/test/trace.test.ts @@ -34,7 +34,7 @@ import { cleanupOtel, mockSdkInit } from './helpers/mockSdkInit'; describe('trace', () => { beforeEach(() => { - mockSdkInit({ enableTracing: true }); + mockSdkInit({ tracesSampleRate: 1 }); }); afterEach(() => { @@ -1138,7 +1138,7 @@ describe('trace', () => { describe('trace (tracing disabled)', () => { beforeEach(() => { - mockSdkInit({ enableTracing: false }); + mockSdkInit({ tracesSampleRate: 0 }); }); afterEach(() => { @@ -1475,7 +1475,7 @@ describe('trace (sampling)', () => { describe('HTTP methods (sampling)', () => { beforeEach(() => { - mockSdkInit({ enableTracing: true }); + mockSdkInit({ tracesSampleRate: 1 }); }); afterEach(() => { @@ -1530,7 +1530,7 @@ describe('HTTP methods (sampling)', () => { describe('continueTrace', () => { beforeEach(() => { - mockSdkInit({ enableTracing: true }); + mockSdkInit({ tracesSampleRate: 1 }); }); afterEach(() => { @@ -1631,7 +1631,7 @@ describe('continueTrace', () => { describe('suppressTracing', () => { beforeEach(() => { - mockSdkInit({ enableTracing: true }); + mockSdkInit({ tracesSampleRate: 1 }); }); afterEach(() => { diff --git a/packages/opentelemetry/test/utils/getActiveSpan.test.ts b/packages/opentelemetry/test/utils/getActiveSpan.test.ts index 9921f82f2982..b4e0efd32cd0 100644 --- a/packages/opentelemetry/test/utils/getActiveSpan.test.ts +++ b/packages/opentelemetry/test/utils/getActiveSpan.test.ts @@ -96,7 +96,7 @@ describe('getRootSpan', () => { let provider: BasicTracerProvider | undefined; beforeEach(() => { - const client = new TestClient(getDefaultTestClientOptions()); + const client = new TestClient(getDefaultTestClientOptions({ tracesSampleRate: 1 })); provider = setupOtel(client); }); diff --git a/packages/opentelemetry/test/utils/setupEventContextTrace.test.ts b/packages/opentelemetry/test/utils/setupEventContextTrace.test.ts index 95c68e5416f1..34c41ad0ef7f 100644 --- a/packages/opentelemetry/test/utils/setupEventContextTrace.test.ts +++ b/packages/opentelemetry/test/utils/setupEventContextTrace.test.ts @@ -18,7 +18,7 @@ describe('setupEventContextTrace', () => { client = new TestClient( getDefaultTestClientOptions({ sampleRate: 1, - enableTracing: true, + tracesSampleRate: 1, beforeSend, debug: true, dsn: PUBLIC_DSN,