Skip to content

Commit a744088

Browse files
authored
fix(opentelemetry): Ensure only orphaned spans of sent spans are sent (#16590)
Noticed this small but potentially impactful typo: We used to mark all finished spans as sent, not just the ones that are actually sent :O (Also we iterated twice over the same array, streamlined this by just doing this once).
1 parent b615f61 commit a744088

File tree

3 files changed

+79
-6
lines changed

3 files changed

+79
-6
lines changed

dev-packages/e2e-tests/test-applications/nextjs-15/tests/ai-test.test.ts

Lines changed: 2 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -3,16 +3,15 @@ import { waitForTransaction } from '@sentry-internal/test-utils';
33

44
test('should create AI spans with correct attributes', async ({ page }) => {
55
const aiTransactionPromise = waitForTransaction('nextjs-15', async transactionEvent => {
6-
return transactionEvent?.transaction === 'ai-test';
6+
return transactionEvent.transaction === 'GET /ai-test';
77
});
88

99
await page.goto('/ai-test');
1010

1111
const aiTransaction = await aiTransactionPromise;
1212

1313
expect(aiTransaction).toBeDefined();
14-
expect(aiTransaction.contexts?.trace?.op).toBe('function');
15-
expect(aiTransaction.transaction).toBe('ai-test');
14+
expect(aiTransaction.transaction).toBe('GET /ai-test');
1615

1716
const spans = aiTransaction.spans || [];
1817

packages/opentelemetry/src/spanExporter.ts

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -180,9 +180,6 @@ export class SentrySpanExporter {
180180

181181
this.flushSentSpanCache();
182182
const sentSpans = this._maybeSend(finishedSpans);
183-
for (const span of finishedSpans) {
184-
this._sentSpans.set(span.spanContext().spanId, Date.now() + DEFAULT_TIMEOUT * 1000);
185-
}
186183

187184
const sentSpanCount = sentSpans.size;
188185
const remainingOpenSpanCount = finishedSpans.length - sentSpanCount;
@@ -191,7 +188,10 @@ export class SentrySpanExporter {
191188
`SpanExporter exported ${sentSpanCount} spans, ${remainingOpenSpanCount} spans are waiting for their parent spans to finish`,
192189
);
193190

191+
const expirationDate = Date.now() + DEFAULT_TIMEOUT * 1000;
192+
194193
for (const span of sentSpans) {
194+
this._sentSpans.set(span.spanContext().spanId, expirationDate);
195195
const bucketEntry = this._spansToBucketEntry.get(span);
196196
if (bucketEntry) {
197197
bucketEntry.spans.delete(span);

packages/opentelemetry/test/integration/transactions.test.ts

Lines changed: 74 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -680,6 +680,80 @@ describe('Integration | Transactions', () => {
680680
expect(finishedSpans[0]?.name).toBe('inner span 2');
681681
});
682682

683+
it('only considers sent spans, not finished spans, for flushing orphaned spans of sent spans', async () => {
684+
const timeout = 5 * 60 * 1000;
685+
const now = Date.now();
686+
vi.useFakeTimers();
687+
vi.setSystemTime(now);
688+
689+
const logs: unknown[] = [];
690+
vi.spyOn(logger, 'log').mockImplementation(msg => logs.push(msg));
691+
692+
const transactions: Event[] = [];
693+
694+
mockSdkInit({
695+
tracesSampleRate: 1,
696+
beforeSendTransaction: event => {
697+
transactions.push(event);
698+
return null;
699+
},
700+
});
701+
702+
const provider = getProvider();
703+
const multiSpanProcessor = provider?.activeSpanProcessor as
704+
| (SpanProcessor & { _spanProcessors?: SpanProcessor[] })
705+
| undefined;
706+
const spanProcessor = multiSpanProcessor?.['_spanProcessors']?.find(
707+
spanProcessor => spanProcessor instanceof SentrySpanProcessor,
708+
) as SentrySpanProcessor | undefined;
709+
710+
const exporter = spanProcessor ? spanProcessor['_exporter'] : undefined;
711+
712+
if (!exporter) {
713+
throw new Error('No exporter found, aborting test...');
714+
}
715+
716+
/**
717+
* This is our span structure:
718+
* span 1 --------
719+
* span 2 ---
720+
* span 3 -
721+
*
722+
* Where span 2 is finished before span 3 & span 1
723+
*/
724+
725+
const [span1, span3] = startSpanManual({ name: 'span 1' }, span1 => {
726+
const [span2, span3] = startSpanManual({ name: 'span 2' }, span2 => {
727+
const span3 = startInactiveSpan({ name: 'span 3' });
728+
return [span2, span3];
729+
});
730+
731+
// End span 2 before span 3
732+
span2.end();
733+
734+
return [span1, span3];
735+
});
736+
737+
vi.advanceTimersByTime(1);
738+
739+
// nothing should be sent yet, as span1 is not yet done
740+
expect(transactions).toHaveLength(0);
741+
742+
// Now finish span1, should be sent with only span2 but without span3, as that is not yet finished
743+
span1.end();
744+
vi.advanceTimersByTime(1);
745+
746+
expect(transactions).toHaveLength(1);
747+
expect(transactions[0]?.spans).toHaveLength(1);
748+
749+
// now finish span3, which should be sent as transaction too
750+
span3.end();
751+
vi.advanceTimersByTime(timeout);
752+
753+
expect(transactions).toHaveLength(2);
754+
expect(transactions[1]?.spans).toHaveLength(0);
755+
});
756+
683757
it('uses & inherits DSC on span trace state', async () => {
684758
const transactionEvents: Event[] = [];
685759
const beforeSendTransaction = vi.fn(event => {

0 commit comments

Comments
 (0)