From ef9e5f12f031be0a3a4fbb2de64b3a8bce63665d Mon Sep 17 00:00:00 2001 From: Charly Gomez Date: Thu, 12 Nov 2026 16:07:27 +0100 Subject: [PATCH] feat(nextjs): Send the trace in the Server-Timing header of document responses Co-Authored-By: Claude Fable 5.1 --- .../cacheOrigin-pageloadConnection.spec.ts | 41 +++-- .../cacheOrigin-pageloadConnection.spec.ts | 33 ++-- .../tests/client-errors.test.ts | 6 +- .../nextjs-app-dir/tests/transactions.test.ts | 9 +- .../tests/transactions.test.ts | 15 +- .../appRouterPageloadInstrumentation.ts | 24 ++- .../src/client/routing/traceMetaTags.ts | 65 +++++-- packages/nextjs/src/server/index.ts | 2 + .../nextjs/src/server/serverTimingHeader.ts | 107 ++++++++++++ .../appRouterRoutingInstrumentation.test.ts | 27 +++ .../nextjs/test/client/traceMetaTags.test.ts | 103 +++++++++++ .../test/server/serverTimingHeader.test.ts | 164 ++++++++++++++++++ 12 files changed, 524 insertions(+), 72 deletions(-) create mode 100644 packages/nextjs/src/server/serverTimingHeader.ts create mode 100644 packages/nextjs/test/server/serverTimingHeader.test.ts diff --git a/dev-packages/e2e-tests/test-applications/nextjs-16-cacheComponents/tests/cacheOrigin-pageloadConnection.spec.ts b/dev-packages/e2e-tests/test-applications/nextjs-16-cacheComponents/tests/cacheOrigin-pageloadConnection.spec.ts index f06c4da961cd..b2ed7555899c 100644 --- a/dev-packages/e2e-tests/test-applications/nextjs-16-cacheComponents/tests/cacheOrigin-pageloadConnection.spec.ts +++ b/dev-packages/e2e-tests/test-applications/nextjs-16-cacheComponents/tests/cacheOrigin-pageloadConnection.spec.ts @@ -5,11 +5,13 @@ import { waitForTransaction } from '@sentry-internal/test-utils'; const APP = 'nextjs-16-cacheComponents'; +// A self-hosted server sends the trace of the request in a `Server-Timing` header of a document +// that renders for the request, which reaches the browser before any HTML, so the pageload continues +// it right away. A document that a shared cache may store gets no header, as a CDN would replay it. // The server only writes `sentry-trace` meta tags for a render that happened for the current request, -// never while it prerenders a shell. So a tag in the document can always be continued; the only -// question is when it arrives. The resumed part of a prerendered shell arrives after the SDK started, -// which the pageload instrumentation waits for. A shell prerendered at runtime carries a -// `sentry-cache-origin` tag instead, which marks the pageload as static and links the prerender. +// never while it prerenders a shell. A shell prerendered at runtime carries a `sentry-cache-origin` +// tag instead, which links the prerender and, together with a late `sentry-trace` tag, marks the +// pageload as partially static. test('connects the pageload trace to the runtime server request', async ({ page }) => { // The shell is prerendered, but the page's dynamic part (`DynamicContent` awaits `headers()`) @@ -24,7 +26,7 @@ test('connects the pageload trace to the runtime server request', async ({ page return transactionEvent.contexts?.trace?.op === 'pageload' && transactionEvent.transaction === '/pageload-tracing'; }); - await page.goto('/pageload-tracing'); + const response = await page.goto('/pageload-tracing'); await expect(page.locator('#todos-fetched')).toHaveText('Todos fetched: 5'); @@ -32,6 +34,16 @@ test('connects the pageload trace to the runtime server request', async ({ page expect(serverTx.contexts?.trace?.trace_id).toBeTruthy(); expect(pageloadTx.contexts?.trace?.trace_id).toBe(serverTx.contexts?.trace?.trace_id); + // The header carries the trace before any HTML, so the pageload does not wait for the meta tag. Both + // are computed inside the request, so the pageload hangs off one of the request's spans. In dev mode + // nothing is prerendered, so the tag is in from the start and wins over the header. + const serverSpanIds = [serverTx.contexts?.trace?.span_id, ...(serverTx.spans ?? []).map(span => span.span_id)]; + const [, headerSpanId] = + new RegExp(`sentry-trace;desc="${serverTx.contexts?.trace?.trace_id}-([a-f0-9]{16})-1"`).exec( + response?.headers()['server-timing'] ?? '', + ) ?? []; + expect(serverSpanIds).toContain(headerSpanId); + expect(serverSpanIds).toContain(pageloadTx.contexts?.trace?.parent_span_id); }); test('connects the pageload trace to a blocking render', async ({ page }) => { @@ -60,7 +72,8 @@ test('does not share a trace between visitors of a shell generated at request ti // `[id]` only lists `test` in `generateStaticParams`, so the first visit prerenders and caches the // shell for this id. The prerender writes no trace tag, only a `sentry-cache-origin` tag with its own - // trace, so every visitor starts a fresh trace that links the prerender and is marked as static. + // trace, so every visitor starts a fresh trace that links the prerender and is marked as static. The + // cached document is cacheable by a CDN as well, so the response carries no trace header either. const id = `shell-${Date.now()}`; const visit = async (): Promise<{ traceId: string | undefined; links: unknown; serverRenderingType: unknown }> => { @@ -74,10 +87,11 @@ test('does not share a trace between visitors of a shell generated at request ti ); }); - await page.goto(`/${id}`); + const response = await page.goto(`/${id}`); await expect(page.locator('#result')).toHaveText(`Hello, ${id}!`); expect(await page.locator('meta[name="sentry-trace"]').count()).toBe(0); expect(await page.locator('meta[name="sentry-cache-origin"]').count()).toBe(1); + expect(response?.headers()['server-timing'] ?? '').not.toContain('sentry-trace'); const pageloadTx = await pageloadTxPromise; await context.close(); @@ -171,22 +185,27 @@ test('starts a fresh trace on a fully static page', async ({ page }) => { return transactionEvent.contexts?.trace?.op === 'pageload' && transactionEvent.transaction === '/static-shell'; }); - await page.goto('/static-shell'); + const response = await page.goto('/static-shell'); await expect(page.locator('#static-shell')).toHaveText('Static shell'); const pageloadTx = await pageloadTxPromise; // A build-time shell carries no trace context and no marker, the SDK does not run during the build. + // The response is cacheable, so the request that serves it sends no trace header either. expect(await page.locator('meta[name="sentry-trace"]').count()).toBe(0); expect(await page.locator('meta[name="sentry-cache-origin"]').count()).toBe(0); + expect(response?.headers()['server-timing'] ?? '').not.toContain('sentry-trace'); expect(pageloadTx.contexts?.trace?.trace_id).toBeTruthy(); expect(pageloadTx.contexts?.trace?.links).toBeUndefined(); expect(pageloadTx.contexts?.trace?.data?.['page.server_rendering.type']).toBeUndefined(); }); -test('keeps a navigation that starts while the pageload waits for the trace meta tag', async ({ page }) => { - test.skip(process.env.TEST_ENV !== 'production', 'Only a prerendered shell makes the trace meta tag arrive late'); +test('keeps a navigation that starts while the document still streams', async ({ page }) => { + test.skip( + process.env.TEST_ENV !== 'production', + 'Only a prerendered shell streams the rest of the document after the SDK started', + ); const pageloadTxPromise = waitForTransaction(APP, transactionEvent => { return transactionEvent.contexts?.trace?.op === 'pageload' && transactionEvent.transaction === '/slow-hole'; @@ -199,7 +218,7 @@ test('keeps a navigation that starts while the pageload waits for the trace meta await page.goto('/slow-hole', { waitUntil: 'commit' }); await page.waitForFunction(() => !!(window as { next?: { router?: unknown } }).next?.router); - // The resumed part, which carries the tag, has not arrived yet, so the pageload is still waiting. + // The resumed part, which carries the tag, has not arrived yet. The header already connected the pageload. await expect(page.locator('#slow-fallback')).toBeVisible(); expect(await page.locator('meta[name="sentry-trace"]').count()).toBe(0); diff --git a/dev-packages/e2e-tests/test-applications/nextjs-16-streaming-cacheComponents/tests/cacheOrigin-pageloadConnection.spec.ts b/dev-packages/e2e-tests/test-applications/nextjs-16-streaming-cacheComponents/tests/cacheOrigin-pageloadConnection.spec.ts index 3d1512789f82..61b9dcd8d378 100644 --- a/dev-packages/e2e-tests/test-applications/nextjs-16-streaming-cacheComponents/tests/cacheOrigin-pageloadConnection.spec.ts +++ b/dev-packages/e2e-tests/test-applications/nextjs-16-streaming-cacheComponents/tests/cacheOrigin-pageloadConnection.spec.ts @@ -5,11 +5,13 @@ import { getSpanOp, waitForStreamedSpan } from '@sentry-internal/test-utils'; const APP = 'nextjs-16-streaming-cacheComponents'; +// A self-hosted server sends the trace of the request in a `Server-Timing` header of a document +// that renders for the request, which reaches the browser before any HTML, so the pageload continues +// it right away. A document that a shared cache may store gets no header, as a CDN would replay it. // The server only writes `sentry-trace` meta tags for a render that happened for the current request, -// never while it prerenders a shell. So a tag in the document can always be continued; the only -// question is when it arrives. The resumed part of a prerendered shell arrives after the SDK started, -// which the pageload instrumentation waits for. A shell prerendered at runtime carries a -// `sentry-cache-origin` tag instead, which marks the pageload as static and links the prerender. +// never while it prerenders a shell. A shell prerendered at runtime carries a `sentry-cache-origin` +// tag instead, which links the prerender and, together with a late `sentry-trace` tag, marks the +// pageload as partially static. test('connects the pageload trace to the runtime server request', async ({ page }) => { // The shell is prerendered, but the page's dynamic part (`DynamicContent` awaits `headers()`) @@ -22,7 +24,7 @@ test('connects the pageload trace to the runtime server request', async ({ page return span.name === '/pageload-tracing' && getSpanOp(span) === 'pageload' && span.is_segment; }); - await page.goto('/pageload-tracing'); + const response = await page.goto('/pageload-tracing'); await expect(page.locator('#todos-fetched')).toHaveText('Todos fetched: 5'); @@ -30,6 +32,8 @@ test('connects the pageload trace to the runtime server request', async ({ page expect(serverSpan.trace_id).toBeTruthy(); expect(pageloadSpan.trace_id).toBe(serverSpan.trace_id); + // The header carries the trace before any HTML, so the pageload does not wait for the meta tag. + expect(response?.headers()['server-timing']).toContain(`sentry-trace;desc="${serverSpan.trace_id}-`); }); test('connects the pageload trace to a blocking render', async ({ page }) => { @@ -58,7 +62,8 @@ test('does not share a trace between visitors of a shell generated at request ti // `[id]` only lists `test` in `generateStaticParams`, so the first visit prerenders and caches the // shell for this id. The prerender writes no trace tag, only a `sentry-cache-origin` tag with its own - // trace, so every visitor starts a fresh trace that links the prerender and is marked as static. + // trace, so every visitor starts a fresh trace that links the prerender and is marked as static. The + // cached document is cacheable by a CDN as well, so the response carries no trace header either. const id = `shell-${Date.now()}`; const visit = async (): Promise<{ traceId: string | undefined; links: unknown; serverRenderingType: unknown }> => { @@ -69,10 +74,11 @@ test('does not share a trace between visitors of a shell generated at request ti return getSpanOp(span) === 'pageload' && span.is_segment && span.attributes['url.path']?.value === `/${id}`; }); - await page.goto(`/${id}`); + const response = await page.goto(`/${id}`); await expect(page.locator('#result')).toHaveText(`Hello, ${id}!`); expect(await page.locator('meta[name="sentry-trace"]').count()).toBe(0); expect(await page.locator('meta[name="sentry-cache-origin"]').count()).toBe(1); + expect(response?.headers()['server-timing'] ?? '').not.toContain('sentry-trace'); const pageloadSpan = await pageloadSpanPromise; await context.close(); @@ -167,22 +173,27 @@ test('starts a fresh trace on a fully static page', async ({ page }) => { return span.name === '/static-shell' && getSpanOp(span) === 'pageload' && span.is_segment; }); - await page.goto('/static-shell'); + const response = await page.goto('/static-shell'); await expect(page.locator('#static-shell')).toHaveText('Static shell'); const pageloadSpan = await pageloadSpanPromise; // A build-time shell carries no trace context and no marker, the SDK does not run during the build. + // The response is cacheable, so the request that serves it sends no trace header either. expect(await page.locator('meta[name="sentry-trace"]').count()).toBe(0); expect(await page.locator('meta[name="sentry-cache-origin"]').count()).toBe(0); + expect(response?.headers()['server-timing'] ?? '').not.toContain('sentry-trace'); expect(pageloadSpan.trace_id).toBeTruthy(); expect(pageloadSpan.links).toBeUndefined(); expect(pageloadSpan.attributes['page.server_rendering.type']).toBeUndefined(); }); -test('keeps a navigation that starts while the pageload waits for the trace meta tag', async ({ page }) => { - test.skip(process.env.TEST_ENV !== 'production', 'Only a prerendered shell makes the trace meta tag arrive late'); +test('keeps a navigation that starts while the document still streams', async ({ page }) => { + test.skip( + process.env.TEST_ENV !== 'production', + 'Only a prerendered shell streams the rest of the document after the SDK started', + ); const pageloadSpanPromise = waitForStreamedSpan(APP, span => { return span.name === '/slow-hole' && getSpanOp(span) === 'pageload' && span.is_segment; @@ -195,7 +206,7 @@ test('keeps a navigation that starts while the pageload waits for the trace meta await page.goto('/slow-hole', { waitUntil: 'commit' }); await page.waitForFunction(() => !!(window as { next?: { router?: unknown } }).next?.router); - // The resumed part, which carries the tag, has not arrived yet, so the pageload is still waiting. + // The resumed part, which carries the tag, has not arrived yet. The header already connected the pageload. await expect(page.locator('#slow-fallback')).toBeVisible(); expect(await page.locator('meta[name="sentry-trace"]').count()).toBe(0); diff --git a/dev-packages/e2e-tests/test-applications/nextjs-app-dir/tests/client-errors.test.ts b/dev-packages/e2e-tests/test-applications/nextjs-app-dir/tests/client-errors.test.ts index 70a8cb313b05..ffc53c210046 100644 --- a/dev-packages/e2e-tests/test-applications/nextjs-app-dir/tests/client-errors.test.ts +++ b/dev-packages/e2e-tests/test-applications/nextjs-app-dir/tests/client-errors.test.ts @@ -29,9 +29,9 @@ test('Sends a client-side exception to Sentry', async ({ page }) => { expect(errorEvent.transaction).toEqual('/'); expect(errorEvent.contexts?.trace).toEqual({ - // Next.js >= 15 propagates a trace ID to the client via a meta tag. Also, only dev mode emits a meta tag because - // the requested page is static and only in dev mode SSR is kicked off. - parent_span_id: nextjsMajor >= 15 && isDevMode ? expect.any(String) : undefined, + // The server sends the trace in a `Server-Timing` header, except with a document a shared cache may store. In + // production the requested page is static, so only dev mode, which renders it per request, connects the pageload. + parent_span_id: isDevMode ? expect.any(String) : undefined, trace_id: expect.stringMatching(/[a-f0-9]{32}/), span_id: expect.stringMatching(/[a-f0-9]{16}/), }); diff --git a/dev-packages/e2e-tests/test-applications/nextjs-app-dir/tests/transactions.test.ts b/dev-packages/e2e-tests/test-applications/nextjs-app-dir/tests/transactions.test.ts index fe912c78b223..98c109253a27 100644 --- a/dev-packages/e2e-tests/test-applications/nextjs-app-dir/tests/transactions.test.ts +++ b/dev-packages/e2e-tests/test-applications/nextjs-app-dir/tests/transactions.test.ts @@ -11,9 +11,6 @@ import { isDevMode } from './isDevMode'; const nextPackageJson = require('next/package.json'); test('Sends a pageload span', async ({ page }) => { - const nextjsVersion = nextPackageJson.version; - const nextjsMajor = Number(nextjsVersion.split('.')[0]); - const pageloadSpanPromise = waitForStreamedSpan('nextjs-app-dir', span => { return getSpanOp(span) === 'pageload' && span.name === '/' && span.is_segment; }); @@ -22,9 +19,9 @@ test('Sends a pageload span', async ({ page }) => { const span = await pageloadSpanPromise; - // Next.js >= 15 propagates a trace ID to the client via a meta tag. Also, only dev mode emits a meta tag because - // the requested page is static and only in dev mode SSR is kicked off. - if (nextjsMajor >= 15 && isDevMode) { + // The server sends the trace in a `Server-Timing` header, except with a document a shared cache may store. In + // production the requested page is static, so only dev mode, which renders it per request, connects the pageload. + if (isDevMode) { expect(span.parent_span_id).toEqual(expect.any(String)); } else { expect(span.parent_span_id).toBeUndefined(); diff --git a/dev-packages/e2e-tests/test-applications/nextjs-pages-dir/tests/transactions.test.ts b/dev-packages/e2e-tests/test-applications/nextjs-pages-dir/tests/transactions.test.ts index 6529185e4f79..dd75989aff1e 100644 --- a/dev-packages/e2e-tests/test-applications/nextjs-pages-dir/tests/transactions.test.ts +++ b/dev-packages/e2e-tests/test-applications/nextjs-pages-dir/tests/transactions.test.ts @@ -2,12 +2,7 @@ import { expect, test } from '@playwright/test'; import { getSpanOp, waitForStreamedSpan } from '@sentry-internal/test-utils'; import { isDevMode } from './isDevMode'; -const nextPackageJson = require('next/package.json'); - test('Sends a pageload span', async ({ page }) => { - const nextjsVersion = nextPackageJson.version; - const nextjsMajor = Number(nextjsVersion.split('.')[0]); - const pageloadSpanPromise = waitForStreamedSpan('nextjs-pages-dir', span => { return getSpanOp(span) === 'pageload' && span.name === '/' && span.is_segment; }); @@ -16,13 +11,9 @@ test('Sends a pageload span', async ({ page }) => { const span = await pageloadSpanPromise; - // Next.js >= 15 propagates a trace ID to the client via a meta tag. Also, only dev mode emits a meta tag because - // the requested page is static and only in dev mode SSR is kicked off. - if (nextjsMajor >= 15 && isDevMode) { - expect(span.parent_span_id).toEqual(expect.any(String)); - } else { - expect(span.parent_span_id).toBeUndefined(); - } + // The server sends the trace in a `Server-Timing` header. The page is static, but the pages router serves it + // without a `Cache-Control` that lets a shared cache store it, so the header goes out in production too. + expect(span.parent_span_id).toEqual(expect.any(String)); expect(span.span_id).toEqual(expect.stringMatching(/[a-f0-9]{16}/)); expect(span.trace_id).toEqual(expect.stringMatching(/[a-f0-9]{32}/)); diff --git a/packages/nextjs/src/client/routing/appRouterPageloadInstrumentation.ts b/packages/nextjs/src/client/routing/appRouterPageloadInstrumentation.ts index 20e7a0e727e0..992093b87d18 100644 --- a/packages/nextjs/src/client/routing/appRouterPageloadInstrumentation.ts +++ b/packages/nextjs/src/client/routing/appRouterPageloadInstrumentation.ts @@ -18,8 +18,8 @@ import { resolveCurrentRoute, startBrowserTracingPageLoadSpan, WINDOW } from '@s import { stripTrailingSlash } from './parameterization'; import type { TraceMetaTagValues, TraceMetaTagWait } from './traceMetaTags'; import { - addTraceMetaTagLink, canWaitForTraceMetaTag, + observeLateTraceMetaTag, readTraceMetaTags, waitForTraceMetaTag, withCacheOrigin, @@ -58,6 +58,9 @@ function startPageloadSpan( if (normalizedRequest) { scope.setSDKProcessingMetadata({ normalizedRequest: { ...normalizedRequest, url: documentUrl } }); } + if (span && !traceMetaTags) { + observeLateTraceMetaTag(span); + } return span; } @@ -80,10 +83,11 @@ export function appRouterInstrumentPageLoad(client: Client): void { }, }; - // A tag that is already in the document was rendered for this request and can be continued. A - // Cache Components document that resumes a prerendered shell gets its tag with the resumed part, - // which usually arrives after the SDK started. Waiting for it lets the pageload continue the server - // trace instead of linking it; the span's start is backdated to the time origin either way. + // A tag that is already in the document was rendered for this request and can be continued, as is + // the trace of a `Server-Timing` header, which a self-hosted server sends. Without either, a Cache + // Components document that resumes a prerendered shell gets its tag with the resumed part, which + // usually arrives after the SDK started. Waiting for it lets the pageload continue the server trace + // instead of linking it; the span's start is backdated to the time origin either way. const traceMetaTags = readTraceMetaTags(); if (traceMetaTags || !canWaitForTraceMetaTag()) { startPageloadSpan(client, spanOptions, documentUrl, traceMetaTags); @@ -97,15 +101,7 @@ export function appRouterInstrumentPageLoad(client: Client): void { }, () => { pendingPageloadWait = undefined; - const span = startPageloadSpan(client, spanOptions, documentUrl); - // Only reachable through the cap or a navigation while the document still streams: a tag that - // shows up after this can no longer be continued, but the server request can still be linked. - if (span) { - waitForTraceMetaTag( - values => span.isRecording() && addTraceMetaTagLink(span, values), - () => undefined, - ); - } + startPageloadSpan(client, spanOptions, documentUrl); }, PAGELOAD_TRACE_META_TAG_TIMEOUT_MS, ); diff --git a/packages/nextjs/src/client/routing/traceMetaTags.ts b/packages/nextjs/src/client/routing/traceMetaTags.ts index c276a8cef03e..198caf895f72 100644 --- a/packages/nextjs/src/client/routing/traceMetaTags.ts +++ b/packages/nextjs/src/client/routing/traceMetaTags.ts @@ -56,19 +56,21 @@ export function hasServerTimingTraceContext(): boolean { } /** - * Whether the SDK can still expect a `sentry-trace` meta tag to arrive: the app has `cacheComponents` - * enabled, so a document can resume a prerendered shell and get its tag with the resumed part, the - * document is still streaming, and nothing else already carries the trace. Without `cacheComponents` - * a tag is either in `` from the start or never comes, so waiting would only hold the pageload - * back. + * Whether a `sentry-trace` meta tag can still arrive: the app has `cacheComponents` enabled, so a + * document can resume a prerendered shell and get its tag with the resumed part, and the document is + * still streaming. Without `cacheComponents` a tag is either in `` from the start or never comes. + */ +function canObserveTraceMetaTag(): boolean { + return hasCacheComponents() && getDocument()?.readyState === 'loading' && typeof MutationObserver !== 'undefined'; +} + +/** + * Whether the pageload should hold its start for a `sentry-trace` meta tag: one can still arrive, and + * nothing else already carries the trace. With a `Server-Timing` header the pageload continues the + * trace at once, and a tag can only still settle how the server rendered the page. */ export function canWaitForTraceMetaTag(): boolean { - return ( - hasCacheComponents() && - getDocument()?.readyState === 'loading' && - typeof MutationObserver !== 'undefined' && - !hasServerTimingTraceContext() - ); + return canObserveTraceMetaTag() && !hasServerTimingTraceContext(); } export interface TraceMetaTagWait { @@ -83,7 +85,7 @@ export interface TraceMetaTagWait { * * Calls `onTag` once with the tag, or `onGiveUp` once when the document finished parsing without * one, `timeoutMs` passed, or `giveUp()` was called, whichever comes first. Settles with `onGiveUp` - * right away when `canWaitForTraceMetaTag()` is false. + * right away when no tag can arrive anymore. */ export function waitForTraceMetaTag( onTag: (values: TraceMetaTagValues) => void, @@ -91,7 +93,7 @@ export function waitForTraceMetaTag( timeoutMs?: number, ): TraceMetaTagWait { const document = getDocument(); - if (!document || !canWaitForTraceMetaTag()) { + if (!document || !canObserveTraceMetaTag()) { onGiveUp(); return { giveUp: () => undefined }; } @@ -159,6 +161,37 @@ export function addTraceMetaTagLink(span: Span, { sentryTrace }: TraceMetaTagVal } } +/** + * Watches for a `sentry-trace` meta tag that arrives after the pageload span started, which can no + * longer be continued. It still settles how the server rendered a document with a + * `sentry-cache-origin` tag, and links the server request unless a `Server-Timing` header already + * connected the pageload to it. + */ +export function observeLateTraceMetaTag(span: Span): void { + const document = getDocument(); + if (!document || !canObserveTraceMetaTag()) { + return; + } + + const hasCacheOrigin = !!lastMetaContent(document, CACHE_ORIGIN_META_TAG_NAME); + const isConnected = hasServerTimingTraceContext(); + const setServerRenderingType = (type: string): void => { + if (hasCacheOrigin && span.isRecording()) { + span.setAttribute(PAGE_SERVER_RENDERING_TYPE, type); + } + }; + + waitForTraceMetaTag( + values => { + if (!isConnected && span.isRecording()) { + addTraceMetaTagLink(span, values); + } + setServerRenderingType('partially_static'); + }, + () => setServerRenderingType('static'), + ); +} + /** * How the server rendered a document with a `sentry-cache-origin` tag. With trace meta tags of this * request, only the shell was reused. Unset while a resumed part can still bring those tags. @@ -167,13 +200,15 @@ function getServerRenderingType(traceMetaTags: TraceMetaTagValues | undefined): if (traceMetaTags) { return 'partially_static'; } - return canWaitForTraceMetaTag() ? undefined : 'static'; + return canObserveTraceMetaTag() ? undefined : 'static'; } /** * Marks a pageload whose document carries a `sentry-cache-origin` tag with how the server rendered * it, and links the render that the page reuses. Applied at span start, so `tracesSampler` and - * `ignoreSpans` see both. Like a `use cache` hit, the pageload links only a sampled render. + * `ignoreSpans` see the link, and the type when it is already known: with a `Server-Timing` header + * the pageload starts while a resumed part can still bring the tag, and `observeLateTraceMetaTag` + * settles the type later. Like a `use cache` hit, the pageload links only a sampled render. */ export function withCacheOrigin(spanOptions: StartSpanOptions, traceMetaTags?: TraceMetaTagValues): StartSpanOptions { const document = getDocument(); diff --git a/packages/nextjs/src/server/index.ts b/packages/nextjs/src/server/index.ts index 1d21332676c3..9c43d37e0131 100644 --- a/packages/nextjs/src/server/index.ts +++ b/packages/nextjs/src/server/index.ts @@ -37,6 +37,7 @@ import { import { distDirRewriteFramesIntegration } from './distDirRewriteFramesIntegration'; import { registerNextSentryPropagator } from './nextSentryPropagator'; import { addNextjsServerSpanHooks, NEXTJS_SERVER_IGNORE_SPANS } from './serverSpanHooks'; +import { addServerTimingTraceHeader } from './serverTimingHeader'; import { prepareSafeIdGeneratorContext } from './prepareSafeIdGeneratorContext'; import { nextjsUseCacheIntegration } from './useCacheInstrumentation'; @@ -199,6 +200,7 @@ export function init(options: NodeOptions): NodeClient | undefined { if (client) { addNextjsServerSpanHooks(client); + addServerTimingTraceHeader(client); const clientOptions = client.getOptions(); clientOptions.ignoreSpans = [...(clientOptions.ignoreSpans || []), ...getTunnelRouteIgnoreSpans(client)]; } else if (isOwnedByCloudflare) { diff --git a/packages/nextjs/src/server/serverTimingHeader.ts b/packages/nextjs/src/server/serverTimingHeader.ts new file mode 100644 index 000000000000..7bcfa5ca5567 --- /dev/null +++ b/packages/nextjs/src/server/serverTimingHeader.ts @@ -0,0 +1,107 @@ +import type { Client } from '@sentry/core'; +import { debug, getTraceServerTimingHeader, isObjectLike, isSharedCacheable } from '@sentry/core'; +import { DEBUG_BUILD } from '../common/debug-build'; + +const SERVER_TIMING_HEADER = 'server-timing'; + +interface HttpServerResponse { + headersSent: boolean; + getHeader(name: string): number | string | string[] | undefined; + setHeader(name: string, value: string): unknown; + writeHead(...args: unknown[]): unknown; +} + +type HeaderObject = Record; + +function isHttpServerResponse(response: unknown): response is HttpServerResponse { + return ( + isObjectLike(response) && + typeof response.writeHead === 'function' && + typeof response.getHeader === 'function' && + typeof response.setHeader === 'function' + ); +} + +/** + * Sends the trace of the request in a `Server-Timing` header of a document response of the Node.js + * server, so the browser SDK continues it in the pageload span before any HTML arrived. Next.js + * flushes the headers with the first chunk of the document, inside the request span, so the value is + * computed then rather than when the request comes in. The hook fires for every request, also when + * incoming request spans are disabled, which the Next.js SDK does because Next.js starts the request + * span. + */ +export function addServerTimingTraceHeader(client: Client): void { + client.on('httpServerRequest', (_request, response) => { + if (!isHttpServerResponse(response)) { + return; + } + + const writeHead = response.writeHead.bind(response); + response.writeHead = (...args: unknown[]): unknown => { + setServerTimingTraceHeader(response, getHeaderObjectArgument(args)); + return writeHead(...args); + }; + }); +} + +// `writeHead(status[, message], headers)`: headers given here win over `setHeader` ones. +function getHeaderObjectArgument(args: unknown[]): HeaderObject | undefined { + const last = args[args.length - 1]; + return args.length > 1 && isObjectLike(last) && !Array.isArray(last) ? last : undefined; +} + +function findHeaderKey(headers: HeaderObject | undefined, name: string): string | undefined { + return headers && Object.keys(headers).find(key => key.toLowerCase() === name); +} + +function readHeader(response: HttpServerResponse, headers: HeaderObject | undefined, name: string): string | undefined { + const key = findHeaderKey(headers, name); + const value = key ? headers?.[key] : response.getHeader(name); + return Array.isArray(value) ? value.join(', ') : value?.toString(); +} + +// Only the navigation entry of a document exposes the header to the browser SDK. +function isDocument(response: HttpServerResponse, headers: HeaderObject | undefined): boolean { + const contentType = readHeader(response, headers, 'content-type'); + return !contentType || contentType.startsWith('text/html'); +} + +/** + * Adds the trace of the current context to the `Server-Timing` header of a document response that no + * shared cache may store. Next.js sends static and ISR documents with `s-maxage`, and a CDN in front of + * the server that stores them would replay the trace, and the sampling decision, of one visitor to + * everyone who gets the cached copy. An existing `sentry-trace` entry of the app is left alone. + * + * @internal + */ +export function setServerTimingTraceHeader(response: HttpServerResponse, headers?: HeaderObject): void { + try { + if ( + response.headersSent || + isSharedCacheable(name => readHeader(response, headers, name)) || + !isDocument(response, headers) + ) { + return; + } + + const existingValue = readHeader(response, headers, SERVER_TIMING_HEADER); + if (existingValue?.includes('sentry-trace')) { + return; + } + + const traceHeader = getTraceServerTimingHeader(); + if (!traceHeader) { + return; + } + + const value = existingValue ? `${existingValue}, ${traceHeader}` : traceHeader; + const key = findHeaderKey(headers, SERVER_TIMING_HEADER); + if (headers && key) { + headers[key] = value; + } else { + response.setHeader('Server-Timing', value); + } + } catch (e) { + DEBUG_BUILD && debug.warn('Failed to add the trace to the Server-Timing header', e); + } +} diff --git a/packages/nextjs/test/client/appRouterRoutingInstrumentation.test.ts b/packages/nextjs/test/client/appRouterRoutingInstrumentation.test.ts index 76817198cd5a..3b9f87d94269 100644 --- a/packages/nextjs/test/client/appRouterRoutingInstrumentation.test.ts +++ b/packages/nextjs/test/client/appRouterRoutingInstrumentation.test.ts @@ -446,6 +446,33 @@ describe('appRouterInstrumentPageLoad', () => { expect(spanJson.links).toEqual([PRERENDER_LINK]); }); + it('continues the trace of a Server-Timing header at once and settles the type when the resumed part arrives', async () => { + const { core, pageload } = await setup('static'); + vi.spyOn(performance, 'getEntriesByType').mockReturnValue([ + { + serverTiming: [ + { name: 'sentry-trace', description: '33333333333333333333333333333333-3333333333333333-1', duration: 0 }, + ], + } as unknown as PerformanceEntry, + ]); + appendMeta(document.head, 'sentry-cache-origin', PRERENDER_SENTRY_TRACE); + + pageload.appRouterInstrumentPageLoad(core.getClient()!); + + const span = core.getActiveSpan()!; + expect(core.spanToJSON(span).trace_id).toBe('33333333333333333333333333333333'); + expect(core.spanToJSON(span).parent_span_id).toBe('3333333333333333'); + expect(core.spanToJSON(span).attributes).not.toHaveProperty(PAGE_SERVER_RENDERING_TYPE); + + appendMeta(document.body, 'sentry-trace', '33333333333333333333333333333333-4444444444444444-1'); + // MutationObserver callbacks run as microtasks. + await Promise.resolve(); + + const spanJson = core.spanToJSON(span); + expect(spanJson.attributes?.[PAGE_SERVER_RENDERING_TYPE]).toBe('partially_static'); + expect(spanJson.links).toEqual([PRERENDER_LINK]); + }); + it('links the server request when its trace meta tag arrives after the wait gave up', async () => { const { core, pageload } = await setup('static'); vi.useFakeTimers({ toFake: ['setTimeout', 'clearTimeout'] }); diff --git a/packages/nextjs/test/client/traceMetaTags.test.ts b/packages/nextjs/test/client/traceMetaTags.test.ts index ec821cc2312f..864f5b12364a 100644 --- a/packages/nextjs/test/client/traceMetaTags.test.ts +++ b/packages/nextjs/test/client/traceMetaTags.test.ts @@ -6,6 +6,7 @@ import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'; import { addTraceMetaTagLink, canWaitForTraceMetaTag, + observeLateTraceMetaTag, readTraceMetaTags, waitForTraceMetaTag, withCacheOrigin, @@ -22,6 +23,12 @@ function appendMeta(parent: HTMLElement, name: string, content: string): HTMLMet return meta; } +function setServerTimingTrace(sentryTrace: string): void { + vi.spyOn(performance, 'getEntriesByType').mockReturnValue([ + { serverTiming: [{ name: 'sentry-trace', description: sentryTrace, duration: 0 }] } as unknown as PerformanceEntry, + ]); +} + const originalReadyState = Object.getOwnPropertyDescriptor(Document.prototype, 'readyState'); function setReadyState(value: DocumentReadyState): void { @@ -268,6 +275,18 @@ describe('withCacheOrigin', () => { }); }); + it('leaves the type unset while a resumed part can still bring a tag after a Server-Timing header', () => { + appendMeta(document.head, 'sentry-cache-origin', HEAD_TRACE); + setReadyState('loading'); + setServerTimingTrace(BODY_TRACE); + + expect(withCacheOrigin(PAGELOAD_OPTIONS)).toEqual({ + name: '/products/:id', + attributes: { [SENTRY_OP]: PAGELOAD }, + links: [PRERENDER_LINK], + }); + }); + it.each([ { tag: 'holds an unsampled trace', content: '11111111111111111111111111111111-1111111111111111-0' }, { tag: 'holds a trace without a sampling decision', content: '11111111111111111111111111111111-1111111111111111' }, @@ -281,3 +300,87 @@ describe('withCacheOrigin', () => { }); }); }); + +describe('observeLateTraceMetaTag', () => { + const SERVER_REQUEST_LINK = { + context: { traceId: '22222222222222222222222222222222', spanId: '2222222222222222', traceFlags: 1 }, + attributes: { [SENTRY_LINK_TYPE]: 'server_request' }, + }; + + function createSpan(): Span & { setAttribute: ReturnType; addLink: ReturnType } { + return { isRecording: () => true, setAttribute: vi.fn(), addLink: vi.fn() } as unknown as Span & { + setAttribute: ReturnType; + addLink: ReturnType; + }; + } + + beforeEach(() => { + setReadyState('loading'); + }); + + it('marks a page as partially static when the tag arrives after a Server-Timing header connected the pageload', async () => { + appendMeta(document.head, 'sentry-cache-origin', HEAD_TRACE); + setServerTimingTrace(BODY_TRACE); + const span = createSpan(); + + observeLateTraceMetaTag(span); + appendMeta(document.body, 'sentry-trace', BODY_TRACE); + // MutationObserver callbacks run as microtasks. + await Promise.resolve(); + + expect(span.setAttribute).toHaveBeenCalledWith(PAGE_SERVER_RENDERING_TYPE, 'partially_static'); + expect(span.addLink).not.toHaveBeenCalled(); + }); + + it('marks a page as static when the document finishes without a tag', () => { + appendMeta(document.head, 'sentry-cache-origin', HEAD_TRACE); + setServerTimingTrace(BODY_TRACE); + const span = createSpan(); + + observeLateTraceMetaTag(span); + setReadyState('interactive'); + document.dispatchEvent(new Event('DOMContentLoaded')); + + expect(span.setAttribute).toHaveBeenCalledWith(PAGE_SERVER_RENDERING_TYPE, 'static'); + expect(span.addLink).not.toHaveBeenCalled(); + }); + + it('links the server request when nothing else connected the pageload', async () => { + appendMeta(document.head, 'sentry-cache-origin', HEAD_TRACE); + vi.spyOn(performance, 'getEntriesByType').mockReturnValue([]); + const span = createSpan(); + + observeLateTraceMetaTag(span); + appendMeta(document.body, 'sentry-trace', BODY_TRACE); + await Promise.resolve(); + + expect(span.addLink).toHaveBeenCalledWith(SERVER_REQUEST_LINK); + expect(span.setAttribute).toHaveBeenCalledWith(PAGE_SERVER_RENDERING_TYPE, 'partially_static'); + }); + + it('only links the server request for a document without a sentry-cache-origin tag', async () => { + vi.spyOn(performance, 'getEntriesByType').mockReturnValue([]); + const span = createSpan(); + + observeLateTraceMetaTag(span); + appendMeta(document.body, 'sentry-trace', BODY_TRACE); + await Promise.resolve(); + setReadyState('interactive'); + document.dispatchEvent(new Event('DOMContentLoaded')); + + expect(span.addLink).toHaveBeenCalledWith(SERVER_REQUEST_LINK); + expect(span.setAttribute).not.toHaveBeenCalled(); + }); + + it('does nothing once the document finished parsing', () => { + appendMeta(document.head, 'sentry-cache-origin', HEAD_TRACE); + setReadyState('interactive'); + const span = createSpan(); + + observeLateTraceMetaTag(span); + document.dispatchEvent(new Event('DOMContentLoaded')); + + expect(span.setAttribute).not.toHaveBeenCalled(); + expect(span.addLink).not.toHaveBeenCalled(); + }); +}); diff --git a/packages/nextjs/test/server/serverTimingHeader.test.ts b/packages/nextjs/test/server/serverTimingHeader.test.ts new file mode 100644 index 000000000000..5af40bdfffb8 --- /dev/null +++ b/packages/nextjs/test/server/serverTimingHeader.test.ts @@ -0,0 +1,164 @@ +import { IncomingMessage, ServerResponse } from 'node:http'; +import { Socket } from 'node:net'; +import { getCurrentScope, setCurrentClient, spanToJSON, startSpan } from '@sentry/core'; +import { NodeClient } from '@sentry/node'; +import { afterEach, describe, expect, it } from 'vitest'; +import { addServerTimingTraceHeader } from '../../src/server/serverTimingHeader'; + +function setup(options: { enabled?: boolean } = {}): NodeClient { + const client = new NodeClient({ + dsn: 'https://public@dsn.ingest.sentry.io/1337', + tracesSampleRate: 1, + integrations: [], + stackParser: () => [], + transport: () => ({ send: () => Promise.resolve({}), flush: () => Promise.resolve(true) }), + ...options, + }); + setCurrentClient(client); + client.init(); + addServerTimingTraceHeader(client); + return client; +} + +// Without a socket the response buffers what it writes, which is all these tests need. +function createResponse(client: NodeClient, headers: Record = {}): ServerResponse { + const response = new ServerResponse(new IncomingMessage(new Socket())); + Object.entries(headers).forEach(([name, value]) => response.setHeader(name, value)); + client.emit('httpServerRequest', {}, response, {}); + return response; +} + +describe('addServerTimingTraceHeader', () => { + afterEach(() => { + getCurrentScope().setClient(undefined); + }); + + it('sends the trace that is active when the headers go out with the first chunk', () => { + const client = setup(); + const response = createResponse(client, { 'Content-Type': 'text/html; charset=utf-8' }); + + const { trace_id: traceId, span_id: spanId } = startSpan({ name: 'GET /page' }, span => { + response.end(''); + return spanToJSON(span); + }); + + expect(response.getHeader('Server-Timing')).toMatch( + new RegExp(`^sentry-trace;desc="${traceId}-${spanId}-1", baggage;desc="sentry-environment=production,`), + ); + }); + + it('sends the trace when the headers are flushed explicitly', () => { + const client = setup(); + const response = createResponse(client); + + startSpan({ name: 'GET /page' }, () => response.flushHeaders()); + + expect(response.getHeader('Server-Timing')).toMatch(/^sentry-trace;desc="[a-f0-9]{32}-[a-f0-9]{16}-1"/); + }); + + it('keeps an existing Server-Timing header of the app', () => { + const client = setup(); + const response = createResponse(client, { 'Server-Timing': 'cache;dur=100' }); + + response.writeHead(200); + + expect(response.getHeader('Server-Timing')).toMatch(/^cache;dur=100, sentry-trace;desc="/); + }); + + // Headers passed to `writeHead` go straight into the raw header block, not into `getHeader`. + it('keeps a Server-Timing header passed to writeHead', () => { + const client = setup(); + const response = createResponse(client); + const headers = { 'server-timing': 'cache;dur=100' }; + + response.writeHead(200, headers); + + expect(headers['server-timing']).toMatch(/^cache;dur=100, sentry-trace;desc="/); + expect((response as unknown as { _header: string })._header).toContain('cache;dur=100, sentry-trace;desc="'); + }); + + it('leaves a Server-Timing header that already carries a sentry-trace entry alone', () => { + const client = setup(); + const response = createResponse(client, { 'Server-Timing': 'sentry-trace;desc="own"' }); + + response.writeHead(200); + + expect(response.getHeader('Server-Timing')).toBe('sentry-trace;desc="own"'); + }); + + it.each([ + 's-maxage=31536000', + 's-maxage=1, stale-while-revalidate=3599', + 'max-age=0, stale-while-revalidate=60', + 'public, max-age=31536000, immutable', + 'max-age=60', + ])('sends no trace with a response that a shared cache may store (%s)', cacheControl => { + const client = setup(); + const response = createResponse(client, { 'Cache-Control': cacheControl }); + + response.writeHead(200); + + expect(response.getHeader('Server-Timing')).toBeUndefined(); + }); + + it.each(['private, no-cache, no-store, max-age=0, must-revalidate', 'no-store', 'private, max-age=60'])( + 'sends the trace with a response that only the browser may store (%s)', + cacheControl => { + const client = setup(); + const response = createResponse(client, { 'Cache-Control': cacheControl }); + + response.writeHead(200); + + expect(response.getHeader('Server-Timing')).toMatch(/^sentry-trace;desc="/); + }, + ); + + it('sends no trace with a response that a CDN stores on its own field', () => { + const client = setup(); + const response = createResponse(client, { + 'Cache-Control': 'private, no-store', + 'Vercel-CDN-Cache-Control': 's-maxage=60', + }); + + response.writeHead(200); + + expect(response.getHeader('Server-Timing')).toBeUndefined(); + }); + + it('reads the Cache-Control header passed to writeHead', () => { + const client = setup(); + const response = createResponse(client); + + response.writeHead(200, { 'Cache-Control': 's-maxage=60' }); + + expect(response.getHeader('Server-Timing')).toBeUndefined(); + }); + + it.each(['application/json', 'text/x-component', 'image/png'])( + 'sends no trace with a response that is not a document (%s)', + contentType => { + const client = setup(); + const response = createResponse(client, { 'Content-Type': contentType }); + + response.writeHead(200); + + expect(response.getHeader('Server-Timing')).toBeUndefined(); + }, + ); + + it('sends no trace when the SDK is disabled', () => { + const client = setup({ enabled: false }); + const response = createResponse(client); + + response.writeHead(200); + + expect(response.getHeader('Server-Timing')).toBeUndefined(); + }); + + it('ignores a response that is not a Node.js server response', () => { + const client = setup(); + + expect(() => client.emit('httpServerRequest', {}, { end: () => undefined }, {})).not.toThrow(); + expect(() => client.emit('httpServerRequest', {}, undefined, {})).not.toThrow(); + }); +});