diff --git a/bun.lock b/bun.lock index 4d64e70dbc..938b418d4e 100644 --- a/bun.lock +++ b/bun.lock @@ -646,6 +646,7 @@ "@opentelemetry/exporter-trace-otlp-http": "^0.222.0", "@opentelemetry/instrumentation": "^0.222.0", "@opentelemetry/instrumentation-fetch": "^0.222.0", + "@opentelemetry/instrumentation-xml-http-request": "^0.222.0", "@opentelemetry/resources": "^2.10.0", "@opentelemetry/sdk-logs": "^0.222.0", "@opentelemetry/sdk-trace-base": "^2.10.0", @@ -1687,6 +1688,8 @@ "@opentelemetry/instrumentation-fetch": ["@opentelemetry/instrumentation-fetch@0.222.0", "", { "dependencies": { "@opentelemetry/core": "2.11.0", "@opentelemetry/instrumentation": "0.222.0", "@opentelemetry/sdk-trace-web": "2.11.0", "@opentelemetry/semantic-conventions": "^1.29.0" }, "peerDependencies": { "@opentelemetry/api": "^1.3.0" } }, "sha512-I0Vlvi1uzSnu4+cMssnYdaQgcJf/ffs0HSnq8/ZlkjgNS/J+ABc3196lZyL7uy++yRCl3bg2zPMhTphVdNx5sA=="], + "@opentelemetry/instrumentation-xml-http-request": ["@opentelemetry/instrumentation-xml-http-request@0.222.0", "", { "dependencies": { "@opentelemetry/core": "2.11.0", "@opentelemetry/instrumentation": "0.222.0", "@opentelemetry/sdk-trace-web": "2.11.0", "@opentelemetry/semantic-conventions": "^1.29.0" }, "peerDependencies": { "@opentelemetry/api": "^1.3.0" } }, "sha512-bA+6QSEV0tk/7IfGgCBnVIhTB6ljVP+eMuwCq/vPapNAZWsuS/8nFd+WE1R0oPJk+TBGGck23bhjq662MqJAEg=="], + "@opentelemetry/otlp-exporter-base": ["@opentelemetry/otlp-exporter-base@0.222.0", "", { "dependencies": { "@opentelemetry/core": "2.11.0", "@opentelemetry/otlp-transformer": "0.222.0" }, "peerDependencies": { "@opentelemetry/api": "^1.3.0" } }, "sha512-YbywG3veEm2Fb6TbdxRkuquWob6eVWXuA8/Ba1tXz9jHfUqpdE3keilOHEtPboC4CvS1bjeeVfNkWGOOrLj+lw=="], "@opentelemetry/otlp-transformer": ["@opentelemetry/otlp-transformer@0.222.0", "", { "dependencies": { "@opentelemetry/api-logs": "0.222.0", "@opentelemetry/core": "2.11.0", "@opentelemetry/resources": "2.11.0", "@opentelemetry/sdk-logs": "0.222.0", "@opentelemetry/sdk-metrics": "2.11.0", "@opentelemetry/sdk-trace": "2.11.0" }, "peerDependencies": { "@opentelemetry/api": "^1.3.0" } }, "sha512-/F3BZ89+CJQnZkMh2tCrtcdB+XT2Dxhj4FFE+WPQ//413hmFL0/RfEX6vgOIWGhiSzrkHWTK3+6SiT7K5/g/jQ=="], diff --git a/docs/browser-sdk.md b/docs/browser-sdk.md index e589756ee8..0f9210b377 100644 --- a/docs/browser-sdk.md +++ b/docs/browser-sdk.md @@ -25,7 +25,7 @@ MapleBrowser.init({ That call: -- starts OTel browser tracing, auto-instrumenting `fetch` and exporting to Maple's ingest (`POST /v1/traces`); +- starts OTel browser tracing, auto-instrumenting `fetch` and `XMLHttpRequest` and exporting to Maple's ingest (`POST /v1/traces`); - captures uncaught errors and unhandled promise rejections as error spans (see [Errors](#errors)); - records the session with rrweb, chunks events into ~5s / 100KB windows, gzips them with the native `CompressionStream`, and uploads them to `POST /v1/sessionReplays/blob`; - writes session metadata to `POST /v1/sessionReplays/meta`: an `active` row at start, a heartbeat every 60s, and an `ended` row on page hide, which includes the trace ids observed during the session. @@ -51,6 +51,7 @@ Every field accepted by `MapleBrowser.init`: | `userId` | `string` | none | **Deprecated**, use `user`. User id attached to the replay session and future browser spans. | | `tracing.enabled` | `boolean` | `true` | Enable OTel browser tracing. | | `tracing.instrumentFetch` | `boolean` | `true` | Auto-instrument `fetch()` to create network spans. Set `false` when another tracer (e.g. the Effect client SDK) already instruments requests. Its spans feed the session through the published sink, and turning this off avoids duplicate network spans. | +| `tracing.instrumentXhr` | `boolean` | `true` | Auto-instrument `XMLHttpRequest` (axios and older clients) like `fetch`. | | `tracing.captureErrors` | `boolean` | `true` | Record uncaught errors and unhandled rejections as error spans. See [Errors](#errors). | | `tracing.propagateTraceHeaderCorsUrls` | `Array` | `[]` | Cross-origin URLs whose `fetch()` requests carry the `traceparent` header. See [Tracing across origins](#tracing-across-origins). | | `tracing.sampleRate` | `number` | `1` | Fraction of sessions whose traces are exported, `0` to `1`. Decided per session; error spans are always exported. See [Sampling](#sampling). | @@ -286,9 +287,23 @@ to `exception.stacktrace` as `Caused by:` blocks after the error's own frames. I fingerprinted on the top frames, so adding a cause does not split an existing issue unless the error's own stack has fewer than three frames. +## Page load timing + +When your router calls `MapleBrowser.startNavigation` (see the package README), the first call opens +a `pageload` span that starts at the browser's navigation start, not when your JavaScript got to +run. Once the page has loaded, the SDK adds child spans from the Navigation Timing entry: + +| Span | Covers | +| --------------- | --------------------------------------------------------------------------- | +| `documentFetch` | fetching the HTML, with `dns`, `connect`, `request` and `response` under it | +| `domProcessing` | the response end until the DOM is complete | +| `loadEvent` | the page's `load` handlers | + +Phases that didn't happen (a reused connection has no `dns` or `connect`) are skipped. + ## Tracing across origins -`fetch` spans send the W3C `traceparent` header to same-origin requests only. When your API lives +`fetch` and `XMLHttpRequest` spans send the W3C `traceparent` header to same-origin requests only. When your API lives on another origin, list it so browser and backend spans join one trace, and allow the `traceparent` header in the API's CORS policy: diff --git a/packages/browser-session/src/replay/capture/network.browser.test.ts b/packages/browser-session/src/replay/capture/network.browser.test.ts new file mode 100644 index 0000000000..ef5f08dece --- /dev/null +++ b/packages/browser-session/src/replay/capture/network.browser.test.ts @@ -0,0 +1,51 @@ +import { afterEach, describe, expect, it } from "vitest" +import { noteStartedTraceId } from "../../events/trace-id" +import type { SessionEvent } from "../../events/events-sink" +import { installNetworkCapture } from "./network" + +const originalOpen = XMLHttpRequest.prototype.open +let uninstall: (() => void) | undefined + +afterEach(() => { + uninstall?.() + uninstall = undefined + XMLHttpRequest.prototype.open = originalOpen +}) + +const request = (xhr: XMLHttpRequest): Promise => + new Promise((resolve) => { + // A macrotask later, so the capture's own `loadend` listener has run. + xhr.addEventListener("loadend", () => setTimeout(resolve, 0)) + xhr.send() + }) + +describe("installNetworkCapture", () => { + it("links an XHR to a span its tracer started in open()", async () => { + // Stands in for a tracing instrumentation installed first, which starts its span in `open`. + const tracedOpen = originalOpen + XMLHttpRequest.prototype.open = function ( + this: XMLHttpRequest, + method: string, + url: string | URL, + async: boolean = true, + username?: string | null, + password?: string | null, + ) { + noteStartedTraceId("0af7651916cd43dd8448eb211c80319c") + tracedOpen.call(this, method, url, async, username, password) + } + const events: SessionEvent[] = [] + uninstall = installNetworkCapture( + (event) => events.push(event), + () => false, + ) + + const xhr = new XMLHttpRequest() + xhr.open("GET", "/") + await request(xhr) + + const network = events.find((event) => event.type === "network") + expect(network?.traceId).toBe("0af7651916cd43dd8448eb211c80319c") + expect(network?.net?.method).toBe("GET") + }) +}) diff --git a/packages/browser-session/src/replay/capture/network.ts b/packages/browser-session/src/replay/capture/network.ts index 090830cf7b..3e7ccb3e31 100644 --- a/packages/browser-session/src/replay/capture/network.ts +++ b/packages/browser-session/src/replay/capture/network.ts @@ -61,12 +61,15 @@ export function installNetworkCapture(emit: Emit, ignoreUrl: (url: string) => bo ) { ;(this as XhrMeta).__mapleMethod = String(method).toUpperCase() ;(this as XhrMeta).__mapleUrl = typeof url === "string" ? url : url.href - return origOpen.apply(this, [method, url, ...rest] as never) + // Some XHR instrumentations start their span in `open`, not `send`. + const call = withStartedTraceId(() => origOpen.apply(this, [method, url, ...rest] as never)) + ;(this as XhrMeta).__mapleTraceId = call.traceId + return call.result } XHR.prototype.send = function (this: XMLHttpRequest, ...args: unknown[]) { const meta = this as XhrMeta const start = performance.now() - let traceId = activeTraceId() + let traceId = meta.__mapleTraceId ?? activeTraceId() this.addEventListener("loadend", () => { record(meta.__mapleUrl ?? "", meta.__mapleMethod ?? "GET", this.status, start, traceId) }) @@ -86,6 +89,7 @@ export function installNetworkCapture(emit: Emit, ignoreUrl: (url: string) => bo interface XhrMeta extends XMLHttpRequest { __mapleMethod?: string __mapleUrl?: string + __mapleTraceId?: string | undefined } function requestUrl(input: RequestInfo | URL): string { diff --git a/packages/browser/README.md b/packages/browser/README.md index 4d39b34387..e88e62f359 100644 --- a/packages/browser/README.md +++ b/packages/browser/README.md @@ -172,6 +172,10 @@ MapleBrowser.endNavigation("/projects/:id") // the route is ready: its template render's trace from a `Server-Timing: traceparent;desc="…"` entry or a `` tag; later calls open `navigate` spans, and end one still open as `app.navigation.interrupted`. +- The document's `pageload` starts at navigation start, and gets child spans + from the Navigation Timing entry once the page has loaded: `documentFetch` + (with `dns`, `connect`, `request` and `response` under it), `domProcessing` + and `loadEvent`. - `traced` returns `fn`'s result and rethrows its error unchanged. Only requests started before `fn`'s first `await` nest under its span. An error it recorded isn't reported again by `captureException` or the global handlers. diff --git a/packages/browser/package.json b/packages/browser/package.json index 1426327add..d4a1ee1525 100644 --- a/packages/browser/package.json +++ b/packages/browser/package.json @@ -47,6 +47,7 @@ "@opentelemetry/exporter-trace-otlp-http": "^0.222.0", "@opentelemetry/instrumentation": "^0.222.0", "@opentelemetry/instrumentation-fetch": "^0.222.0", + "@opentelemetry/instrumentation-xml-http-request": "^0.222.0", "@opentelemetry/resources": "^2.10.0", "@opentelemetry/sdk-logs": "^0.222.0", "@opentelemetry/sdk-trace-base": "^2.10.0", diff --git a/packages/browser/scripts/size.ts b/packages/browser/scripts/size.ts index 42d657374b..c3a21a4c1a 100644 --- a/packages/browser/scripts/size.ts +++ b/packages/browser/scripts/size.ts @@ -24,13 +24,15 @@ import { gzipSync } from "node:zlib" /** Ceilings in gzipped KB. Raise deliberately, with the reason in the commit. */ const BUDGET = { /** - * 42 since 2026-09: error filters and cause chains (~0.8 kB). 41 before that: + * 43 since 2026-09: XHR spans and the HTTP status policy, which must patch + * before the app's first request (~1.5 kB). Document timing went to the + * deferred chunk instead. 42: error filters and cause chains. 41 before that: * per-session trace sampling and the `logger` queue added ~2.4 kB (~1.2 kB * code, the rest chunk-split overhead now that a second chunk shares the OTel * core). Was 38 for navigation spans. */ - eager: 42, - /** Every page load, after `init()`: the OTel logs SDK and exporter. */ + eager: 43, + /** Every page load, after `init()`: the OTel logs SDK and exporter, document timing. */ deferred: 8, lazy: 68, /** diff --git a/packages/browser/src/config.ts b/packages/browser/src/config.ts index 70e2ed9fee..3720af8447 100644 --- a/packages/browser/src/config.ts +++ b/packages/browser/src/config.ts @@ -55,6 +55,11 @@ export interface MapleBrowserConfig { * sink, and disabling this avoids redundant duplicate network spans. */ readonly instrumentFetch?: boolean + /** + * Auto-instrument `XMLHttpRequest` (axios and older clients) the same way. + * Default true. Turn it off for the same reason as `instrumentFetch`. + */ + readonly instrumentXhr?: boolean /** * Capture uncaught errors and unhandled promise rejections as error * spans. Default true. Turn off only when another tracker already owns @@ -138,6 +143,7 @@ export interface ResolvedConfig { identity: ResolvedIdentity | undefined readonly tracingEnabled: boolean readonly tracingInstrumentFetch: boolean + readonly tracingInstrumentXhr: boolean readonly tracingCaptureErrors: boolean readonly propagateTraceHeaderCorsUrls: ReadonlyArray readonly tracingSampleRate: number @@ -202,6 +208,7 @@ export function resolveConfig(config: MapleBrowserConfig): ResolvedConfig { identity: resolveIdentity(config), tracingEnabled: config.tracing?.enabled ?? true, tracingInstrumentFetch: config.tracing?.instrumentFetch ?? true, + tracingInstrumentXhr: config.tracing?.instrumentXhr ?? true, tracingCaptureErrors: config.tracing?.captureErrors ?? true, propagateTraceHeaderCorsUrls: config.tracing?.propagateTraceHeaderCorsUrls ?? [], tracingSampleRate: resolveSampleRate("tracing.sampleRate", config.tracing?.sampleRate), diff --git a/packages/browser/src/deferred/document-timing.ts b/packages/browser/src/deferred/document-timing.ts new file mode 100644 index 0000000000..bbbdd2c5d7 --- /dev/null +++ b/packages/browser/src/deferred/document-timing.ts @@ -0,0 +1,79 @@ +// The document's own load, as child spans of the `pageload` navigation: the +// response for the HTML (and its network phases), DOM processing, and the load +// event. Read from the Navigation Timing entry once the page has loaded. +import { scrubUrl } from "@maple/browser-session" +import { context, type Span, type Tracer, trace, TraceFlags } from "@opentelemetry/api" + +type Mark = (entry: PerformanceNavigationTiming) => number +type Phase = readonly [name: string, start: Mark, end: Mark] + +const FETCH_PHASES: ReadonlyArray = [ + ["dns", (e) => e.domainLookupStart, (e) => e.domainLookupEnd], + ["connect", (e) => e.connectStart, (e) => e.connectEnd], + ["request", (e) => e.requestStart, (e) => e.responseStart], + ["response", (e) => e.responseStart, (e) => e.responseEnd], +] + +const PAGE_PHASES: ReadonlyArray = [ + ["domProcessing", (e) => e.responseEnd, (e) => e.domComplete], + ["loadEvent", (e) => e.loadEventStart, (e) => e.loadEventEnd], +] + +/** Epoch ms for a Navigation Timing offset. */ +const at = (offset: number): number => performance.timeOrigin + offset + +function spanPhases( + tracer: Tracer, + parent: Span, + entry: PerformanceNavigationTiming, + phases: ReadonlyArray, +): void { + const ctx = trace.setSpan(context.active(), parent) + for (const [name, start, end] of phases) { + const from = start(entry) + const to = end(entry) + // Zero marks are phases that did not happen: a reused connection has no dns or connect. + if (from <= 0 || to <= from) continue + tracer.startSpan(name, { startTime: at(from) }, ctx).end(at(to)) + } +} + +function record(tracer: Tracer, pageload: Span): void { + const [entry] = performance.getEntriesByType("navigation") + if (!(entry instanceof PerformanceNavigationTiming) || entry.responseEnd <= 0) return + const fetch = tracer.startSpan( + "documentFetch", + { + startTime: at(entry.fetchStart), + attributes: { + "url.full": scrubUrl(entry.name), + ...(entry.responseStatus > 0 + ? { "http.response.status_code": entry.responseStatus } + : undefined), + ...(entry.encodedBodySize > 0 + ? { "http.response.body.size": entry.encodedBodySize } + : undefined), + }, + }, + trace.setSpan(context.active(), pageload), + ) + spanPhases(tracer, fetch, entry, FETCH_PHASES) + fetch.end(at(entry.responseEnd)) + spanPhases(tracer, pageload, entry, PAGE_PHASES) +} + +/** Span the document's load under `pageload`, now or once the `load` event has finished. */ +export function recordDocumentTiming(tracer: Tracer, pageload: Span): void { + // Sampled, not recording: the app has usually ended the span by the time this chunk lands. + const sampled = (pageload.spanContext().traceFlags & TraceFlags.SAMPLED) !== 0 + if (!sampled || typeof performance.getEntriesByType !== "function") return + // A task after `load`, so `loadEventEnd` is set. Timing is best-effort: never throw into the page. + const run = (): void => + void setTimeout(() => { + try { + record(tracer, pageload) + } catch {} + }, 0) + if (document.readyState === "complete") run() + else window.addEventListener("load", run, { once: true }) +} diff --git a/packages/browser/src/deferred/index.ts b/packages/browser/src/deferred/index.ts index fedef2c720..0c1f6ccd88 100644 --- a/packages/browser/src/deferred/index.ts +++ b/packages/browser/src/deferred/index.ts @@ -1,10 +1,13 @@ // Everything that can start a moment after `init()` without losing data lives // behind this chunk, so it stays off the eager bundle every page load pays for. import type { ResolvedConfig } from "../config" +import { onDocumentPageload } from "../navigation" +import { recordDocumentTiming } from "./document-timing" import { startLogs } from "./logs" export function startDeferred(config: ResolvedConfig): () => Promise { - const stops = [startLogs(config)] + onDocumentPageload(recordDocumentTiming) + const stops = [startLogs(config), async () => onDocumentPageload(undefined)] return async () => { await Promise.all(stops.map((stop) => stop())) } diff --git a/packages/browser/src/http-status.test.ts b/packages/browser/src/http-status.test.ts new file mode 100644 index 0000000000..67873f60bf --- /dev/null +++ b/packages/browser/src/http-status.test.ts @@ -0,0 +1,62 @@ +import { SpanKind, SpanStatusCode } from "@opentelemetry/api" +import { + BasicTracerProvider, + InMemorySpanExporter, + type ReadableSpan, + SimpleSpanProcessor, +} from "@opentelemetry/sdk-trace-base" +import { describe, expect, it } from "vitest" +import { HttpStatusExporter } from "./http-status" + +const exported = new InMemorySpanExporter() +const tracer = new BasicTracerProvider({ + spanProcessors: [new SimpleSpanProcessor(new HttpStatusExporter(exported))], +}).getTracer("test") + +const finish = ( + build: (span: ReturnType) => void, + kind = SpanKind.CLIENT, +): ReadableSpan => { + exported.reset() + const span = tracer.startSpan("GET", { kind }) + build(span) + span.end() + const [result] = exported.getFinishedSpans() + if (!result) throw new Error("nothing exported") + return result +} + +describe("HttpStatusExporter", () => { + it("clears an Error set only because of the response status", () => { + const span = finish((s) => { + s.setAttribute("http.response.status_code", 404) + s.setAttribute("error.type", "404") + s.setStatus({ code: SpanStatusCode.ERROR }) + }) + expect(span.status.code).toBe(SpanStatusCode.UNSET) + expect(span.attributes["error.type"]).toBeUndefined() + expect(span.attributes["http.response.status_code"]).toBe(404) + expect(span.spanContext().spanId).toMatch(/^[0-9a-f]{16}$/) + }) + + it("keeps network failures, recorded exceptions, and non-client spans", () => { + const network = finish((s) => { + s.setAttribute("error.type", "timeout") + s.setStatus({ code: SpanStatusCode.ERROR, message: "timeout" }) + }) + expect(network.status.code).toBe(SpanStatusCode.ERROR) + + const withException = finish((s) => { + s.setAttribute("error.type", "500") + s.recordException(new Error("boom")) + s.setStatus({ code: SpanStatusCode.ERROR }) + }) + expect(withException.status.code).toBe(SpanStatusCode.ERROR) + + const internal = finish((s) => { + s.setAttribute("error.type", "500") + s.setStatus({ code: SpanStatusCode.ERROR }) + }, SpanKind.INTERNAL) + expect(internal.status.code).toBe(SpanStatusCode.ERROR) + }) +}) diff --git a/packages/browser/src/http-status.ts b/packages/browser/src/http-status.ts new file mode 100644 index 0000000000..cb6fe6ec30 --- /dev/null +++ b/packages/browser/src/http-status.ts @@ -0,0 +1,60 @@ +// One rule for when an HTTP client span is an error, whichever instrumentation +// made it. The fetch instrumentation leaves 4xx/5xx responses Unset; the XHR +// one marks every status >= 400 Error, and every Error span becomes an issue. +// A response status alone is not an error here; a network failure still is. +import { type Attributes, SpanKind, SpanStatusCode } from "@opentelemetry/api" +import type { ReadableSpan, SpanExporter } from "@opentelemetry/sdk-trace-base" + +const HTTP_STATUS = /^\d{3}$/ + +/** An Error set only because of the response status: `error.type` is the status code itself. */ +function isStatusOnlyError(span: ReadableSpan): boolean { + return ( + span.kind === SpanKind.CLIENT && + span.status.code === SpanStatusCode.ERROR && + HTTP_STATUS.test(String(span.attributes["error.type"] ?? "")) && + !span.events.some((event) => event.name === "exception") + ) +} + +function withoutStatusError(span: ReadableSpan): ReadableSpan { + const { "error.type": _errorType, ...attributes } = span.attributes + return { + name: span.name, + kind: span.kind, + spanContext: () => span.spanContext(), + parentSpanContext: span.parentSpanContext, + startTime: span.startTime, + endTime: span.endTime, + status: { code: SpanStatusCode.UNSET }, + attributes: attributes satisfies Attributes, + links: span.links, + events: span.events, + duration: span.duration, + ended: span.ended, + resource: span.resource, + instrumentationScope: span.instrumentationScope, + droppedAttributesCount: span.droppedAttributesCount, + droppedEventsCount: span.droppedEventsCount, + droppedLinksCount: span.droppedLinksCount, + } +} + +export class HttpStatusExporter implements SpanExporter { + constructor(private readonly inner: SpanExporter) {} + + export(spans: ReadableSpan[], callback: (result: { code: number; error?: Error }) => void): void { + this.inner.export( + spans.map((span) => (isStatusOnlyError(span) ? withoutStatusError(span) : span)), + callback, + ) + } + + forceFlush(): Promise { + return this.inner.forceFlush?.() ?? Promise.resolve() + } + + shutdown(): Promise { + return this.inner.shutdown() + } +} diff --git a/packages/browser/src/logs.browser.test.ts b/packages/browser/src/logs.browser.test.ts index 0245c1ba97..e8f926a202 100644 --- a/packages/browser/src/logs.browser.test.ts +++ b/packages/browser/src/logs.browser.test.ts @@ -37,6 +37,18 @@ const BASE: InitConfig = { tracing: { instrumentFetch: false }, } +/** Document timing spans (`documentFetch`, `dns`, ...) are covered by their own tests. */ +const TIMING_SPANS = new Set([ + "documentFetch", + "dns", + "connect", + "request", + "response", + "domProcessing", + "loadEvent", +]) +const spanNames = () => exportedSpans.filter((span) => !TIMING_SPANS.has(span.name)).map((span) => span.name) + let handle: ReturnType | undefined const stop = async (): Promise => { await handle?.shutdown() @@ -122,7 +134,7 @@ describe("tracing.sampleRate", () => { MapleBrowser.captureException(error) await stop() - expect(exportedSpans.map((span) => span.name)).toEqual(["exception"]) + expect(spanNames()).toEqual(["exception"]) expect(exportedSpans[0]?.parentSpanContext).toBeUndefined() }) @@ -146,7 +158,7 @@ describe("tracing.sampleRate", () => { MapleBrowser.startNavigation("/a") MapleBrowser.endNavigation("/a") await stop() - expect(exportedSpans.map((span) => span.name)).toEqual(["pageload /a"]) + expect(spanNames()).toEqual(["pageload /a"]) expect(exportedSpans[0]?.spanContext().traceState).toBeUndefined() }) }) diff --git a/packages/browser/src/navigation.browser.test.ts b/packages/browser/src/navigation.browser.test.ts index 155fc6e66d..2b0faed482 100644 --- a/packages/browser/src/navigation.browser.test.ts +++ b/packages/browser/src/navigation.browser.test.ts @@ -1,5 +1,5 @@ // TEST-SEAM: This focused test replaces process-global modules that have no instance-level injection seam. -import { resetConsentForTests } from "@maple/browser-session" +import { resetConsentForTests, scrubUrl, setConsent } from "@maple/browser-session" import { context, INVALID_SPAN_CONTEXT, @@ -61,6 +61,18 @@ const stop = async (): Promise => { handle = undefined } +/** Document timing spans (`documentFetch`, `dns`, ...) are covered by their own tests. */ +const TIMING_SPANS = new Set([ + "documentFetch", + "dns", + "connect", + "request", + "response", + "domProcessing", + "loadEvent", +]) +const spanNames = () => exported.filter((span) => !TIMING_SPANS.has(span.name)).map((span) => span.name) + const named = (name: string): ReadableSpan => { const span = exported.find((candidate) => candidate.name === name) if (!span) throw new Error(`no exported span named ${name}: ${exported.map((s) => s.name).join(", ")}`) @@ -122,7 +134,7 @@ describe("startNavigation / endNavigation", () => { MapleBrowser.endNavigation("/settings") await stop() - expect(exported.map((span) => span.name)).toEqual(["pageload /projects/:id", "navigate /settings"]) + expect(spanNames()).toEqual(["pageload /projects/:id", "navigate /settings"]) expect(named("pageload /projects/:id").attributes["url.path"]).toBe("/projects/8f2a") expect(named("navigate /settings").attributes["url.path"]).toBe("/settings") expect(named("navigate /settings").attributes["app.navigation.interrupted"]).toBeUndefined() @@ -134,7 +146,7 @@ describe("startNavigation / endNavigation", () => { MapleBrowser.endNavigation() await stop() - expect(exported.map((span) => span.name)).toEqual(["pageload"]) + expect(spanNames()).toEqual(["pageload"]) }) it("does nothing when no navigation is open", async () => { @@ -146,7 +158,7 @@ describe("startNavigation / endNavigation", () => { MapleBrowser.endNavigation("/b") await stop() - expect(exported.map((span) => span.name)).toEqual(["pageload /a"]) + expect(spanNames()).toEqual(["pageload /a"]) }) it("ends a navigation still open when the next starts, as interrupted", async () => { @@ -158,7 +170,7 @@ describe("startNavigation / endNavigation", () => { MapleBrowser.endNavigation("/fast") await stop() - expect(exported.map((span) => span.name)).toEqual(["pageload /a", "navigate", "navigate /fast"]) + expect(spanNames()).toEqual(["pageload /a", "navigate", "navigate /fast"]) expect(named("navigate").attributes["app.navigation.interrupted"]).toBe(true) expect(named("navigate").attributes["url.path"]).toBe("/slow") expect(named("navigate /fast").attributes["app.navigation.interrupted"]).toBeUndefined() @@ -179,7 +191,7 @@ describe("startNavigation / endNavigation", () => { MapleBrowser.endNavigation("/login?token=abc") await stop() - expect(exported.map((span) => span.name)).toEqual(["pageload /login?token=REDACTED"]) + expect(spanNames()).toEqual(["pageload /login?token=REDACTED"]) }) it("ends and exports a navigation still open when the page is left", async () => { @@ -188,11 +200,11 @@ describe("startNavigation / endNavigation", () => { window.dispatchEvent(new Event("pagehide")) // Exported by the page-exit flush itself, not by shutdown - await vi.waitFor(() => expect(exported.map((span) => span.name)).toEqual(["pageload"])) + await vi.waitFor(() => expect(spanNames()).toEqual(["pageload"])) expect(named("pageload").attributes["app.navigation.interrupted"]).toBe(true) expect(() => MapleBrowser.endNavigation("/checkout")).not.toThrow() await stop() - expect(exported).toHaveLength(1) + expect(spanNames()).toEqual(["pageload"]) }) it("stamps session.id and user.id like every other span", async () => { @@ -517,9 +529,9 @@ describe("error dedupe", () => { expect(allExceptionEvents()).toHaveLength(1) expect(exceptionEvents(named("loader /a"))).toHaveLength(1) - expect(exported.map((span) => span.name)).not.toContain("react.render_error") - expect(exported.map((span) => span.name)).not.toContain("browser.unhandled_rejection") - expect(exported.map((span) => span.name)).not.toContain("browser.uncaught_error") + expect(spanNames()).not.toContain("react.render_error") + expect(spanNames()).not.toContain("browser.unhandled_rejection") + expect(spanNames()).not.toContain("browser.uncaught_error") }) it("puts the exception event on the innermost span only when traced calls nest", async () => { @@ -550,7 +562,7 @@ describe("error dedupe", () => { MapleBrowser.captureException(error) await stop() - expect(exported.map((span) => span.name)).toEqual(["exception"]) + expect(spanNames()).toEqual(["exception"]) }) }) @@ -582,7 +594,7 @@ describe("without live tracing", () => { MapleBrowser.endNavigation("/b") await stop() - expect(exported.map((span) => span.name)).toEqual(["navigate /b"]) + expect(spanNames()).toEqual(["navigate /b"]) }) it("is a no-op with tracing disabled", async () => { @@ -608,7 +620,7 @@ describe("without live tracing", () => { // The page load came before consent: the first traced navigation is a // click, not the page load, and does not join the server render's trace - expect(exported.map((span) => span.name)).toEqual(["loader /b", "navigate /b"]) + expect(spanNames()).toEqual(["loader /b", "navigate /b"]) expect(named("navigate /b").spanContext().traceId).not.toBe(SERVER_TRACE_ID) }) @@ -629,7 +641,7 @@ describe("without live tracing", () => { MapleBrowser.captureException(error) await stop() - expect(exported.map((span) => span.name)).toEqual(["exception"]) + expect(spanNames()).toEqual(["exception"]) }) it("is a no-op after shutdown", async () => { @@ -647,7 +659,7 @@ describe("shutdown", () => { MapleBrowser.startNavigation("/a") await stop() - expect(exported.map((span) => span.name)).toEqual(["pageload"]) + expect(spanNames()).toEqual(["pageload"]) expect(named("pageload").attributes["app.navigation.interrupted"]).toBe(true) // Ended and cleared: nothing left to end expect(() => MapleBrowser.endNavigation("/a")).not.toThrow() @@ -657,7 +669,7 @@ describe("shutdown", () => { MapleBrowser.startNavigation("/b") MapleBrowser.endNavigation("/b") await stop() - expect(exported.map((span) => span.name)).toEqual(["pageload /b"]) + expect(spanNames()).toEqual(["pageload /b"]) // Long past the server render: only the document's own page load joins it expect(parentOf(named("pageload /b"))).toBeUndefined() expect(named("pageload /b").spanContext().traceId).not.toBe(SERVER_TRACE_ID) @@ -684,3 +696,52 @@ describe("host-owned global provider", () => { expect(parentOf(named("loader /a"))).toBe(named("pageload /a").spanContext().spanId) }) }) + +/** The deferred chunk spans the document a task after it lands (the test page loaded long ago). */ +const timingRecorded = async (): Promise => { + await import("./deferred") + await new Promise((resolve) => setTimeout(resolve, 20)) +} + +describe("document timing", () => { + it("starts the page load at navigation start and spans the document's load under it", async () => { + start() + MapleBrowser.startNavigation("/a") + MapleBrowser.endNavigation("/a") + await timingRecorded() + await stop() + + const pageload = named("pageload /a") + const fetch = named("documentFetch") + const toMs = ([s, ns]: [number, number]) => s * 1_000 + ns / 1_000_000 + expect(toMs(pageload.startTime)).toBeCloseTo(performance.timeOrigin, 0) + expect(parentOf(fetch)).toBe(pageload.spanContext().spanId) + expect(fetch.attributes["url.full"]).toBe(scrubUrl(location.href)) + const response = named("response") + expect(parentOf(response)).toBe(fetch.spanContext().spanId) + const [entry] = performance.getEntriesByType("navigation") + if (!(entry instanceof PerformanceNavigationTiming)) throw new Error("no navigation entry") + expect(toMs(response.endTime)).toBeCloseTo(performance.timeOrigin + entry.responseEnd, 0) + expect(parentOf(named("domProcessing"))).toBe(pageload.spanContext().spanId) + }) + + it("starts the page load at the consent grant when consent came later, so it still exports", async () => { + start({ privacy: { requireConsent: true } }) + setConsent(true) + MapleBrowser.startNavigation("/a") + MapleBrowser.endNavigation("/a") + await stop() + expect(spanNames()).toContain("pageload /a") + }) + + it("does not span the document again for a navigate", async () => { + start() + MapleBrowser.startNavigation("/a") + MapleBrowser.endNavigation("/a") + await timingRecorded() + MapleBrowser.startNavigation("/b") + MapleBrowser.endNavigation("/b") + await stop() + expect(exported.filter((span) => span.name === "documentFetch")).toHaveLength(1) + }) +}) diff --git a/packages/browser/src/navigation.test.ts b/packages/browser/src/navigation.test.ts index 84b597c743..1c3b68416d 100644 --- a/packages/browser/src/navigation.test.ts +++ b/packages/browser/src/navigation.test.ts @@ -45,6 +45,7 @@ const CONFIG = { respectDoNotTrack: false, propagateTraceHeaderCorsUrls: [], tracingSampleRate: 1, + tracingInstrumentXhr: false, errorFilters: {}, sanitizeUrl: undefined, } diff --git a/packages/browser/src/navigation.ts b/packages/browser/src/navigation.ts index 947ab5e9fd..b3887967ef 100644 --- a/packages/browser/src/navigation.ts +++ b/packages/browser/src/navigation.ts @@ -10,7 +10,7 @@ // app that registered its provider first owns that). Without a live provider // (before `init()`, after `shutdown()`, tracing disabled, consent not yet // granted, or on a server) nothing is spanned and `traced` only runs `fn`. -import { hasConsent, scrubUrl } from "@maple/browser-session" +import { consentAllowedSince, hasConsent, scrubUrl } from "@maple/browser-session" import { type Context, context, @@ -18,6 +18,7 @@ import { type Span, type SpanContext, trace, + type Tracer, } from "@opentelemetry/api" import { captureException, recordFailure } from "./errors" import { liveMapleTracer } from "./tracing" @@ -47,6 +48,18 @@ let firstLoad = true */ let documentLoad = true +type PageloadListener = (tracer: Tracer, pageload: Span) => void +/** Set by the deferred chunk, which spans the document's own load under `pageload`. */ +let pageloadListener: PageloadListener | undefined +/** A document page load that began before the deferred chunk landed. */ +let pendingPageload: { readonly tracer: Tracer; readonly span: Span } | undefined + +export function onDocumentPageload(listener: PageloadListener | undefined): void { + pageloadListener = listener + if (listener && pendingPageload) listener(pendingPageload.tracer, pendingPageload.span) + pendingPageload = undefined +} + /** Spans `traced` opened, which a nested `traced` may parent to instead of the navigation. */ const tracedSpans = new WeakSet() @@ -74,7 +87,15 @@ export function startNavigation(path: string): void { const live = tracer() if (!live) return const parent = (joinServer ? serverContext() : undefined) ?? context.active() - navigation = { kind, span: live.startSpan(kind, { attributes: { "url.path": scrubUrl(path) } }, parent) } + // The document's page load began at navigation start, not when the app's JS got here, + // but never before a consent grant: the exporter drops anything that began earlier. + const startTime = joinServer ? Math.max(performance.timeOrigin, consentAllowedSince()) : undefined + const span = live.startSpan(kind, { startTime, attributes: { "url.path": scrubUrl(path) } }, parent) + navigation = { kind, span } + if (joinServer) { + if (pageloadListener) pageloadListener(live, span) + else pendingPageload = { tracer: live, span } + } // A page left mid-navigation still exports it. Capture phase, so this runs // before the provider's own `pagehide` flush (at the target, capture // listeners run first). Registering the same listener again is a no-op. @@ -139,6 +160,7 @@ function isFailure(options: TracedOptions, error: unknown): boolean { export function resetNavigation(): void { interruptNavigation() firstLoad = true + pendingPageload = undefined } /** Test seam: as if the document had just loaded. */ diff --git a/packages/browser/src/tracing.browser.test.ts b/packages/browser/src/tracing.browser.test.ts index 27798ac9e9..9532a34e9c 100644 --- a/packages/browser/src/tracing.browser.test.ts +++ b/packages/browser/src/tracing.browser.test.ts @@ -54,6 +54,7 @@ const CONFIG = { respectDoNotTrack: false, propagateTraceHeaderCorsUrls: [], tracingSampleRate: 1, + tracingInstrumentXhr: false, errorFilters: {}, sanitizeUrl: undefined, } @@ -205,6 +206,26 @@ describe("setupTracing unload flush", () => { URL.revokeObjectURL(url) }) + it("spans an XMLHttpRequest and ends it on pagehide like a fetch", async () => { + vi.useFakeTimers({ toFake: ["setTimeout"] }) + const poll = { interval: 0 } + shutdown = setupTracing({ ...CONFIG, tracingInstrumentXhr: true }) + const url = URL.createObjectURL(new Blob(["ok"])) + + const xhr = new XMLHttpRequest() + xhr.open("GET", url) + await new Promise((resolve) => { + xhr.addEventListener("loadend", () => resolve()) + xhr.send() + }) + await vi.waitFor(() => expect(vi.getTimerCount()).toBeGreaterThan(0), poll) + + window.dispatchEvent(new Event("pagehide")) + await vi.waitFor(() => expect(exported).toHaveLength(1), poll) + expect(exported[0]?.attributes["url.full"] ?? exported[0]?.attributes["http.url"]).toBe(url) + URL.revokeObjectURL(url) + }) + it("does not end a fetch span the instrumentation already ended", async () => { const errors: string[] = [] const noop = (): void => {} diff --git a/packages/browser/src/tracing.ts b/packages/browser/src/tracing.ts index b20777cb68..b41a982c86 100644 --- a/packages/browser/src/tracing.ts +++ b/packages/browser/src/tracing.ts @@ -18,12 +18,14 @@ import { import { OTLPTraceExporter } from "@opentelemetry/exporter-trace-otlp-http" import { registerInstrumentations } from "@opentelemetry/instrumentation" import { FetchInstrumentation } from "@opentelemetry/instrumentation-fetch" +import { XMLHttpRequestInstrumentation } from "@opentelemetry/instrumentation-xml-http-request" import { resourceFromAttributes } from "@opentelemetry/resources" import type { ReadableSpan, Span, SpanExporter, SpanProcessor } from "@opentelemetry/sdk-trace-base" import { BatchSpanProcessor } from "@opentelemetry/sdk-trace-base" import { WebTracerProvider } from "@opentelemetry/sdk-trace-web" import { ATTR_SERVICE_NAME, ATTR_SERVICE_VERSION } from "@opentelemetry/semantic-conventions" import type { ResolvedConfig } from "./config" +import { HttpStatusExporter } from "./http-status" import { SessionSampler } from "./sampling" import { SDK_NAME, SDK_VERSION } from "./version" @@ -163,12 +165,14 @@ export function resourceAttributes(config: ResolvedConfig): Record Promise { const exporter = new ConsentSpanExporter( - new OTLPTraceExporter({ - url: `${config.endpoint}/v1/traces`, - // The same auth + `x-maple-sdk` headers as every session write; a page - // cannot set `user-agent`, so ingest reads the SDK from the latter. - headers: ingestHeaders({ ingestKey: config.ingestKey, sdk: sdkHint(SDK_NAME, SDK_VERSION) }), - }), + new HttpStatusExporter( + new OTLPTraceExporter({ + url: `${config.endpoint}/v1/traces`, + // The same auth + `x-maple-sdk` headers as every session write; a page + // cannot set `user-agent`, so ingest reads the SDK from the latter. + headers: ingestHeaders({ ingestKey: config.ingestKey, sdk: sdkHint(SDK_NAME, SDK_VERSION) }), + }), + ), ) const provider = new WebTracerProvider({ @@ -211,8 +215,8 @@ export function setupTracing(config: ResolvedConfig): () => Promise { const onVisibilityChange = (): void => { if (document.visibilityState === "hidden") onExit() } - // Fetch spans need a push first on the way out: the fetch instrumentation - // ends each one 300ms after its response (waiting on resource timing), so a + // Fetch and XHR spans need a push first on the way out: both instrumentations + // end each one 300ms after its response (waiting on resource timing), so a // fetch that settled just before a navigation is still open when the flush // runs, and the page is gone before its timer fires. `pagehide` ends those at // their real response time, dropping their resource-timing network events. @@ -220,46 +224,50 @@ export function setupTracing(config: ResolvedConfig): () => Promise { // tab switch) lives on, and its timer would then hit an ended span. A page // entering the bfcache fires it too; ending there is still right, since it // may never be restored. - const settledFetches = new Map() + const settledRequests = new Map() const onPageHide = (): void => { - for (const [span, endTime] of settledFetches) { - // Entries are only pruned on the next fetch, so some already ended. + for (const [span, endTime] of settledRequests) { + // Entries are only pruned on the next request, so some already ended. if (span.isRecording()) span.end(endTime) } - settledFetches.clear() + settledRequests.clear() onExit() } + // Runs as the response settles, right before the instrumentation schedules + // the span's deferred end. Pruning here keeps the map to spans still waiting. + const noteSettled = (span: ApiSpan): void => { + for (const settled of settledRequests.keys()) { + if (!settled.isRecording()) settledRequests.delete(settled) + } + settledRequests.set(span, Date.now()) + } const canListen = typeof document !== "undefined" && typeof document.addEventListener === "function" if (canListen) { document.addEventListener("visibilitychange", onVisibilityChange) window.addEventListener("pagehide", onPageHide) } - const unregisterInstrumentations = config.tracingInstrumentFetch - ? registerInstrumentations({ - // Explicit, not the global: a host app that registered its own provider - // first owns the global, and these spans would otherwise go to it. - tracerProvider: provider, - instrumentations: [ - new FetchInstrumentation({ - // Maple's own ingest calls are not traced at all. - ignoreUrls: [new RegExp(`${escapeRegExp(config.endpoint)}/v1/`)], - // `traceparent` goes to same-origin requests only, unless the app - // lists the cross-origin APIs that accept it. - propagateTraceHeaderCorsUrls: [...config.propagateTraceHeaderCorsUrls], - // Runs as the response settles, right before the instrumentation - // schedules the span's deferred end. Pruning here keeps the map to - // spans still waiting on that timer. - applyCustomAttributesOnSpan: (span) => { - for (const settled of settledFetches.keys()) { - if (!settled.isRecording()) settledFetches.delete(settled) - } - settledFetches.set(span, Date.now()) - }, - }), - ], - }) - : undefined + const requestOptions = { + // Maple's own ingest calls are not traced at all. + ignoreUrls: [new RegExp(`${escapeRegExp(config.endpoint)}/v1/`)], + // `traceparent` goes to same-origin requests only, unless the app lists + // the cross-origin APIs that accept it. + propagateTraceHeaderCorsUrls: [...config.propagateTraceHeaderCorsUrls], + applyCustomAttributesOnSpan: noteSettled, + } + const instrumentations = [ + ...(config.tracingInstrumentFetch ? [new FetchInstrumentation(requestOptions)] : []), + ...(config.tracingInstrumentXhr ? [new XMLHttpRequestInstrumentation(requestOptions)] : []), + ] + const unregisterInstrumentations = + instrumentations.length > 0 + ? registerInstrumentations({ + // Explicit, not the global: a host app that registered its own provider + // first owns the global, and these spans would otherwise go to it. + tracerProvider: provider, + instrumentations, + }) + : undefined return async () => { if (canListen) {