diff --git a/docs/browser-sdk.md b/docs/browser-sdk.md index cad2d9f599..3e0829a865 100644 --- a/docs/browser-sdk.md +++ b/docs/browser-sdk.md @@ -63,6 +63,8 @@ Every field accepted by `MapleBrowser.init`: | `errors` | `ErrorFilterOptions` | see [Filtering errors](#filtering-errors) | Drop captured errors by message, script URL, or a `beforeCapture` hook. | | `replay.enabled` | `boolean` | `true` | Enable rrweb session recording. | | `replay.sampleRate` | `number` | `1` | Fraction of sessions to record, `0` to `1`. Out-of-range values are clamped with a warning. See [Sampling](#sampling). | +| `tracing.longFrames` | `boolean` | `false` | Span main-thread frames of 100ms or more. See [Jank](#jank). | +| `tracing.slowInteractions` | `boolean` | `false` | Span interactions of 200ms or more. See [Jank](#jank). | | `tracing.captureHeaders` | `{ request?, response? }` | none | Header names recorded on `fetch`/XHR spans as `http.request.header.` / `http.response.header.`. See [Request and response detail](#request-and-response-detail). | | `replay.canvasFps` | `number` | off | Record `` content at this many frames per second. | | `replay.networkBodies` | `{ urls, maxLength? }` | none | Keep text request/response bodies of these URLs on replay network events. | @@ -498,6 +500,26 @@ Sampled traces carry the W3C `tracestate` threshold (`ot=th:…`), so Maple weig inverse of the rate and request counts stay realistic. A trace joined from a server-rendered `traceparent` follows the server's decision instead. +## Jank + +Two opt-in span sources show where the main thread got stuck: + +```ts +tracing: { longFrames: true, slowInteractions: true } +``` + +- `longFrames` spans every frame of 100ms or more as `longAnimationFrame`, with the script that ran + longest as `code.file.path` / `code.function.name`, its `maple.browser.script.invoker` (e.g. + `BUTTON#save.onclick`) and `maple.browser.script.duration_ms`, plus + `maple.browser.frame.blocking_duration_ms`. Browsers without the Long Animation Frames API report + `longtask` spans instead, without script attribution. +- `slowInteractions` spans every interaction of 200ms or more (INP's "needs improvement" line) as + `interaction `, named after the event whose handlers ran longest, with + `maple.browser.interaction.input_delay_ms`, `processing_ms`, `presentation_ms` and `target`. + +Both nest under the open navigation span when there is one, include what happened before the SDK +finished loading, and follow `tracing.sampleRate`. + ## Request and response detail Headers go on the spans, as the HTTP semantic conventions define them. List the ones you want: diff --git a/packages/browser-session/src/capture/interactions.ts b/packages/browser-session/src/capture/interactions.ts index 33265195de..97785d0845 100644 --- a/packages/browser-session/src/capture/interactions.ts +++ b/packages/browser-session/src/capture/interactions.ts @@ -38,7 +38,7 @@ export function installInteractionCapture(emit: Emit, maskAllText: boolean): () } /** A short, human-readable selector: tag + #id + .first-class. */ -function selectorOf(el: Element): string { +export function selectorOf(el: Element): string { const tag = el.tagName.toLowerCase() const id = el.id ? `#${el.id}` : "" const cls = diff --git a/packages/browser-session/src/index.ts b/packages/browser-session/src/index.ts index ed5c7beeaf..f94fbcc4b4 100644 --- a/packages/browser-session/src/index.ts +++ b/packages/browser-session/src/index.ts @@ -57,3 +57,4 @@ export { warnIfKeylessMapleIngest, } from "./platform/region" export { redactUrl, scrubUrl } from "./platform/url-privacy" +export { selectorOf } from "./capture/interactions" diff --git a/packages/browser/scripts/size.ts b/packages/browser/scripts/size.ts index b5dcbec7fa..cfbdad2608 100644 --- a/packages/browser/scripts/size.ts +++ b/packages/browser/scripts/size.ts @@ -34,10 +34,11 @@ const BUDGET = { */ eager: 44, /** - * Every page load, after `init()`: the OTel logs SDK and exporter, document - * timing, and `web-vitals` (~3.3 kB, 8 -> 12). + * Every page load, after `init()`, off the critical path: the OTel logs SDK + * and exporter, document timing, `web-vitals` (~3.3 kB), breadcrumbs, + * reports, the offline queue and long-frame/interaction spans. */ - deferred: 12, + deferred: 14, lazy: 68, /** * Our own eager code, with OpenTelemetry and rrweb left external. diff --git a/packages/browser/src/config.ts b/packages/browser/src/config.ts index 9ca8c820bb..efc96152e1 100644 --- a/packages/browser/src/config.ts +++ b/packages/browser/src/config.ts @@ -95,6 +95,13 @@ export interface MapleBrowserConfig { readonly request?: ReadonlyArray readonly response?: ReadonlyArray } + /** + * Span main-thread frames of 100ms or more (`longAnimationFrame`, with the + * script that ran longest; `longtask` where that API is missing). Default false. + */ + readonly longFrames?: boolean + /** Span interactions of 200ms or more (`interaction click`, ...), split into input delay, processing and presentation. Default false. */ + readonly slowInteractions?: boolean } /** * Report Core Web Vitals (LCP, CLS, INP, FCP, TTFB) as `browser.web_vital` @@ -228,6 +235,8 @@ export interface ResolvedConfig { | { readonly urls: ReadonlyArray; readonly maxLength: number } | undefined readonly captureHeaders: HeaderCapture + readonly longFrames: boolean + readonly slowInteractions: boolean readonly maskAllInputs: boolean readonly maskAllText: boolean readonly persistVisitorId: boolean @@ -310,6 +319,8 @@ export function resolveConfig(config: MapleBrowserConfig): ResolvedConfig { } : undefined, captureHeaders: resolveHeaderCapture(config.tracing?.captureHeaders), + longFrames: config.tracing?.longFrames ?? false, + slowInteractions: config.tracing?.slowInteractions ?? false, replayOnErrorSampleRate: config.replay?.onErrorSampleRate === undefined ? 0 diff --git a/packages/browser/src/deferred/index.ts b/packages/browser/src/deferred/index.ts index 7d04b2d78e..fd8d6918f3 100644 --- a/packages/browser/src/deferred/index.ts +++ b/packages/browser/src/deferred/index.ts @@ -9,6 +9,7 @@ import { flushBreadcrumbs, startBreadcrumbs } from "./breadcrumbs" import { recordDocumentTiming } from "./document-timing" import { startLogs } from "./logs" import { startOfflineQueue } from "./offline" +import { startPerf } from "./perf" import { startReports } from "./reports" import { startWebVitals } from "./web-vitals" @@ -26,6 +27,7 @@ export function startDeferred(config: ResolvedConfig): () => Promise { }) const stopErrorListener = onErrorRecorded(flushBreadcrumbs) const stopReports = startReports({ csp: config.reportCsp, browserReports: config.reportBrowser }) + const stopPerf = startPerf({ longFrames: config.longFrames, slowInteractions: config.slowInteractions }) const offline = config.offlineQueue ? startOfflineQueue(config) : undefined attachSpanStash(offline?.stashSpans) const stops = [ @@ -38,6 +40,7 @@ export function startDeferred(config: ResolvedConfig): () => Promise { stopReports() attachSpanStash(undefined) offline?.stop() + stopPerf() }, ] return async () => { diff --git a/packages/browser/src/deferred/perf.browser.test.ts b/packages/browser/src/deferred/perf.browser.test.ts new file mode 100644 index 0000000000..416056e8ff --- /dev/null +++ b/packages/browser/src/deferred/perf.browser.test.ts @@ -0,0 +1,155 @@ +// TEST-SEAM: This focused test replaces process-global modules that have no instance-level injection seam. +import type { ReadableSpan } from "@opentelemetry/sdk-trace-base" +import { userEvent } from "vitest/browser" +import { afterEach, describe, expect, it, vi } from "vitest" + +const exported: ReadableSpan[] = [] +vi.mock("@opentelemetry/exporter-trace-otlp-http", () => ({ + OTLPTraceExporter: class { + export(spans: ReadableSpan[], callback: (result: { code: number }) => void): void { + exported.push(...spans) + callback({ code: 0 }) + } + forceFlush(): Promise { + return Promise.resolve() + } + shutdown(): Promise { + return Promise.resolve() + } + }, +})) + +const { MapleBrowser } = await import("../index") +const { onLongFrame } = await import("./perf") + +class ScriptTimingStub { + constructor( + private readonly values: { + duration: number + invoker: string + sourceURL: string + sourceFunctionName: string + }, + ) {} + get duration(): number { + return this.values.duration + } + get invoker(): string { + return this.values.invoker + } + get sourceURL(): string { + return this.values.sourceURL + } + get sourceFunctionName(): string { + return this.values.sourceFunctionName + } +} +const scriptTiming = (duration: number, invoker: string, sourceURL: string, sourceFunctionName = "") => + new ScriptTimingStub({ duration, invoker, sourceURL, sourceFunctionName }) + +const busy = (ms: number): void => { + const until = performance.now() + ms + while (performance.now() < until) { + // Block the main thread, like a slow handler would. + } +} + +let handle: ReturnType | undefined +afterEach(async () => { + await handle?.shutdown() + handle = undefined + vi.restoreAllMocks() + exported.length = 0 + document.body.replaceChildren() + vi.unstubAllGlobals() +}) + +const init = async (): Promise => { + vi.stubGlobal( + "fetch", + vi.fn(async () => new Response("{}")), + ) + handle = MapleBrowser.init({ + ingestKey: "k", + serviceName: "web", + endpoint: "https://ingest.test", + replay: { enabled: false }, + webVitals: false, + breadcrumbs: false, + tracing: { instrumentFetch: false, instrumentXhr: false, longFrames: true, slowInteractions: true }, + }) + await import("./index") + await new Promise((resolve) => setTimeout(resolve, 0)) +} + +const stop = async (): Promise => { + await handle?.shutdown() + handle = undefined +} + +describe("slow interactions", () => { + it("spans a slow click once, named after the event whose handler ran long", async () => { + await init() + const button = document.createElement("button") + button.id = "save" + button.textContent = "Save" + button.addEventListener("click", () => busy(250)) + document.body.append(button) + await userEvent.click(button) + // Event timing entries are delivered after the next paint. + await new Promise((resolve) => setTimeout(resolve, 500)) + await stop() + + const interactions = exported.filter((span) => span.name.startsWith("interaction ")) + expect(interactions.map((span) => span.name)).toEqual(["interaction click"]) + expect(interactions[0]?.attributes["maple.browser.interaction.target"]).toBe("button#save") + expect( + Number(interactions[0]?.attributes["maple.browser.interaction.processing_ms"]), + ).toBeGreaterThanOrEqual(200) + }) +}) + +describe("long frames", () => { + it("falls back to long tasks where Long Animation Frames are missing", async () => { + const supported = PerformanceObserver.supportedEntryTypes.filter( + (type) => type !== "long-animation-frame", + ) + vi.spyOn(PerformanceObserver, "supportedEntryTypes", "get").mockReturnValue(supported) + await init() + busy(150) + await new Promise((resolve) => setTimeout(resolve, 300)) + await stop() + expect(exported.map((span) => span.name)).toContain("longtask") + }) + + it("names the longest script of a long animation frame", async () => { + await init() + const entry = { + name: "long-animation-frame", + entryType: "long-animation-frame", + startTime: 100, + duration: 180, + toJSON: () => ({}), + blockingDuration: 130, + // Real PerformanceScriptTiming fields are prototype getters, not own properties. + scripts: [ + scriptTiming(20, "a", "https://app.test/a.js"), + scriptTiming(150, "BUTTON#save.onclick", "https://app.test/checkout.js?token=x", "submit"), + ], + } + onLongFrame(entry) + await stop() + // Buffered real frames (from earlier busy loops) may be reported too; find this one. + const frame = exported.find( + (span) => + span.name === "longAnimationFrame" && span.attributes["code.function.name"] === "submit", + ) + expect(frame?.attributes).toMatchObject({ + "maple.browser.frame.blocking_duration_ms": 130, + "code.file.path": "https://app.test/checkout.js?token=REDACTED", + "code.function.name": "submit", + "maple.browser.script.invoker": "BUTTON#save.onclick", + "maple.browser.script.duration_ms": 150, + }) + }) +}) diff --git a/packages/browser/src/deferred/perf.ts b/packages/browser/src/deferred/perf.ts new file mode 100644 index 0000000000..e473ea657c --- /dev/null +++ b/packages/browser/src/deferred/perf.ts @@ -0,0 +1,166 @@ +// Main-thread jank as spans: long animation frames (with the script that ran +// longest) and slow interactions (split into input delay, processing and +// presentation). Opt-in; nested under the open navigation when there is one. +import { hasConsent, scrubUrl, selectorOf } from "@maple/browser-session" +import { context, trace } from "@opentelemetry/api" +import { openNavigationSpan } from "../navigation" +import { liveMapleTracer } from "../tracing" +import { SDK_NAME, SDK_VERSION } from "../version" + +/** A frame this long is visible jank; the Long Animation Frames API reports from 50ms. */ +const LONG_FRAME_MS = 100 +/** INP's "needs improvement" line. */ +const SLOW_INTERACTION_MS = 200 + +export interface PerfOptions { + readonly longFrames: boolean + readonly slowInteractions: boolean +} + +interface ScriptTiming { + readonly duration: number + readonly invoker?: string + readonly sourceURL?: string + readonly sourceFunctionName?: string +} + +const epoch = (offset: number): number => performance.timeOrigin + offset + +function span( + name: string, + start: number, + duration: number, + attributes: Record, +): void { + const tracer = hasConsent() ? liveMapleTracer(SDK_NAME, SDK_VERSION) : undefined + if (!tracer) return + const navigation = openNavigationSpan() + const parent = navigation ? trace.setSpan(context.active(), navigation) : context.active() + tracer.startSpan(name, { startTime: epoch(start), attributes }, parent).end(epoch(start + duration)) +} + +function scriptsOf(entry: PerformanceEntry): ScriptTiming[] { + const scripts: unknown = "scripts" in entry ? entry.scripts : undefined + if (!Array.isArray(scripts)) return [] + return scripts.flatMap((script: unknown): ScriptTiming[] => { + if (typeof script !== "object" || script === null || !("duration" in script)) return [] + if (typeof script.duration !== "number") return [] + // `in` and property reads walk the prototype, where PerformanceScriptTiming keeps these getters. + const invoker: unknown = "invoker" in script ? script.invoker : undefined + const sourceURL: unknown = "sourceURL" in script ? script.sourceURL : undefined + const sourceFunctionName: unknown = + "sourceFunctionName" in script ? script.sourceFunctionName : undefined + return [ + { + duration: script.duration, + invoker: typeof invoker === "string" && invoker !== "" ? invoker : undefined, + sourceURL: typeof sourceURL === "string" && sourceURL !== "" ? sourceURL : undefined, + sourceFunctionName: + typeof sourceFunctionName === "string" && sourceFunctionName !== "" + ? sourceFunctionName + : undefined, + }, + ] + }) +} + +/** Exported for tests: headless Chromium lists LoAF as supported but never renders a frame to report. */ +export function onLongFrame(entry: PerformanceEntry): void { + if (entry.duration < LONG_FRAME_MS) return + const blocking = + "blockingDuration" in entry && typeof entry.blockingDuration === "number" + ? entry.blockingDuration + : undefined + const longest = scriptsOf(entry).sort((a, b) => b.duration - a.duration)[0] + span( + entry.entryType === "longtask" ? "longtask" : "longAnimationFrame", + entry.startTime, + entry.duration, + { + ...(blocking !== undefined + ? { "maple.browser.frame.blocking_duration_ms": Math.round(blocking) } + : undefined), + ...(longest?.sourceURL ? { "code.file.path": scrubUrl(longest.sourceURL) } : undefined), + ...(longest?.sourceFunctionName + ? { "code.function.name": longest.sourceFunctionName } + : undefined), + ...(longest?.invoker ? { "maple.browser.script.invoker": longest.invoker } : undefined), + ...(longest ? { "maple.browser.script.duration_ms": Math.round(longest.duration) } : undefined), + }, + ) +} + +function observe( + type: string, + onEntries: (entries: PerformanceEntryList) => void, + options: Record = {}, +): () => void { + if ( + typeof PerformanceObserver === "undefined" || + !PerformanceObserver.supportedEntryTypes?.includes(type) + ) { + return () => {} + } + const observer = new PerformanceObserver((list) => onEntries(list.getEntries())) + // Buffered: what happened before this chunk loaded is reported too. + observer.observe({ type, buffered: true, ...options }) + return () => observer.disconnect() +} + +const processingOf = (entry: PerformanceEventTiming): number => entry.processingEnd - entry.processingStart + +function spanInteraction(entry: PerformanceEventTiming): void { + span(`interaction ${entry.name}`, entry.startTime, entry.duration, { + "maple.browser.interaction.input_delay_ms": Math.round(entry.processingStart - entry.startTime), + "maple.browser.interaction.processing_ms": Math.round(processingOf(entry)), + "maple.browser.interaction.presentation_ms": Math.round( + entry.startTime + entry.duration - entry.processingEnd, + ), + ...(entry.target instanceof Element + ? { "maple.browser.interaction.target": selectorOf(entry.target) } + : undefined), + }) +} + +export function startPerf(options: PerfOptions): () => void { + const stops: Array<() => void> = [] + if (options.longFrames) { + const hasLoaf = + typeof PerformanceObserver !== "undefined" && + PerformanceObserver.supportedEntryTypes?.includes("long-animation-frame") === true + stops.push( + observe(hasLoaf ? "long-animation-frame" : "longtask", (entries) => { + for (const entry of entries) onLongFrame(entry) + }), + ) + } + if (options.slowInteractions) { + const seen = new Set() + stops.push( + observe( + "event", + (entries) => { + // One interaction fires several events (pointerdown, pointerup, click): span it + // once, named after the event whose handlers ran longest. + const byInteraction = new Map() + for (const entry of entries) { + if (!(entry instanceof PerformanceEventTiming) || entry.interactionId === 0) continue + if (entry.duration < SLOW_INTERACTION_MS || seen.has(entry.interactionId)) continue + const best = byInteraction.get(entry.interactionId) + if (!best || processingOf(entry) > processingOf(best)) + byInteraction.set(entry.interactionId, entry) + } + for (const [id, entry] of byInteraction) { + seen.add(id) + spanInteraction(entry) + } + if (seen.size > 500) seen.clear() + }, + { durationThreshold: SLOW_INTERACTION_MS }, + ), + ) + } + return () => { + for (const stop of stops) stop() + } +} diff --git a/packages/browser/src/navigation.test.ts b/packages/browser/src/navigation.test.ts index d215ad35db..0e2adc7491 100644 --- a/packages/browser/src/navigation.test.ts +++ b/packages/browser/src/navigation.test.ts @@ -39,6 +39,8 @@ const CONFIG = { canvasFps: undefined, networkBodies: undefined, captureHeaders: { request: [], response: [] }, + longFrames: false, + slowInteractions: false, maskAllInputs: true, maskAllText: false, persistVisitorId: true, diff --git a/packages/browser/src/navigation.ts b/packages/browser/src/navigation.ts index b3887967ef..7ed3dafcf5 100644 --- a/packages/browser/src/navigation.ts +++ b/packages/browser/src/navigation.ts @@ -70,6 +70,11 @@ const tracedSpans = new WeakSet() */ const tracer = () => (hasConsent() ? liveMapleTracer(SDK_NAME, SDK_VERSION) : undefined) +/** The navigation span in flight, for work that should nest under it. */ +export function openNavigationSpan(): Span | undefined { + return navigation?.span +} + /** End the open navigation as interrupted: something other than its route finishing ended it. */ function interruptNavigation(): void { navigation?.span.setAttribute("app.navigation.interrupted", true) diff --git a/packages/browser/src/tracing.browser.test.ts b/packages/browser/src/tracing.browser.test.ts index cb57677ffa..f18b84c98a 100644 --- a/packages/browser/src/tracing.browser.test.ts +++ b/packages/browser/src/tracing.browser.test.ts @@ -48,6 +48,8 @@ const CONFIG = { canvasFps: undefined, networkBodies: undefined, captureHeaders: { request: [], response: [] }, + longFrames: false, + slowInteractions: false, maskAllInputs: true, maskAllText: false, persistVisitorId: true,