diff --git a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/linked-traces/consistent-sampling/meta-negative/test.ts b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/linked-traces/consistent-sampling/meta-negative/test.ts index c8faee2f5feb..96048f405b6c 100644 --- a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/linked-traces/consistent-sampling/meta-negative/test.ts +++ b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/linked-traces/consistent-sampling/meta-negative/test.ts @@ -86,8 +86,15 @@ sentryTest.describe('When `consistentTraceSampling` is `true` and page contains quantity: 4, reason: 'sample_rate', }, + { + category: 'span', + quantity: expect.any(Number), + reason: 'sample_rate', + }, ], }); + // exact number depends on performance observer emissions + expect(clientReport.discarded_events[1].quantity).toBeGreaterThanOrEqual(10); }); await sentryTest.step('Wait for transactions to be discarded', async () => { diff --git a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/linked-traces/consistent-sampling/meta-precedence/test.ts b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/linked-traces/consistent-sampling/meta-precedence/test.ts index 3dab9594ba7c..374a1e81458b 100644 --- a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/linked-traces/consistent-sampling/meta-precedence/test.ts +++ b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/linked-traces/consistent-sampling/meta-precedence/test.ts @@ -75,8 +75,15 @@ sentryTest.describe('When `consistentTraceSampling` is `true` and page contains quantity: 2, reason: 'sample_rate', }, + { + category: 'span', + quantity: expect.any(Number), + reason: 'sample_rate', + }, ], }); + // exact number depends on performance observer emissions + expect(clientReport.discarded_events[1].quantity).toBeGreaterThanOrEqual(3); }); await sentryTest.step('Navigate to another page with meta tags', async () => { diff --git a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/linked-traces/consistent-sampling/tracesSampler-precedence/test.ts b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/linked-traces/consistent-sampling/tracesSampler-precedence/test.ts index 2bb196c898fd..81ad107f62e3 100644 --- a/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/linked-traces/consistent-sampling/tracesSampler-precedence/test.ts +++ b/dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/linked-traces/consistent-sampling/tracesSampler-precedence/test.ts @@ -58,6 +58,11 @@ sentryTest.describe('When `consistentTraceSampling` is `true`', () => { quantity: 1, reason: 'sample_rate', }, + { + category: 'span', + quantity: 1, + reason: 'sample_rate', + }, ], }); }); @@ -81,6 +86,11 @@ sentryTest.describe('When `consistentTraceSampling` is `true`', () => { quantity: 1, reason: 'sample_rate', }, + { + category: 'span', + quantity: 1, + reason: 'sample_rate', + }, ], }); }); diff --git a/dev-packages/node-integration-tests/suites/tracing/sampling-static/test.ts b/dev-packages/node-integration-tests/suites/tracing/sampling-static/test.ts index 0746817a92cc..83e83a46251e 100644 --- a/dev-packages/node-integration-tests/suites/tracing/sampling-static/test.ts +++ b/dev-packages/node-integration-tests/suites/tracing/sampling-static/test.ts @@ -7,7 +7,13 @@ describe('negative sampling (static)', () => { }); createEsmAndCjsTests(__dirname, 'server.mjs', 'instrument.mjs', (createRunner, test) => { - test('records sample_rate outcome for root span/transaction', async () => { + test('records sample_rate outcomes for the transaction and all of its spans', async () => { + // `/health` and `/ok` go through the same middleware, so the `/ok` transaction tells us how many + // spans the dropped `/health` transaction would have had. The count differs per runtime (e.g. Bun creates + // no Express spans), so we derive it instead of hardcoding it. + let okSpanCount: number | undefined; + let droppedSpanCount: number | undefined; + const runner = createRunner() .unignore('client_report') // The `GET /ok` transaction is sent as soon as its span ends, while the negatively-sampled @@ -16,19 +22,18 @@ describe('negative sampling (static)', () => { // match unordered instead of asserting a fixed sequence. .unordered() .expect({ - transaction: { - transaction: 'GET /ok', + transaction: transaction => { + expect(transaction.transaction).toBe('GET /ok'); + okSpanCount = 1 + (transaction.spans?.length ?? 0); }, }) .expect({ - client_report: { - discarded_events: [ - { - category: 'transaction', - quantity: 1, - reason: 'sample_rate', - }, - ], + client_report: clientReport => { + expect(clientReport.discarded_events).toEqual([ + { category: 'transaction', quantity: 1, reason: 'sample_rate' }, + { category: 'span', quantity: expect.any(Number), reason: 'sample_rate' }, + ]); + droppedSpanCount = clientReport.discarded_events[1]!.quantity; }, }) .start(); @@ -40,6 +45,8 @@ describe('negative sampling (static)', () => { expect((res2 as { status: string }).status).toBe('ok'); await runner.completed(); + + expect(droppedSpanCount).toBe(okSpanCount); }); }); }); diff --git a/packages/core/src/client.ts b/packages/core/src/client.ts index 12d02b348bb2..03ba13dff60e 100644 --- a/packages/core/src/client.ts +++ b/packages/core/src/client.ts @@ -1515,13 +1515,17 @@ export abstract class Client { const isError = isErrorEvent(event); const eventType = event.type || 'error'; const beforeSendLabel = `before send for type \`${eventType}\``; - let beforeSendDropReason: 'before_send' | 'callback_error' = 'before_send'; + let beforeSendDropReason: BeforeSendDropReason = 'before_send'; + let ignoredSpanCount = 0; // 1.0 === 100% events are sent // 0.0 === 0% events are sent // Sampling for transaction happens somewhere else const parsedSampleRate = typeof sampleRate === 'undefined' ? undefined : parseSampleRate(sampleRate); const dataCategory = getDataCategoryByType(event.type); + // Spans that event processors removed are already recorded in `prepareEvent`, so all later + // span outcomes are relative to the span count of the prepared event. + let preparedSpanCount = 0; return this._prepareEvent(event, hint, currentScope, isolationScope) .then(prepared => { @@ -1529,26 +1533,42 @@ export abstract class Client { throw _makeDoNotSendEventError('An event processor returned `null`, will not send event.'); } + preparedSpanCount = prepared.spans?.length || 0; + const isInternalException = (hint.data as { __sentry__: boolean })?.__sentry__ === true; if (isInternalException) { return prepared; } - const result = processBeforeSend(this, options, prepared, hint, () => { - beforeSendDropReason = 'callback_error'; - }); + const result = processBeforeSend( + options, + prepared, + hint, + reason => { + beforeSendDropReason = reason; + }, + count => { + ignoredSpanCount = count; + }, + ); return _validateBeforeSendResult(result, beforeSendLabel); }) .then(processedEvent => { + if (ignoredSpanCount) { + this.recordDroppedEvent('ignored', 'span', ignoredSpanCount); + } + if (processedEvent === null) { this.recordDroppedEvent(beforeSendDropReason, dataCategory); if (isTransaction) { - const spans = event.spans || []; - // the transaction itself counts as one span, plus all the child spans that are added - this.recordDroppedEvent(beforeSendDropReason, 'span', 1 + spans.length); + // the transaction itself counts as one span, plus all the child spans that weren't ignored before + this.recordDroppedEvent(beforeSendDropReason, 'span', 1 + preparedSpanCount - ignoredSpanCount); } - const dropMessage = beforeSendDropReason === 'callback_error' ? 'threw an error' : 'returned `null`'; - throw _makeDoNotSendEventError(`${beforeSendLabel} ${dropMessage}, will not send event.`); + const dropMessage = + beforeSendDropReason === 'ignored' + ? 'Transaction matched `ignoreSpans`' + : `${beforeSendLabel} ${beforeSendDropReason === 'callback_error' ? 'threw an error' : 'returned `null`'}`; + throw _makeDoNotSendEventError(`${dropMessage}, will not send event.`); } const session = currentScope.getSession() || isolationScope.getSession(); @@ -1564,10 +1584,7 @@ export abstract class Client { } if (isTransaction) { - const spanCountBefore = processedEvent.sdkProcessingMetadata?.spanCountBeforeProcessing || 0; - const spanCountAfter = processedEvent.spans ? processedEvent.spans.length : 0; - - const droppedSpanCount = spanCountBefore - spanCountAfter; + const droppedSpanCount = preparedSpanCount - ignoredSpanCount - (processedEvent.spans?.length || 0); if (droppedSpanCount > 0) { this.recordDroppedEvent('before_send', 'span', droppedSpanCount); } @@ -1717,15 +1734,17 @@ function _validateBeforeSendResult( return beforeSendResult; } +type BeforeSendDropReason = 'before_send' | 'callback_error' | 'ignored'; + /** * Process the matching `beforeSendXXX` callback. */ function processBeforeSend( - client: Client, options: ClientOptions, event: Event, hint: EventHint, - onCallbackError: () => void, + onDrop: (reason: Exclude) => void, + onIgnoredSpans: (count: number) => void, ): PromiseLike | Event | null { const { beforeSend, @@ -1743,7 +1762,7 @@ function processBeforeSend( DEBUG_BUILD ? 'The `beforeSend` callback threw an error, dropping the event:' : '', () => beforeSend(errorEvent, hint), () => { - onCallbackError(); + onDrop('callback_error'); return null; }, ); @@ -1763,7 +1782,7 @@ function processBeforeSend( ignoreSpans, ) ) { - // dropping the whole transaction! + onDrop('ignored'); return null; } @@ -1798,30 +1817,17 @@ function processBeforeSend( } } - const droppedSpans = processedEvent.spans.length - processedSpans.length; - if (droppedSpans) { - client.recordDroppedEvent('before_send', 'span', droppedSpans); - } - + onIgnoredSpans(initialSpans.length - processedSpans.length); processedEvent.spans = processedSpans; } } if (beforeSendTransaction) { - if (processedEvent.spans) { - // We store the # of spans before processing in SDK metadata, - // so we can compare it afterwards to determine how many spans were dropped - const spanCountBefore = processedEvent.spans.length; - processedEvent.sdkProcessingMetadata = { - ...event.sdkProcessingMetadata, - spanCountBeforeProcessing: spanCountBefore, - }; - } return safeCallback( DEBUG_BUILD ? 'The `beforeSendTransaction` callback threw an error, dropping the event:' : '', () => beforeSendTransaction(processedEvent as TransactionEvent, hint), () => { - onCallbackError(); + onDrop('callback_error'); return null; }, ); diff --git a/packages/core/src/scope.ts b/packages/core/src/scope.ts index d2fba52a8fc0..5ae6649c0a0c 100644 --- a/packages/core/src/scope.ts +++ b/packages/core/src/scope.ts @@ -62,7 +62,6 @@ export interface SdkProcessingMetadata { dynamicSamplingContext?: Partial; capturedSpanScope?: Scope; capturedSpanIsolationScope?: Scope; - spanCountBeforeProcessing?: number; ipAddress?: string; } diff --git a/packages/core/src/tracing/sentrySpan.ts b/packages/core/src/tracing/sentrySpan.ts index f0285f63eb27..f2a6064fa3c1 100644 --- a/packages/core/src/tracing/sentrySpan.ts +++ b/packages/core/src/tracing/sentrySpan.ts @@ -370,8 +370,6 @@ export class SentrySpan implements Span { } DEBUG_BUILD && debug.log('[Tracing] Discarding standalone span because its trace was not chosen to be sampled.'); - client.recordDroppedEvent('sample_rate', 'span'); - return; } diff --git a/packages/core/src/tracing/trace.ts b/packages/core/src/tracing/trace.ts index ff312712ee46..cb6f9f853184 100644 --- a/packages/core/src/tracing/trace.ts +++ b/packages/core/src/tracing/trace.ts @@ -308,7 +308,11 @@ export function startNewTrace(callback: () => T): T { */ function startMissingRequiredParentSpan(scope: Scope, client: Client | undefined): SentryNonRecordingSpan { client?.recordDroppedEvent('no_parent_span', 'span'); - const span = new SentryNonRecordingSpan({ traceId: scope.getPropagationContext().traceId }); + // Spans nested inside the placeholder inherit its drop reason in `_startChildSpan` + const span = new SentryNonRecordingSpan({ + dropReason: 'no_parent_span', + traceId: scope.getPropagationContext().traceId, + }); setCapturedScopesOnSpan(span, scope, getIsolationScope()); return span; } @@ -523,7 +527,14 @@ function _startRootSpan( if (!sampled && client && !_isTracingSuppressed) { DEBUG_BUILD && debug.log('[Tracing] Discarding root span because its trace was not chosen to be sampled.'); - client.recordDroppedEvent(dropReason || 'sample_rate', hasSpanStreamingEnabled(client) ? 'span' : 'transaction'); + const outcomeReason = dropReason || 'sample_rate'; + // A standalone span is sent on its own and never becomes a transaction. + // TODO(v12): Drop the `isStandalone` check once the static trace lifecycle is gone. + if (!hasSpanStreamingEnabled(client) && !spanArguments.isStandalone) { + client.recordDroppedEvent(outcomeReason, 'transaction'); + } + // Child spans of this root record their own `span` outcome in `_startChildSpan`. + client.recordDroppedEvent(outcomeReason, 'span'); } setCapturedScopesOnSpan(rootSpan, scope, isolationScope); @@ -568,11 +579,10 @@ function _startChildSpan( return childSpan; } - if (hasSpanStreamingEnabled(client) && spanIsNonRecordingSpan(childSpan)) { + if (spanIsNonRecordingSpan(childSpan)) { if (spanIsNonRecordingSpan(parentSpan) && parentSpan.dropReason) { - // We land here if the parent span was a segment span that was ignored (`ignoreSpans`). - // In this case, the child was also ignored (see `sampled` above) but we need to - // record a client outcome for the child. + // The parent was dropped for a reason other than sampling (e.g. an ignored segment span or + // an `onlyIfParent` placeholder), so the child is dropped for the same reason. childSpan.dropReason = parentSpan.dropReason; client.recordDroppedEvent(parentSpan.dropReason, 'span'); } else if (!_isTracingSuppressed) { diff --git a/packages/core/src/utils/prepareEvent.ts b/packages/core/src/utils/prepareEvent.ts index f00e90932135..4588056c3a54 100644 --- a/packages/core/src/utils/prepareEvent.ts +++ b/packages/core/src/utils/prepareEvent.ts @@ -110,6 +110,10 @@ export function prepareEvent( // Skip event processors for internal exceptions to prevent recursion // oxlint-disable-next-line typescript/prefer-optional-chain const isInternalException = hint.data && (hint.data as { __sentry__: boolean }).__sentry__ === true; + const isTransaction = event.type === 'transaction'; + // Snapshot the count rather than reading `event.spans` later: processors get a shallow copy of the + // event, so one that mutates `spans` in place also mutates the original array. + const spanCountBeforeProcessing = event.spans?.length || 0; const result: PromiseLike = isInternalException ? resolvedSyncPromise(prepared) : notifyEventProcessors(eventProcessors, prepared, hint, 0, reason => { @@ -118,8 +122,8 @@ export function prepareEvent( } client.recordDroppedEvent(reason, getDataCategoryByType(event.type)); - if (event.type === 'transaction') { - client.recordDroppedEvent(reason, 'span', 1 + (event.spans || []).length); + if (isTransaction) { + client.recordDroppedEvent(reason, 'span', 1 + spanCountBeforeProcessing); } }); @@ -128,6 +132,13 @@ export function prepareEvent( return null; } + if (isTransaction && client) { + const droppedSpanCount = spanCountBeforeProcessing - (evt.spans?.length || 0); + if (droppedSpanCount > 0) { + client.recordDroppedEvent('event_processor', 'span', droppedSpanCount); + } + } + // We apply the debug_meta field only after all event processors have ran, so that if any event processors modified // file names (e.g.the RewriteFrames integration) the filename -> debug ID relationship isn't destroyed. // This should not cause any PII issues, since we're only moving data that is already on the event and not adding diff --git a/packages/core/test/lib/client.test.ts b/packages/core/test/lib/client.test.ts index c77bdce7d24c..f609f5c06085 100644 --- a/packages/core/test/lib/client.test.ts +++ b/packages/core/test/lib/client.test.ts @@ -21,6 +21,7 @@ import { _INTERNAL_captureMetric } from '../../src/metrics/internal'; import * as traceModule from '../../src/tracing/trace'; import { DEFAULT_TRANSPORT_BUFFER_SIZE } from '../../src/transports/base'; import type { Envelope } from '../../src/types/envelope'; +import type { Outcome } from '../../src/types/clientreport'; import type { ErrorEvent, Event, TransactionEvent } from '../../src/types/event'; import type { SpanJSON } from '../../src/types/span'; import * as debugLoggerModule from '../../src/utils/debug-logger'; @@ -1334,6 +1335,7 @@ describe('Client', () => { const captureExceptionSpy = vi.spyOn(client, 'captureException'); const loggerLogSpy = vi.spyOn(debugLoggerModule.debug, 'log'); + const recordDroppedEventSpy = vi.spyOn(client, 'recordDroppedEvent'); const transaction: Event = { transaction: 'root span', @@ -1363,7 +1365,10 @@ describe('Client', () => { // This proves that the reason the event didn't send/didn't get set on the test client is not because there was an // error, but because the event processor returned `null` expect(captureExceptionSpy).not.toBeCalled(); - expect(loggerLogSpy).toBeCalledWith('before send for type `transaction` returned `null`, will not send event.'); + expect(loggerLogSpy).toBeCalledWith('Transaction matched `ignoreSpans`, will not send event.'); + expect(recordDroppedEventSpy).toHaveBeenCalledTimes(2); + expect(recordDroppedEventSpy).toHaveBeenCalledWith('ignored', 'transaction'); + expect(recordDroppedEventSpy).toHaveBeenCalledWith('ignored', 'span', 3); }); test('uses `ignoreSpans` to drop child spans', () => { @@ -1433,7 +1438,8 @@ describe('Client', () => { status: 'ok', }, ]); - expect(recordDroppedEventSpy).toBeCalledWith('before_send', 'span', 1); + expect(recordDroppedEventSpy).toHaveBeenCalledTimes(1); + expect(recordDroppedEventSpy).toHaveBeenCalledWith('ignored', 'span', 1); }); test('uses complex `ignoreSpans` to drop child spans', () => { @@ -1509,7 +1515,8 @@ describe('Client', () => { status: 'ok', }, ]); - expect(recordDroppedEventSpy).toBeCalledWith('before_send', 'span', 2); + expect(recordDroppedEventSpy).toHaveBeenCalledTimes(1); + expect(recordDroppedEventSpy).toHaveBeenCalledWith('ignored', 'span', 2); }); test('does not modify existing contexts for root span in `beforeSendSpan`', () => { @@ -2116,6 +2123,372 @@ describe('Client', () => { expect(recordLostEventSpy).toHaveBeenCalledWith('event_processor', 'span', 2); }); + test('event processor records spans it removes from a sent transaction', () => { + const client = new TestClient(getDefaultTestClientOptions({ dsn: PUBLIC_DSN })); + const recordLostEventSpy = vi.spyOn(client, 'recordDroppedEvent'); + + const spans = [ + { + span_id: 'aaaaaaaaaaaaaaaa', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + { + span_id: 'bbbbbbbbbbbbbbbb', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + { + span_id: 'cccccccccccccccc', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + ]; + + const scope = new Scope(); + scope.addEventProcessor(event => ({ ...event, spans: event.spans?.slice(0, 1) })); + + client.captureEvent({ transaction: '/dogs/are/great', type: 'transaction', spans }, {}, scope); + + expect(TestClient.instance!.event?.spans).toHaveLength(1); + expect(recordLostEventSpy).toHaveBeenCalledTimes(1); + expect(recordLostEventSpy).toHaveBeenCalledWith('event_processor', 'span', 2); + }); + + test('event processor counts spans removed in place before a later processor drops the transaction', () => { + const client = new TestClient(getDefaultTestClientOptions({ dsn: PUBLIC_DSN })); + const recordLostEventSpy = vi.spyOn(client, 'recordDroppedEvent'); + + const spans = [ + { + span_id: 'aaaaaaaaaaaaaaaa', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + { + span_id: 'bbbbbbbbbbbbbbbb', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + { + span_id: 'cccccccccccccccc', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + ]; + + const scope = new Scope(); + scope.addEventProcessor(event => { + event.spans?.splice(0, 2); + return event; + }); + scope.addEventProcessor(() => null); + + client.captureEvent({ transaction: '/dogs/are/great', type: 'transaction', spans }, {}, scope); + + expect(recordLostEventSpy).toHaveBeenCalledTimes(2); + expect(recordLostEventSpy).toHaveBeenCalledWith('event_processor', 'transaction'); + expect(recordLostEventSpy).toHaveBeenCalledWith('event_processor', 'span', 4); + }); + + test('spans removed by event processors and `beforeSendTransaction` are each counted once', () => { + const beforeSendTransaction = vi.fn(event => ({ ...event, spans: [] })); + const client = new TestClient(getDefaultTestClientOptions({ dsn: PUBLIC_DSN, beforeSendTransaction })); + const recordLostEventSpy = vi.spyOn(client, 'recordDroppedEvent'); + + const spans = [ + { + span_id: 'aaaaaaaaaaaaaaaa', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + { + span_id: 'bbbbbbbbbbbbbbbb', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + { + span_id: 'cccccccccccccccc', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + ]; + + const scope = new Scope(); + scope.addEventProcessor(event => ({ ...event, spans: event.spans?.slice(0, 1) })); + + client.captureEvent({ transaction: '/dogs/are/great', type: 'transaction', spans }, {}, scope); + + expect(TestClient.instance!.event?.type).toBe('transaction'); + expect(TestClient.instance!.event?.spans).toEqual([]); + expect(recordLostEventSpy).toHaveBeenCalledTimes(2); + expect(recordLostEventSpy).toHaveBeenCalledWith('event_processor', 'span', 2); + expect(recordLostEventSpy).toHaveBeenCalledWith('before_send', 'span', 1); + }); + + test('spans removed by event processors are not counted again when `beforeSendTransaction` drops the transaction', () => { + const client = new TestClient( + getDefaultTestClientOptions({ dsn: PUBLIC_DSN, beforeSendTransaction: () => null }), + ); + const recordLostEventSpy = vi.spyOn(client, 'recordDroppedEvent'); + + const spans = [ + { + span_id: 'aaaaaaaaaaaaaaaa', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + { + span_id: 'bbbbbbbbbbbbbbbb', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + { + span_id: 'cccccccccccccccc', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + ]; + + const scope = new Scope(); + scope.addEventProcessor(event => ({ ...event, spans: event.spans?.slice(0, 1) })); + + client.captureEvent({ transaction: '/dogs/are/great', type: 'transaction', spans }, {}, scope); + + expect(TestClient.instance!.event).toBeUndefined(); + expect(recordLostEventSpy).toHaveBeenCalledTimes(3); + expect(recordLostEventSpy).toHaveBeenCalledWith('event_processor', 'span', 2); + expect(recordLostEventSpy).toHaveBeenCalledWith('before_send', 'transaction'); + expect(recordLostEventSpy).toHaveBeenCalledWith('before_send', 'span', 2); + }); + + test('spans removed by event processors are not counted again when `ignoreSpans` drops the root span', () => { + const client = new TestClient(getDefaultTestClientOptions({ dsn: PUBLIC_DSN, ignoreSpans: ['/dogs/are/great'] })); + const recordLostEventSpy = vi.spyOn(client, 'recordDroppedEvent'); + + const spans = [ + { + span_id: 'aaaaaaaaaaaaaaaa', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + { + span_id: 'bbbbbbbbbbbbbbbb', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + { + span_id: 'cccccccccccccccc', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + ]; + + const scope = new Scope(); + scope.addEventProcessor(event => ({ ...event, spans: event.spans?.slice(0, 1) })); + + client.captureEvent({ transaction: '/dogs/are/great', type: 'transaction', spans }, {}, scope); + + expect(TestClient.instance!.event).toBeUndefined(); + expect(recordLostEventSpy).toHaveBeenCalledTimes(3); + expect(recordLostEventSpy).toHaveBeenCalledWith('event_processor', 'span', 2); + expect(recordLostEventSpy).toHaveBeenCalledWith('ignored', 'transaction'); + expect(recordLostEventSpy).toHaveBeenCalledWith('ignored', 'span', 2); + }); + + test('child spans dropped by `ignoreSpans` are counted as ignored when `beforeSendTransaction` drops the transaction', () => { + const client = new TestClient( + getDefaultTestClientOptions({ + dsn: PUBLIC_DSN, + ignoreSpans: ['ignored-child'], + beforeSendTransaction: () => null, + }), + ); + const recordLostEventSpy = vi.spyOn(client, 'recordDroppedEvent'); + + const spans = [ + { + span_id: 'aaaaaaaaaaaaaaaa', + description: 'ignored-child', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + { + span_id: 'bbbbbbbbbbbbbbbb', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + ]; + + client.captureEvent({ transaction: '/dogs/are/great', type: 'transaction', spans }); + + expect(TestClient.instance!.event).toBeUndefined(); + expect(recordLostEventSpy).toHaveBeenCalledTimes(3); + expect(recordLostEventSpy).toHaveBeenCalledWith('ignored', 'span', 1); + expect(recordLostEventSpy).toHaveBeenCalledWith('before_send', 'transaction'); + expect(recordLostEventSpy).toHaveBeenCalledWith('before_send', 'span', 2); + }); + + test('child spans dropped by `ignoreSpans` and removed by `beforeSendTransaction` are counted once with their reason', () => { + const client = new TestClient( + getDefaultTestClientOptions({ + dsn: PUBLIC_DSN, + ignoreSpans: ['ignored-child'], + beforeSendTransaction: event => ({ ...event, spans: [] }), + }), + ); + const recordLostEventSpy = vi.spyOn(client, 'recordDroppedEvent'); + + const spans = [ + { + span_id: 'aaaaaaaaaaaaaaaa', + description: 'ignored-child', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + { + span_id: 'bbbbbbbbbbbbbbbb', + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + }, + ]; + + client.captureEvent({ transaction: '/dogs/are/great', type: 'transaction', spans }); + + expect(TestClient.instance!.event?.spans).toEqual([]); + expect(recordLostEventSpy).toHaveBeenCalledTimes(2); + expect(recordLostEventSpy).toHaveBeenCalledWith('ignored', 'span', 1); + expect(recordLostEventSpy).toHaveBeenCalledWith('before_send', 'span', 1); + }); + + describe('span outcomes when all span drop mechanisms apply to the same transaction', () => { + const childSpanDescriptions = [ + 'removed-by-event-processor-1', + 'removed-by-event-processor-2', + 'ignored-child', + 'removed-by-before-send-transaction', + 'kept-1', + 'kept-2', + ]; + + function captureTransaction( + beforeSendTransaction: (event: TransactionEvent) => TransactionEvent | null, + ): TestClient { + const client = new TestClient( + getDefaultTestClientOptions({ + dsn: PUBLIC_DSN, + ignoreSpans: ['ignored-child'], + beforeSendSpan: withStaticSpan(span => ({ ...span, data: { ...span.data, scrubbed: true } })), + beforeSendTransaction, + }), + ); + + const scope = new Scope(); + scope.addEventProcessor(event => ({ + ...event, + spans: event.spans?.filter(span => !span.description?.startsWith('removed-by-event-processor')), + })); + + client.captureEvent( + { + transaction: '/dogs/are/great', + type: 'transaction', + spans: childSpanDescriptions.map((description, i) => ({ + description, + span_id: `${i}`.padStart(16, '0'), + start_timestamp: 1, + trace_id: '86f39e84263a4de99c326acab3bfe3bd', + data: {}, + status: 'ok', + })), + }, + {}, + scope, + ); + + return client; + } + + function getOutcomes(client: TestClient): { outcomes: Outcome[]; spanOutcomeTotal: number } { + const outcomes = client._clearOutcomes(); + const spanOutcomeTotal = outcomes.filter(o => o.category === 'span').reduce((sum, o) => sum + o.quantity, 0); + return { outcomes, spanOutcomeTotal }; + } + + test('counts each dropped span exactly once when the transaction is sent', () => { + const client = captureTransaction(event => ({ + ...event, + spans: event.spans?.filter(span => span.description !== 'removed-by-before-send-transaction'), + })); + + const sentSpans = TestClient.instance!.event!.spans!; + expect(sentSpans.map(span => span.description)).toEqual(['kept-1', 'kept-2']); + + const { outcomes, spanOutcomeTotal } = getOutcomes(client); + expect(outcomes).toEqual([ + { reason: 'event_processor', category: 'span', quantity: 2 }, + { reason: 'ignored', category: 'span', quantity: 1 }, + { reason: 'before_send', category: 'span', quantity: 1 }, + ]); + // every child span is either sent or counted once; the root span is sent as the transaction + expect(spanOutcomeTotal + sentSpans.length).toBe(childSpanDescriptions.length); + }); + + test('counts each span exactly once when `beforeSendTransaction` drops the transaction', () => { + const client = captureTransaction(() => null); + + expect(TestClient.instance!.event).toBeUndefined(); + + const { outcomes, spanOutcomeTotal } = getOutcomes(client); + expect(outcomes).toEqual([ + { reason: 'event_processor', category: 'span', quantity: 2 }, + { reason: 'ignored', category: 'span', quantity: 1 }, + { reason: 'before_send', category: 'transaction', quantity: 1 }, + { reason: 'before_send', category: 'span', quantity: 4 }, + ]); + // all child spans plus the root span are counted once + expect(spanOutcomeTotal).toBe(childSpanDescriptions.length + 1); + }); + }); + test('mutating transaction name with event processors sets transaction-name-change metadata', () => { const options = getDefaultTestClientOptions({ dsn: PUBLIC_DSN, enableSend: true }); const client = new TestClient(options); diff --git a/packages/core/test/lib/tracing/idleSpan.test.ts b/packages/core/test/lib/tracing/idleSpan.test.ts index 3809db713668..a129c35e6a13 100644 --- a/packages/core/test/lib/tracing/idleSpan.test.ts +++ b/packages/core/test/lib/tracing/idleSpan.test.ts @@ -501,7 +501,9 @@ describe('startIdleSpan', () => { idleSpan.end(); + expect(recordDroppedEventSpy).toHaveBeenCalledTimes(2); expect(recordDroppedEventSpy).toHaveBeenCalledWith('sample_rate', 'transaction'); + expect(recordDroppedEventSpy).toHaveBeenCalledWith('sample_rate', 'span'); }); it('sets finish reason when span is ended manually', () => { diff --git a/packages/core/test/lib/tracing/trace.test.ts b/packages/core/test/lib/tracing/trace.test.ts index 5d7ab473b1b8..f59946d50c10 100644 --- a/packages/core/test/lib/tracing/trace.test.ts +++ b/packages/core/test/lib/tracing/trace.test.ts @@ -642,6 +642,21 @@ describe('startSpan', () => { expect(spyOnDroppedEvent).toHaveBeenCalledTimes(1); }); + it('records no_parent_span client reports for spans nested in a span without parent', () => { + const spyOnDroppedEvent = vi.spyOn(client, 'recordDroppedEvent'); + + startSpan({ name: 'test span', onlyIfParent: true }, () => { + startSpan({ name: 'child span' }, () => { + startInactiveSpan({ name: 'grandchild span' }).end(); + }); + }); + + expect(spyOnDroppedEvent).toHaveBeenCalledTimes(3); + expect(spyOnDroppedEvent).toHaveBeenNthCalledWith(1, 'no_parent_span', 'span'); + expect(spyOnDroppedEvent).toHaveBeenNthCalledWith(2, 'no_parent_span', 'span'); + expect(spyOnDroppedEvent).toHaveBeenNthCalledWith(3, 'no_parent_span', 'span'); + }); + it('creates a span if there is a parent', () => { const spyOnDroppedEvent = vi.spyOn(client, 'recordDroppedEvent'); @@ -2773,7 +2788,7 @@ describe('ignoreSpans (core path, streaming)', () => { expect(spyOnDroppedEvent).toHaveBeenNthCalledWith(2, 'sample_rate', 'span'); }); - it('records sample_rate/transaction for unsampled root span on static path', () => { + it('records sample_rate outcomes for the transaction and all of its spans on static path', () => { const options = getDefaultTestClientOptions({ tracesSampleRate: 0, }); @@ -2783,11 +2798,62 @@ describe('ignoreSpans (core path, streaming)', () => { const spyOnDroppedEvent = vi.spyOn(client, 'recordDroppedEvent'); startSpan({ name: 'GET /foo' }, () => { - startSpan({ name: 'db.query' }, () => {}); + startSpan({ name: 'db.query' }, () => { + startSpan({ name: 'cache.lookup' }, () => {}); + }); + startInactiveSpan({ name: 'http.client' }).end(); }); + expect(spyOnDroppedEvent).toHaveBeenCalledTimes(5); + expect(spyOnDroppedEvent).toHaveBeenNthCalledWith(1, 'sample_rate', 'transaction'); + expect(spyOnDroppedEvent).toHaveBeenNthCalledWith(2, 'sample_rate', 'span'); + expect(spyOnDroppedEvent).toHaveBeenNthCalledWith(3, 'sample_rate', 'span'); + expect(spyOnDroppedEvent).toHaveBeenNthCalledWith(4, 'sample_rate', 'span'); + expect(spyOnDroppedEvent).toHaveBeenNthCalledWith(5, 'sample_rate', 'span'); + }); + + it('records a single sample_rate/span outcome for an unsampled standalone root span on static path', () => { + const options = getDefaultTestClientOptions({ + tracesSampleRate: 0, + }); + client = new TestClient(options); + setCurrentClient(client); + client.init(); + const spyOnDroppedEvent = vi.spyOn(client, 'recordDroppedEvent'); + + // oxlint-disable-next-line typescript/no-deprecated + startInactiveSpan({ name: 'inp', experimental: { standalone: true } }).end(); + expect(spyOnDroppedEvent).toHaveBeenCalledTimes(1); - expect(spyOnDroppedEvent).toHaveBeenCalledWith('sample_rate', 'transaction'); + expect(spyOnDroppedEvent).toHaveBeenCalledWith('sample_rate', 'span'); + }); + + // Unsampled spans are counted when they start, so this also counts spans a sampled + // transaction would never contain (here: a child that never ends). + it('records sample_rate outcomes for unsampled spans that a sampled transaction would not contain', () => { + const runScenario = (tracesSampleRate: number): ReturnType => { + client = new TestClient(getDefaultTestClientOptions({ tracesSampleRate })); + setCurrentClient(client); + client.init(); + const spyOnDroppedEvent = vi.spyOn(client, 'recordDroppedEvent'); + + startSpan({ name: 'GET /foo' }, () => { + startInactiveSpan({ name: 'never ended' }); + }); + + return spyOnDroppedEvent; + }; + + const sampledSpy = vi.spyOn(TestClient.prototype, 'sendEvent'); + runScenario(1); + expect(sampledSpy).toHaveBeenCalledWith(expect.objectContaining({ spans: [] }), expect.anything()); + sampledSpy.mockRestore(); + + const unsampledDroppedEventSpy = runScenario(0); + expect(unsampledDroppedEventSpy).toHaveBeenCalledTimes(3); + expect(unsampledDroppedEventSpy).toHaveBeenNthCalledWith(1, 'sample_rate', 'transaction'); + expect(unsampledDroppedEventSpy).toHaveBeenNthCalledWith(2, 'sample_rate', 'span'); + expect(unsampledDroppedEventSpy).toHaveBeenNthCalledWith(3, 'sample_rate', 'span'); }); it('records only one ignored outcome for directly ignored child span', () => {