Skip to content

Commit efa7a0a

Browse files
committed
fix(browser): Apply Http timing attributes to streamed http.client spans
1 parent 6d95588 commit efa7a0a

5 files changed

Lines changed: 57 additions & 32 deletions

File tree

  • dev-packages/browser-integration-tests/suites/tracing
    • browserTracingIntegration/http-timings-streamed
    • setSpanActive-streamed
  • packages/browser/src

dev-packages/browser-integration-tests/suites/tracing/browserTracingIntegration/http-timings-streamed/test.ts

Lines changed: 2 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -3,16 +3,8 @@ import { sentryTest } from '../../../../utils/fixtures';
33
import { shouldSkipTracingTest, testingCdnBundle } from '../../../../utils/helpers';
44
import { getSpanOp, waitForStreamedSpans } from '../../../../utils/spanUtils';
55

6-
/**
7-
* This test details a limitation of span streaming in comparison to transaction-based tracing:
8-
* We can no longer attach http PerformanceResourceTiming attributes to http.client spans in
9-
* span streaming mode. The reason is that we track `http.client` spans in real time but only
10-
* get the detailed timing information after the span already ended.
11-
* We can probably fix this (somehat at least) but will do so in a follow-up PR.
12-
* @see https://github.com/getsentry/sentry-javascript/issues/19613
13-
*/
146
sentryTest(
15-
"[limitation] doesn't add http timing to http.client spans in span streaming mode",
7+
'adds http timing to http.client spans in span streaming mode',
168
async ({ browserName, getLocalTestUrl, page }) => {
179
const supportedBrowsers = ['chromium', 'firefox'];
1810

@@ -49,7 +41,7 @@ sentryTest(
4941
end_timestamp: expect.any(Number),
5042
trace_id: pageloadSpan?.trace_id,
5143
status: 'ok',
52-
attributes: expect.not.objectContaining({
44+
attributes: expect.objectContaining({
5345
'http.request.redirect_start': expect.any(Object),
5446
'http.request.redirect_end': expect.any(Object),
5547
'http.request.worker_start': expect.any(Object),

dev-packages/browser-integration-tests/suites/tracing/setSpanActive-streamed/nested-parentAlwaysRoot/test.ts

Lines changed: 3 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -11,27 +11,22 @@ sentryTest(
1111
const checkoutSpansPromise = waitForStreamedSpans(page, spans =>
1212
spans.some(s => s.name === 'checkout-flow' && s.is_segment),
1313
);
14-
const postCheckoutSpansPromise = waitForStreamedSpans(page, spans =>
15-
spans.some(s => s.name === 'post-checkout' && s.is_segment),
16-
);
1714

1815
const url = await getLocalTestUrl({ testDir: __dirname });
1916
await page.goto(url);
2017

2118
const checkoutSpans = await checkoutSpansPromise;
22-
const postCheckoutSpans = await postCheckoutSpansPromise;
2319

2420
const checkoutSpan = checkoutSpans.find(s => s.name === 'checkout-flow');
25-
const postCheckoutSpan = postCheckoutSpans.find(s => s.name === 'post-checkout');
21+
const postCheckoutSpan = checkoutSpans.find(s => s.name === 'post-checkout');
2622

2723
const checkoutSpanId = checkoutSpan?.span_id;
2824
const postCheckoutSpanId = postCheckoutSpan?.span_id;
2925

3026
expect(checkoutSpanId).toMatch(/[a-f\d]{16}/);
3127
expect(postCheckoutSpanId).toMatch(/[a-f\d]{16}/);
3228

33-
expect(checkoutSpans.filter(s => !s.is_segment)).toHaveLength(4);
34-
expect(postCheckoutSpans.filter(s => !s.is_segment)).toHaveLength(1);
29+
expect(checkoutSpans.filter(s => !s.is_segment)).toHaveLength(5);
3530

3631
const checkoutStep1 = checkoutSpans.find(s => s.name === 'checkout-step-1');
3732
const checkoutStep2 = checkoutSpans.find(s => s.name === 'checkout-step-2');
@@ -56,7 +51,7 @@ sentryTest(
5651

5752
// post-checkout trace is started as a new trace because ending checkoutSpan removes the active
5853
// span on the scope
59-
const postCheckoutStep1 = postCheckoutSpans.find(s => s.name === 'post-checkout-1');
54+
const postCheckoutStep1 = checkoutSpans.find(s => s.name === 'post-checkout-1');
6055
expect(postCheckoutStep1).toBeDefined();
6156
expect(postCheckoutStep1?.parent_span_id).toBe(postCheckoutSpanId);
6257
},

dev-packages/browser-integration-tests/suites/tracing/setSpanActive-streamed/nested/test.ts

Lines changed: 3 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -11,27 +11,22 @@ sentryTest(
1111
const checkoutSpansPromise = waitForStreamedSpans(page, spans =>
1212
spans.some(s => s.name === 'checkout-flow' && s.is_segment),
1313
);
14-
const postCheckoutSpansPromise = waitForStreamedSpans(page, spans =>
15-
spans.some(s => s.name === 'post-checkout' && s.is_segment),
16-
);
1714

1815
const url = await getLocalTestUrl({ testDir: __dirname });
1916
await page.goto(url);
2017

2118
const checkoutSpans = await checkoutSpansPromise;
22-
const postCheckoutSpans = await postCheckoutSpansPromise;
2319

2420
const checkoutSpan = checkoutSpans.find(s => s.name === 'checkout-flow');
25-
const postCheckoutSpan = postCheckoutSpans.find(s => s.name === 'post-checkout');
21+
const postCheckoutSpan = checkoutSpans.find(s => s.name === 'post-checkout');
2622

2723
const checkoutSpanId = checkoutSpan?.span_id;
2824
const postCheckoutSpanId = postCheckoutSpan?.span_id;
2925

3026
expect(checkoutSpanId).toMatch(/[a-f\d]{16}/);
3127
expect(postCheckoutSpanId).toMatch(/[a-f\d]{16}/);
3228

33-
expect(checkoutSpans.filter(s => !s.is_segment)).toHaveLength(4);
34-
expect(postCheckoutSpans.filter(s => !s.is_segment)).toHaveLength(1);
29+
expect(checkoutSpans.filter(s => !s.is_segment)).toHaveLength(5);
3530

3631
const checkoutStep1 = checkoutSpans.find(s => s.name === 'checkout-step-1');
3732
const checkoutStep2 = checkoutSpans.find(s => s.name === 'checkout-step-2');
@@ -51,7 +46,7 @@ sentryTest(
5146
// root span due to this being default behaviour in browser environments
5247
expect(checkoutStep21?.parent_span_id).toBe(checkoutSpanId);
5348

54-
const postCheckoutStep1 = postCheckoutSpans.find(s => s.name === 'post-checkout-1');
49+
const postCheckoutStep1 = checkoutSpans.find(s => s.name === 'post-checkout-1');
5550
expect(postCheckoutStep1).toBeDefined();
5651
expect(postCheckoutStep1?.parent_span_id).toBe(postCheckoutSpanId);
5752
},

packages/browser/src/integrations/spanstreaming.ts

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -58,7 +58,12 @@ export const spanStreamingIntegration = defineIntegration(() => {
5858
// In addition to capturing the span, we also flush the trace when the segment
5959
// span ends to ensure things are sent timely. We never know when the browser
6060
// is closed, users navigate away, etc.
61-
client.on('afterSegmentSpanEnd', segmentSpan => buffer.flush(segmentSpan.spanContext().traceId));
61+
client.on('afterSegmentSpanEnd', segmentSpan => {
62+
const traceId = segmentSpan.spanContext().traceId;
63+
setTimeout(() => {
64+
buffer.flush(traceId);
65+
}, 500);
66+
});
6267
},
6368
};
6469
}) satisfies IntegrationFn;

packages/browser/src/tracing/request.ts

Lines changed: 43 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ import type {
55
ResponseHookInfo,
66
SentryWrappedXMLHttpRequest,
77
Span,
8+
SpanTimeInput,
89
} from '@sentry/core';
910
import {
1011
addFetchEndInstrumentationHandler,
@@ -238,8 +239,17 @@ export function instrumentOutgoingRequests(client: Client, _options?: Partial<Re
238239
}
239240

240241
/**
241-
* Creates a temporary observer to listen to the next fetch/xhr resourcing timings,
242-
* so that when timings hit their per-browser limit they don't need to be removed.
242+
* The maximum time (ms) to wait for PerformanceResourceTiming data before ending the span.
243+
* Same approach is used by OTel's browser fetch instrumentation:
244+
* See {@link https://github.com/open-telemetry/opentelemetry-js/blob/30f94fe99339287b1e4d3c8bb90172c2523f06f4/experimental/packages/opentelemetry-instrumentation-fetch/src/fetch.ts#L352-L372}
245+
*/
246+
const HTTP_TIMING_WAIT_MS = 300;
247+
248+
/**
249+
* Intercepts `span.end()` to delay the actual span ending until PerformanceResourceTiming
250+
* data is available (or until the timeout elapses), so that timing attributes are always
251+
* present on the span even in span-streaming mode where spans are serialised immediately
252+
* on end.
243253
*
244254
* @param span A span that has yet to be finished, must contain `url` on data.
245255
*/
@@ -250,16 +260,44 @@ function addHTTPTimings(span: Span): void {
250260
return;
251261
}
252262

263+
// Capture a reference to the real end implementation before shadowing it.
264+
const originalEnd = span.end.bind(span);
265+
let capturedEndTimestamp: SpanTimeInput | undefined;
266+
let isEnded = false;
267+
268+
// Shadow the prototype method with an instance property so that when
269+
// instrumentFetchRequest / xhrCallback calls span.end(), we intercept it.
270+
span.end = (endTimestamp?: SpanTimeInput) => {
271+
capturedEndTimestamp = endTimestamp;
272+
// Do not call originalEnd here; finishSpan() handles that once timing data
273+
// has arrived (or the timeout fires).
274+
};
275+
276+
const endSpanAndCleanup = (): void => {
277+
if (isEnded) {
278+
return;
279+
}
280+
isEnded = true;
281+
// In the next tick, clean up the performance observer
282+
// We have to wait here because otherwise we clean it up before it is fully done
283+
setTimeout(cleanup);
284+
originalEnd(capturedEndTimestamp);
285+
clearTimeout(fallbackTimeout);
286+
};
287+
253288
const cleanup = addPerformanceInstrumentationHandler('resource', ({ entries }) => {
254289
entries.forEach(entry => {
255290
if (isPerformanceResourceTiming(entry) && entry.name.endsWith(url)) {
256291
span.setAttributes(resourceTimingToSpanAttributes(entry));
257-
// In the next tick, clean this handler up
258-
// We have to wait here because otherwise this cleans itself up before it is fully done
259-
setTimeout(cleanup);
292+
endSpanAndCleanup();
260293
}
261294
});
262295
});
296+
297+
// Fallback: always end the span after HTTP_TIMING_WAIT_MS even if no
298+
// PerformanceResourceTiming entry arrives (e.g. cross-origin without
299+
// Timing-Allow-Origin, or the browser didn't fire the observer in time).
300+
const fallbackTimeout = setTimeout(endSpanAndCleanup, HTTP_TIMING_WAIT_MS);
263301
}
264302

265303
/**

0 commit comments

Comments
 (0)