From c85e39b182f2aa9cb4360221cd22a4257c2afa36 Mon Sep 17 00:00:00 2001 From: Bryan English Date: Tue, 3 Nov 2026 14:02:57 -0500 Subject: [PATCH] perf: skip export-only work on unsampled spans Previously, a request whose trace was not sampled still got a full span: attributes, wall-clock and monotonic timestamps, response listeners, and status and exception recording. None of it could be exported, since Span.end() buffers only sampled spans, so all of it was wasted work that only propagation and parenting actually needed. Now the handlers check the span once, right after it is created, and skip everything from there that only serves the export: the attribute work (URL parsing, header reads, setAttribute calls) for HTTP/1 servers and clients, HTTP/2 servers, and undici, the timestamps in the Span constructor and end(), and the response 'close' and 'end' listeners, the stashed span, status, exception events, and error handling that records onto the span. What propagation needs stays: trace and span IDs, trace flags, tracestate and baggage, removing a stale tracestate from outgoing requests, making the span current for the request handler, and the self-trace suppression. A sampled span exports the same fields as before, though it now reads its start time just after its trace context is set up rather than just before. An unsampled traced request now costs about a third less of microtel's own time, for HTTP and fetch alike, in CPU profiles of 50k requests. Sampled requests are unchanged. Signed-off-by: Bryan English --- README.md | 10 +- benchmark/fetch-unsampled.bench.js | 8 ++ benchmark/helpers/http.js | 23 +++-- benchmark/http-unsampled.bench.js | 8 ++ lib/instrumentations.js | 117 ++++++++++++++--------- lib/span.js | 35 +++++-- test/fixtures/unsampled-child.js | 144 +++++++++++++++++++++++++++++ test/test-http2.js | 58 +++++++++--- test/test-sampling.js | 98 ++++++++++++++++++++ 9 files changed, 428 insertions(+), 73 deletions(-) create mode 100644 benchmark/fetch-unsampled.bench.js create mode 100644 benchmark/http-unsampled.bench.js create mode 100644 test/fixtures/unsampled-child.js diff --git a/README.md b/README.md index d12f6cd..eadc52b 100644 --- a/README.md +++ b/README.md @@ -276,6 +276,12 @@ Services that use the same rule agree with each other: a trace kept at one ratio is kept at any higher ratio. A `sampleRatio` of `0` starts no sampled traces, so only requests that arrive sampled are traced. +A span whose trace is not sampled is never exported, so it records none of +what only the export would read: no attributes, no timestamps, no response +listeners. Trace and span IDs, trace flags, tracestate, and baggage are kept, +the span is still the parent of the spans made while handling the request, +and its context is still injected into outgoing requests. + When `sampleRatio` is below `1`, a sampled root span starts its trace with the `tracestate` entry `ot=th:`. It tells samplers and backends downstream the probability the trace was kept with. Traces this process starts @@ -302,7 +308,9 @@ The traced and untraced HTTP and fetch configurations live in separate files: the runner executes each file in its own child process, and tracing activates at most once per process. The traced runs export to a local dummy collector in the same process, so the measurement includes the export work -done while the requests run. +done while the requests run. An unsampled traced configuration, with +`sampleRatio: 0`, is measured too: its requests propagate context but never +export, so the comparison tracks what that costs. Smaller benchmarks time pieces of that work on their own: building client and server spans, generating IDs into a `traceparent` value, and exporting diff --git a/benchmark/fetch-unsampled.bench.js b/benchmark/fetch-unsampled.bench.js new file mode 100644 index 0000000..3e0cd3b --- /dev/null +++ b/benchmark/fetch-unsampled.bench.js @@ -0,0 +1,8 @@ +'use strict'; + +const { registerFetchBenchmark } = require('./helpers/http'); + +registerFetchBenchmark('fetch request (traced, unsampled)', { + tracing: true, + sampleRatio: 0, +}); diff --git a/benchmark/helpers/http.js b/benchmark/helpers/http.js index ec21d5b..c5cfdb4 100644 --- a/benchmark/helpers/http.js +++ b/benchmark/helpers/http.js @@ -14,8 +14,10 @@ const listen = (server) => const close = (server) => new Promise((resolve) => server.close(resolve)); // Starts, when tracing, a dummy collector: the measurement then covers -// span creation, serialization, and the export round trip. -async function startCollector({ tracing }) { +// span creation, serialization, and the export round trip. A sampleRatio +// of 0 traces requests without exporting anything, so it measures the +// work a request that only propagates its context pays for. +async function startCollector({ tracing, sampleRatio }) { if (!tracing) return null; const collector = http.createServer((req, res) => { @@ -23,7 +25,10 @@ async function startCollector({ tracing }) { res.end(); }); await listen(collector); - microtel.init({ endpoint: `http://127.0.0.1:${collector.address().port}` }); + microtel.init({ + endpoint: `http://127.0.0.1:${collector.address().port}`, + sampleRatio, + }); return collector; } @@ -38,8 +43,8 @@ async function startTargetServer() { // Sets up a local target server, a keep-alive agent for the load, and, // when tracing, a dummy collector. -async function setup({ tracing = false } = {}) { - const collector = await startCollector({ tracing }); +async function setup({ tracing = false, sampleRatio } = {}) { + const collector = await startCollector({ tracing, sampleRatio }); const server = await startTargetServer(); const port = server.address().port; @@ -69,13 +74,13 @@ async function setup({ tracing = false } = {}) { // keep-alive connection, so the traced/untraced difference reflects // per-request work (two spans per request), not scheduling or connection // noise. -function registerHttpBenchmark(name, { tracing = false } = {}) { +function registerHttpBenchmark(name, { tracing = false, sampleRatio } = {}) { const kRequestsPerSample = 200; let ctx; before(async () => { - ctx = await setup({ tracing }); + ctx = await setup({ tracing, sampleRatio }); }); after(() => ctx.close()); @@ -93,7 +98,7 @@ function registerHttpBenchmark(name, { tracing = false } = {}) { // Requests are sequential over the pooled connection, so the // traced/untraced difference reflects per-request work (two spans per // request), not scheduling or connection noise. -function registerFetchBenchmark(name, { tracing = false } = {}) { +function registerFetchBenchmark(name, { tracing = false, sampleRatio } = {}) { const kRequestsPerSample = 200; let server; @@ -101,7 +106,7 @@ function registerFetchBenchmark(name, { tracing = false } = {}) { let url; before(async () => { - collector = await startCollector({ tracing }); + collector = await startCollector({ tracing, sampleRatio }); server = await startTargetServer(); url = `http://127.0.0.1:${server.address().port}/bench`; }); diff --git a/benchmark/http-unsampled.bench.js b/benchmark/http-unsampled.bench.js new file mode 100644 index 0000000..7fc40dd --- /dev/null +++ b/benchmark/http-unsampled.bench.js @@ -0,0 +1,8 @@ +'use strict'; + +const { registerHttpBenchmark } = require('./helpers/http'); + +registerHttpBenchmark('http request (traced, unsampled)', { + tracing: true, + sampleRatio: 0, +}); diff --git a/lib/instrumentations.js b/lib/instrumentations.js index c08bf9f..4f2724e 100644 --- a/lib/instrumentations.js +++ b/lib/instrumentations.js @@ -220,9 +220,6 @@ function onHttpServerRequestStart({ request, response, socket }) { const baggage = request.headers.baggage; const method = request.method || 'GET'; - const rawUrl = request.url || '/'; - const qIdx = rawUrl.indexOf('?'); - const path = qIdx === -1 ? rawUrl : rawUrl.slice(0, qIdx); // Per the OTel semantic conventions span names must be low cardinality. // Core has no route concept, so only the method is used; the path lives // in an attribute. @@ -234,6 +231,20 @@ function onHttpServerRequestStart({ request, response, socket }) { baggage, }); + // The span deliberately stays in the AsyncLocalStorage after the request + // ends, so work started while handling it still links to the server + // span as its parent. + spanStorage.enterWith(span); + + // Everything from here on serves only the export, which an unsampled + // span never reaches: the attributes, the stash the response handlers + // read, and the listener that ends the span at the right moment. + if (!span.isSampled) return; + + const rawUrl = request.url || '/'; + const qIdx = rawUrl.indexOf('?'); + const path = qIdx === -1 ? rawUrl : rawUrl.slice(0, qIdx); + span.setAttribute('http.request.method', method); span.setAttribute('url.path', path); if (qIdx !== -1) span.setAttribute('url.query', rawUrl.slice(qIdx + 1)); @@ -254,11 +265,6 @@ function onHttpServerRequestStart({ request, response, socket }) { // need a second AsyncLocalStorage lookup. response[kSpan] = span; - // The span deliberately stays in the AsyncLocalStorage after the request - // ends, so work started while handling it still links to the server - // span as its parent. - spanStorage.enterWith(span); - // Response 'close' without 'finish' means the connection was terminated // before the response completed. Request 'close' cannot be used for // this: it also fires when the request stream is merely consumed, which @@ -348,21 +354,25 @@ function onHttpClientRequestCreated({ request }) { const method = request.method || 'GET'; const span = new Span(method, SPAN_KIND_CLIENT, { parent }); - span.setAttribute('http.request.method', method); + // The attributes and the stash the response and error handlers read + // serve only the export, which an unsampled span never reaches. + if (span.isSampled) { + span.setAttribute('http.request.method', method); - const [hostPart, portPart] = splitAuthority(authority); - span.setAttribute('server.address', host || hostPart); - // A missing port means the scheme's default. - if (portPart == null) { - span.setAttribute('server.port', protocol === 'https:' ? 443 : 80); - } else { - const port = parsePort(portPart); - if (port !== undefined) span.setAttribute('server.port', port); - } + const [hostPart, portPart] = splitAuthority(authority); + span.setAttribute('server.address', host || hostPart); + // A missing port means the scheme's default. + if (portPart == null) { + span.setAttribute('server.port', protocol === 'https:' ? 443 : 80); + } else { + const port = parsePort(portPart); + if (port !== undefined) span.setAttribute('server.port', port); + } - span.setAttribute('url.full', `${protocol}//${authority}${path}`); + span.setAttribute('url.full', `${protocol}//${authority}${path}`); - request[kSpan] = span; + request[kSpan] = span; + } // Node stores the headers inside the ClientRequest constructor when they // are given as an array or include Expect, so setHeader would throw @@ -431,9 +441,6 @@ function onHttp2ServerStreamStart({ stream, headers }) { const tracestate = parent != null ? headers?.tracestate : undefined; const method = headers?.[':method'] || 'GET'; - const rawUrl = headers?.[':path'] || '/'; - const qIdx = rawUrl.indexOf('?'); - const path = qIdx === -1 ? rawUrl : rawUrl.slice(0, qIdx); const span = new Span(method, SPAN_KIND_SERVER, { parent, @@ -445,16 +452,34 @@ function onHttp2ServerStreamStart({ stream, headers }) { baggage: headers.baggage, }); + // A stream whose session is already gone was destroyed by an earlier + // subscriber, before this channel fired. No handler code will run for + // it, so it is not made current in either sampling mode. An unsampled + // span is dropped here, since it is never exported. + const session = stream.session; + if (session === undefined && !span.isSampled) return; + + // Everything from here on serves only the export, which an unsampled + // span never reaches: the attributes and the stash the stream handlers + // read. The span is still made current, so work started while handling + // the request links to it as its parent. + if (!span.isSampled) { + spanStorage.enterWith(span); + return; + } + + const rawUrl = headers?.[':path'] || '/'; + const qIdx = rawUrl.indexOf('?'); + const path = qIdx === -1 ? rawUrl : rawUrl.slice(0, qIdx); + span.setAttribute('http.request.method', method); span.setAttribute('url.path', path); if (qIdx !== -1) span.setAttribute('url.query', rawUrl.slice(qIdx + 1)); // The :scheme pseudo-header carries the request scheme; requests that // omit it fall back to the session's encryption state, like the - // socket check for HTTP/1.1. Another subscriber to the stream's - // created channel can destroy the stream before this channel fires, - // which clears the session, so it may be gone here. - const session = stream.session; + // socket check for HTTP/1.1. The session is gone for a stream + // destroyed before this channel fires, so it may be missing here. const scheme = headers?.[':scheme'] || (session?.encrypted ? 'https' : 'http'); span.setAttribute('url.scheme', scheme); @@ -585,25 +610,29 @@ function onUndiciRequestCreate({ request }) { const method = request.method || 'GET'; const span = new Span(method, SPAN_KIND_CLIENT, { parent }); - span.setAttribute('http.request.method', method); - - const { origin } = request; - const path = request.path; - if (origin) { - if (origin !== lastOrigin) { - // The origin omits the port when it is the scheme default. - const parsed = new URL(origin); - lastOriginAddress = parsed.hostname; - lastOriginPort = - Number(parsed.port) || (parsed.protocol === 'https:' ? 443 : 80); - lastOrigin = origin; + // The attributes and the stash the response handlers read serve only + // the export, which an unsampled span never reaches. + if (span.isSampled) { + span.setAttribute('http.request.method', method); + + const { origin } = request; + const path = request.path; + if (origin) { + if (origin !== lastOrigin) { + // The origin omits the port when it is the scheme default. + const parsed = new URL(origin); + lastOriginAddress = parsed.hostname; + lastOriginPort = + Number(parsed.port) || (parsed.protocol === 'https:' ? 443 : 80); + lastOrigin = origin; + } + span.setAttribute('server.address', lastOriginAddress); + span.setAttribute('server.port', lastOriginPort); } - span.setAttribute('server.address', lastOriginAddress); - span.setAttribute('server.port', lastOriginPort); - } - span.setAttribute('url.full', `${origin}${path}`); + span.setAttribute('url.full', `${origin}${path}`); - request[kSpan] = span; + request[kSpan] = span; + } if (request.addHeader) { setUndiciHeader(request, 'traceparent', span.toTraceparent()); diff --git a/lib/span.js b/lib/span.js index 49d9723..e45b3a8 100644 --- a/lib/span.js +++ b/lib/span.js @@ -103,7 +103,9 @@ class Span { // clock; the end is derived as start + a monotonic duration, so spans // survive a backward clock step while keeping human-readable absolute // timestamps. Conversion to OTLP nanoseconds happens only at export, so - // unsampled or filtered spans never pay for it. + // unsampled or filtered spans never pay for it. An unsampled span is + // never exported, so it is never given timestamps: its endTime only + // marks that it has ended. startTime; endTime; #startMonotonic; @@ -126,11 +128,8 @@ class Span { this.name = name; this.kind = kind; this.spanId = generateSpanId(); - this.#attributes = new SpanAttributes(); this.#events = kNoEvents; this.#status = kUnsetStatus; - this.startTime = Date.now(); - this.#startMonotonic = performance.now(); let rootTracestate; if (parent != null) { @@ -159,17 +158,31 @@ class Span { // Baggage follows the same inheritance: an explicit inbound value // wins, children inherit their parent's. this.baggage = options?.baggage ?? parent?.baggage; + + // Attributes and timestamps serve only the export, so an unsampled + // span is given neither. + if (this.#traceFlags & kTraceFlagSampled) { + this.#attributes = new SpanAttributes(); + this.startTime = Date.now(); + this.#startMonotonic = performance.now(); + } } get traceFlags() { return this.#traceFlags; } + get isSampled() { + return (this.#traceFlags & kTraceFlagSampled) !== 0; + } + get hasRemoteParent() { return this.#remoteParent; } setAttribute(key, value) { + // An unsampled span has no attributes to record into. + if (this.#attributes === undefined) return this; const writes = this.#attributeLimit; if (typeof writes === 'number' && writes < kAttributeCountLimit) { this.#attributeLimit = writes + 1; @@ -220,6 +233,8 @@ class Span { // Only the internal exception producer uses events today; cap them // once addEvent becomes part of a public API. // TODO(bengl): cap the number of events per span then. + // An unsampled span is never exported, so its events are dropped. + if (this.#attributes === undefined) return this; if (this.#events === kNoEvents) this.#events = []; this.#events.push({ name, @@ -245,10 +260,16 @@ class Span { end() { if (this.endTime !== undefined) return; - this.endTime = this.startTime + (performance.now() - this.#startMonotonic); - // Only export sampled spans. - if (this.#traceFlags & kTraceFlagSampled) addSpan(this); + if (this.#traceFlags & kTraceFlagSampled) { + this.endTime = + this.startTime + (performance.now() - this.#startMonotonic); + addSpan(this); + } else { + // An unsampled span reads no clock on the way out, it is only + // marked ended. + this.endTime = 0; + } } // Produces the outgoing header value; the caller writes it into the diff --git a/test/fixtures/unsampled-child.js b/test/fixtures/unsampled-child.js new file mode 100644 index 0000000..81836c9 --- /dev/null +++ b/test/fixtures/unsampled-child.js @@ -0,0 +1,144 @@ +'use strict'; + +// Spawned with JSON init options as argv[2]: activates tracing at a +// sampleRatio of 0, then drives one sampled and one unsampled request +// through an HTTP frontend, an unsampled fetch, and an unsampled HTTP/2 +// stream. The inbound requests go over raw sockets and an HTTP/2 session, +// so the incoming trace flags are under the test's control. Prints what +// each backend hop saw, and the listener counts around the frontend's +// responses, as one JSON line. + +const dc = require('node:diagnostics_channel'); +const http = require('node:http'); +const http2 = require('node:http2'); +const net = require('node:net'); + +const { init, flush } = require(process.env.MICROTEL_PATH); +const { kSpan } = require(`${process.env.MICROTEL_PATH}/lib/span`); + +init(JSON.parse(process.argv[2])); + +// Subscribed after init(), so these run after microtel's handlers and see +// whether they stashed a span for the export-only handlers to find. +const stashed = {}; +dc.subscribe('http2.server.stream.start', ({ stream, headers }) => { + stashed[headers[':path']] = stream[kSpan] !== undefined; +}); +dc.subscribe('undici:request:create', ({ request }) => { + stashed[request.path] = request[kSpan] !== undefined; +}); + +const listen = (server) => + new Promise((resolve) => server.listen(0, '127.0.0.1', resolve)); + +// What each backend hop received, keyed by request path. +const saw = {}; +// Listener counts on the frontend's responses, keyed by request path. +// Plain node leaves no 'close' listener on a server response and no +// 'end' or 'close' listener on a client response, so microtel's own +// listeners are the whole difference. +const listeners = {}; + +let backendPort; + +const backend = http.createServer((req, res) => { + saw[req.url] = { + traceparent: req.headers.traceparent, + tracestate: req.headers.tracestate, + baggage: req.headers.baggage, + }; + res.end('ok'); +}); + +// The frontend records its listener counts, then forwards to the backend +// carrying stale propagation headers that the span's own context, or its +// absence, must replace. +const frontend = http.createServer((req, res) => { + listeners[req.url] = { serverClose: res.listenerCount('close') }; + http.get( + `http://127.0.0.1:${backendPort}${req.url}`, + { headers: { tracestate: 'stale=yes', baggage: 'stale=yes' } }, + (clientRes) => { + listeners[req.url].clientEnd = clientRes.listenerCount('end'); + listeners[req.url].clientClose = clientRes.listenerCount('close'); + clientRes.resume(); + clientRes.on('end', () => res.end('ok')); + }, + ); +}); + +// The HTTP/2 span is current while its stream is handled, so the request +// it makes carries the incoming trace ID. +const h2Frontend = http2.createServer(); +h2Frontend.on('stream', (stream) => { + http.get(`http://127.0.0.1:${backendPort}/h2-hop`, (res) => { + res.resume(); + res.on('end', () => { + stream.respond({ ':status': 200 }); + stream.end('ok'); + }); + }); +}); + +function rawRequest(port, path, headers) { + const lines = Object.entries(headers).map( + ([name, value]) => `${name}: ${value}`, + ); + return new Promise((resolve) => { + const socket = net.connect(port, '127.0.0.1', () => { + socket.write( + `GET ${path} HTTP/1.1\r\n` + + `Host: 127.0.0.1:${port}\r\n` + + `${lines.join('\r\n')}\r\n` + + `Connection: close\r\n` + + `\r\n`, + ); + socket.on('data', () => {}); + socket.on('end', resolve); + }); + }); +} + +async function main() { + await listen(backend); + backendPort = backend.address().port; + await listen(frontend); + await listen(h2Frontend); + + const frontendPort = frontend.address().port; + await rawRequest(frontendPort, '/sampled', { + traceparent: `00-${'7'.repeat(32)}-0123456789abcdef-01`, + tracestate: 'kept=yes', + baggage: 'kept=yes', + }); + await rawRequest(frontendPort, '/unsampled', { + traceparent: `00-${'2'.repeat(32)}-0123456789abcdef-02`, + tracestate: 'kept=yes', + baggage: 'kept=yes', + }); + + const session = http2.connect( + `http://127.0.0.1:${h2Frontend.address().port}`, + ); + await new Promise((resolve) => { + const stream = session.request({ + ':path': '/h2', + traceparent: `00-${'3'.repeat(32)}-0123456789abcdef-02`, + }); + stream.resume(); + stream.on('end', () => session.close(resolve)); + }); + + await fetch(`http://127.0.0.1:${backendPort}/fetch`, { + headers: { tracestate: 'stale=yes', baggage: 'stale=yes' }, + }).then((res) => res.arrayBuffer()); + + backend.close(); + frontend.close(); + h2Frontend.close(); + http.globalAgent.destroy(); + flush(); + console.log(JSON.stringify({ saw, listeners, stashed })); +} + +main(); diff --git a/test/test-http2.js b/test/test-http2.js index ba3b9c2..e1aad7d 100644 --- a/test/test-http2.js +++ b/test/test-http2.js @@ -13,6 +13,7 @@ const { spanAttrs, closeAll, } = require('./common/otel'); +const { getSpanStorage } = require('../lib/core'); // Starts a plain HTTP/2 server for traced requests. The handler receives // (stream, headers). Exposes port and close(). @@ -434,6 +435,19 @@ describe('otel HTTP/2 server spans', () => { // work must not throw over the missing session. const onCreated = ({ stream }) => stream.destroy(); dc.subscribe('http2.server.stream.created', onCreated); + // Subscribed after init(), so this runs after microtel's start + // handler and sees whether a span was left current. The second + // request arrives unsampled, through a traceparent with its sampled + // flag off. + let currentAfterStart; + let currentAfterUnsampledStart; + const onStart = ({ headers }) => { + if (headers?.[':path'] === '/destroyed') + currentAfterStart = getSpanStorage().getStore(); + if (headers?.[':path'] === '/destroyed-unsampled') + currentAfterUnsampledStart = getSpanStorage().getStore(); + }; + dc.subscribe('http2.server.stream.start', onStart); const warnings = []; const onWarning = (w) => warnings.push(w.name); process.on('warning', onWarning); @@ -442,25 +456,32 @@ describe('otel HTTP/2 server spans', () => { // The handler stays quiet: the stream is destroyed before it runs. const target = await startHTTP2Server(() => {}); try { - await new Promise((resolve) => { - const session = http2.connect(`http://127.0.0.1:${target.port}`); - session.on('error', () => {}); - const stream = session.request({ ':path': '/destroyed' }); - stream.on('error', () => {}); - stream.on('close', () => { - session.close(); - resolve(); + const destroyedGet = (path, headers = {}) => + new Promise((resolve) => { + const session = http2.connect(`http://127.0.0.1:${target.port}`); + session.on('error', () => {}); + const stream = session.request({ ':path': path, ...headers }); + stream.on('error', () => {}); + stream.on('close', () => { + session.close(); + resolve(); + }); + setTimeout(() => { + session.close(); + resolve(); + }, 50); }); - setTimeout(() => { - session.close(); - resolve(); - }, 50); + + await destroyedGet('/destroyed'); + await destroyedGet('/destroyed-unsampled', { + traceparent: `00-${'a'.repeat(32)}-${'1'.repeat(16)}-00`, }); } finally { await target.close(); } } finally { dc.unsubscribe('http2.server.stream.created', onCreated); + dc.unsubscribe('http2.server.stream.start', onStart); process.removeListener('warning', onWarning); } @@ -468,6 +489,19 @@ describe('otel HTTP/2 server spans', () => { !warnings.includes('OTelInstrumentationWarning'), 'The span work must not fail over the missing session', ); + // The ended span must not be left current: no handler runs for the + // destroyed stream, and later subscribers share this context. + assert.strictEqual( + currentAfterStart?.endTime, + undefined, + 'The ended span must not be left current', + ); + // An unsampled destroyed stream leaves no span current either. Its + // span never ended, so the endTime check above could not tell. + assert.ok( + currentAfterUnsampledStart == null, + 'The unsampled destroyed span must not be left current', + ); // The instrumentation still traces the next stream. const next = await startHTTP2Server(); diff --git a/test/test-sampling.js b/test/test-sampling.js index 02cdddb..df6492a 100644 --- a/test/test-sampling.js +++ b/test/test-sampling.js @@ -3,11 +3,13 @@ const assert = require('node:assert'); const http = require('node:http'); const { after, before, describe, it } = require('node:test'); +const { Span, SPAN_KIND_SERVER } = require('../lib/span'); const { startTracing, startOTelCollector, startHTTPServer, flushAndCollect, + getSpans, httpGet, rawRequest, fixture, @@ -145,4 +147,100 @@ describe('otel sampling', () => { await zeroCollector.close(); }); + + it('gives an unsampled span no export state', () => { + const span = new Span('GET', SPAN_KIND_SERVER, { + parent: { + traceId: '1'.repeat(32), + spanId: '2'.repeat(16), + traceFlags: 0, + }, + }); + span.setAttribute('http.request.method', 'GET'); + span.addEvent('exception', { 'exception.message': 'boom' }); + span.end(); + + assert.strictEqual(span.isSampled, false); + assert.strictEqual(span.startTime, undefined); + assert.strictEqual(span.getAttributes(), undefined); + assert.deepStrictEqual(span.getEvents(), []); + assert.strictEqual(span.endTime, 0); + }); + + it('skips export-only work while unsampled requests propagate', async () => { + // A child process, since this file already used its one activation. + // The fixture drives a sampled and an unsampled request through an + // HTTP frontend, an unsampled fetch, and an unsampled HTTP/2 stream, + // and reports what each hop saw. + const zeroCollector = await startOTelCollector(); + const { code, stdout, stderr } = await spawnMicrotel([ + fixture('unsampled-child.js'), + JSON.stringify({ + endpoint: `http://127.0.0.1:${zeroCollector.port}`, + sampleRatio: 0, + }), + ]); + + assert.strictEqual(code, 0, stderr); + try { + const { saw, listeners, stashed } = JSON.parse( + stdout.trim().split('\n').pop(), + ); + + // The HTTP/2 stream and the fetch hold no span for the export-only + // handlers to find. + assert.deepStrictEqual(stashed, { '/h2': false, '/fetch': false }); + + // A sampled request gets microtel's own listeners: one 'close' on + // the server response, one 'end' and one 'close' on the client + // response. An unsampled request gets none, the same counts as a + // process without tracing. + assert.strictEqual(listeners['/sampled'].serverClose, 1); + assert.strictEqual(listeners['/sampled'].clientEnd, 2); + assert.strictEqual(listeners['/sampled'].clientClose, 1); + assert.strictEqual(listeners['/unsampled'].serverClose, 0); + assert.strictEqual(listeners['/unsampled'].clientEnd, 1); + assert.strictEqual(listeners['/unsampled'].clientClose, 0); + + // Context still propagates on the unsampled requests: the outgoing + // traceparent carries the incoming trace ID and flags, and the + // span's inherited tracestate and baggage replace the stale headers + // the caller sent. + assert.match( + saw['/unsampled'].traceparent, + RegExp(`^00-${'2'.repeat(32)}-[0-9a-f]{16}-02$`), + ); + assert.strictEqual(saw['/unsampled'].tracestate, 'kept=yes'); + assert.strictEqual(saw['/unsampled'].baggage, 'kept=yes'); + assert.strictEqual(saw['/sampled'].tracestate, 'kept=yes'); + + // An HTTP/2 stream span is current while its stream is handled, so + // the request it makes carries the stream's trace ID and flags. + assert.match( + saw['/h2-hop'].traceparent, + RegExp(`^00-${'3'.repeat(32)}-[0-9a-f]{16}-02$`), + ); + + // A fetch with no trace context of its own starts a fresh + // unsampled trace, and the stale propagation headers the caller + // sent are removed rather than carried into it. + assert.match( + saw['/fetch'].traceparent, + /^00-[0-9a-f]{32}-[0-9a-f]{16}-02$/, + ); + assert.strictEqual(saw['/fetch'].tracestate, undefined); + assert.strictEqual(saw['/fetch'].baggage, undefined); + + // The child has exited, so any export it started has completed. + // Only the request that arrived sampled exported anything. + const exported = new Set(); + for (const payload of zeroCollector.payloads) + for (const span of getSpans(payload)) exported.add(span.traceId); + assert.deepEqual([...exported], ['7'.repeat(32)]); + } finally { + // Closed even when an assertion fails, so the server does not + // keep the process alive. + await zeroCollector.close(); + } + }); });