From becbf5c36262ea413a2dec2b0c929f30f57b908b Mon Sep 17 00:00:00 2001 From: Bryan English Date: Tue, 27 Oct 2026 16:02:19 -0400 Subject: [PATCH] feat: add HTTP/2 server instrumentation Create a SERVER span for each incoming HTTP/2 request stream, subscribing to the http2.server.stream.start, finish, close, and error diagnostics channels: - start: span creation from the request pseudo-headers (:method, :path, :scheme, :authority) plus inbound traceparent/tracestate parsing with the same W3C semantics as the HTTP/1.1 server handler - finish: response status code from the :status pseudo-header, with error status and error.type for 5xx responses only - close: span end, so the duration covers the full response transfer; streams closed without a completed response (aborted flag set, or the server never responded) end with error status - error: error status for stream errors network.protocol.version is always 2.0. The node:http2/server filter scope is covered by node:http2 through the existing prefix match, like node:http and node:http/server. Outgoing node:http2 requests are not instrumented: Node's http2 client channels publish a detached snapshot of the request headers after they have been serialized for the wire, so there is no seam at which a traceparent could be injected. This is documented in the README. Signed-off-by: Bryan English --- README.md | 48 ++++++- lib/instrumentations.js | 115 ++++++++++++++++ test/test-http2.js | 295 ++++++++++++++++++++++++++++++++++++++++ 3 files changed, 451 insertions(+), 7 deletions(-) create mode 100644 test/test-http2.js diff --git a/README.md b/README.md index e852ffd..da55df0 100644 --- a/README.md +++ b/README.md @@ -47,7 +47,7 @@ started. Invalid options throw. | `serviceName` | string | `unknown_service:node` | Service name in exported resource attributes. The default follows the OpenTelemetry [semantic conventions](https://opentelemetry.io/docs/specs/semconv/general/trace/) for low-cardinality service names. | | `sdkName` | string | `microtel` | `telemetry.sdk.name` resource attribute, and the name of the instrumentation scope on exported spans. | | `sdkVersion` | string | this package's version | `telemetry.sdk.version` resource attribute, and the scope version. | -| `filter` | string | all modules | Comma-separated list of modules to instrument. Supported values: `node:http`, `node:http/client`, `node:http/server`, and `node:undici`. `node:fetch` is an alias for `node:undici`: both cover all undici requests, including `fetch()`, and either one enables them. | +| `filter` | string | all modules | Comma-separated list of modules to instrument. Supported values: `node:http`, `node:http/client`, `node:http/server`, `node:http2`, `node:http2/server`, and `node:undici`. `node:http` covers `node:http/client` and `node:http/server`; `node:http2` covers `node:http2/server`. `node:fetch` is an alias for `node:undici`: both cover all undici requests, including `fetch()`, and either one enables them. | | `exclude` | string | none | Comma-separated list of modules to exclude from instrumentation. Same values as `filter`; takes precedence over it. | | `maxBufferSize` | number | `100` | Number of spans buffered before an immediate flush is triggered. Must be a positive integer. | | `flushInterval` | number | `10000` | Milliseconds between periodic flushes. Must be a positive integer. | @@ -93,6 +93,32 @@ Attributes set on server spans: | `http.response.status_code` | Response status code | When response finishes | | `error.type` | HTTP status code as string | On 5xx responses | +### HTTP/2 server + +A span with kind `SERVER` is created for each incoming HTTP/2 request +stream, whether over cleartext (`http2.createServer`) or TLS +(`http2.createSecureServer`). The span starts when the request headers are +received and ends when the stream closes, so its duration covers the full +response transfer. Incoming `traceparent`/`tracestate` headers are parsed +with the same semantics as for HTTP/1.1 servers. + +If a stream is aborted before the response completes, the span ends with an +error status. Server spans receive error status (`STATUS_ERROR`) for 5xx +response codes; 4xx responses are not server errors. + +Attributes set on HTTP/2 server spans: + +| Attribute | Description | Condition | +| --------------------------- | -------------------------------- | ----------------------------- | +| `http.request.method` | HTTP method (e.g. `GET`, `POST`) | Always | +| `url.path` | Request URL path (without query) | Always | +| `url.query` | Query string (without `?`) | When query string is present | +| `url.scheme` | `http` or `https` | Always | +| `server.address` | `:authority` pseudo-header value | When present | +| `network.protocol.version` | `2.0` | Always | +| `http.response.status_code` | Response status code | When the response is sent | +| `error.type` | HTTP status code as string | On 5xx responses | + ### HTTP client A span with kind `CLIENT` is created for each outgoing HTTP request made via @@ -149,14 +175,15 @@ scheme default (`80` for `http:`, `443` for `https:`) when the origin omits it. Tracing automatically propagates [W3C Trace Context](https://www.w3.org/TR/trace-context/) across HTTP boundaries: * **Incoming requests**: The `traceparent` header is read from incoming HTTP -requests, and child spans created during request processing inherit the trace -ID. `traceparent` values using a version other than `00` are rejected, and a -fresh trace is started instead. The `tracestate` header, when present, is -attached to the span and forwarded verbatim to outgoing requests. It is never -parsed or modified. +and HTTP/2 requests, and child spans created during request processing +inherit the trace ID. `traceparent` values using a version other than `00` are +rejected, and a fresh trace is started instead. The `tracestate` header, when +present, is attached to the span and forwarded verbatim to outgoing requests. +It is never parsed or modified. * **Outgoing requests**: The `traceparent` header is injected into outgoing HTTP and undici/fetch requests, together with the stored `tracestate` when -one is present, enabling distributed tracing across services. +one is present, enabling distributed tracing across services. Outgoing +`node:http2` requests receive no injection; see the limitations below. ## Benchmarks @@ -185,6 +212,13 @@ package or a userland OpenTelemetry SDK, not both. `init()` activates tracing in the thread that calls it. Worker threads (`node:worker_threads`) are not traced unless they call `init()` themselves. +Outgoing requests made through `node:http2` are not traced, on either the +span or the propagation side. Node's HTTP/2 client diagnostics channels +publish a detached snapshot of the request headers after they have already +been serialized for the wire, so there is no seam at which the +instrumentation could inject a `traceparent` or remove a stale `tracestate`. +Inbound HTTP/2 context is fully parsed; only the client side is affected. + Buffered spans are exported periodically, when the buffer fills, and when the event loop is about to drain. Spans that are still buffered when `process.exit()` is called explicitly are lost, because explicit exits do not run the exit-time diff --git a/lib/instrumentations.js b/lib/instrumentations.js index f10dab1..d92e5ef 100644 --- a/lib/instrumentations.js +++ b/lib/instrumentations.js @@ -211,6 +211,111 @@ function onClientRequestError({ request, error }) { failClientSpan(span, error); } +// HTTP/2 server spans. Only the server channels are instrumented: Node's +// http2 client channels publish a detached snapshot of the request headers +// after they have already been serialized for the wire, so there is no seam +// at which an outgoing traceparent could be injected. + +function onHttp2ServerStreamStart({ stream, headers }) { + // Exports travel over HTTP/1.1, so an export request can never arrive as + // an HTTP/2 stream and the self-trace suppression the http handlers need + // does not apply here. + const traceparent = headers?.traceparent; + const parent = + traceparent != null ? Span.fromTraceparent(traceparent) : undefined; + // Per the W3C Trace Context spec, tracestate is only meaningful + // alongside a valid traceparent. It is discarded when the traceparent + // is absent or rejected, same as for HTTP/1.1 requests. + 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, + // The tracestate is forwarded verbatim; it is never parsed. + tracestate, + }); + + 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. + span.setAttribute( + 'url.scheme', + headers?.[':scheme'] || (stream?.session?.encrypted ? 'https' : 'http'), + ); + span.setAttribute('network.protocol.version', '2.0'); + + const authority = headers?.[':authority']; + if (authority) span.setAttribute('server.address', authority); + + // The span is stashed on the stream so the finish and close handlers do + // not need a second AsyncLocalStorage lookup. + stream[kSpan] = span; + + // The span deliberately stays in the AsyncLocalStorage after the stream + // ends, so work started while handling it still links to the server + // span as its parent. + spanStorage.enterWith(span); +} + +// Fires when the response headers are submitted, so the status code is +// known before the body transfers; the span itself ends when the stream +// closes, keeping the duration over the full transfer. +// stream.respond() accepts headers as either an object or a flat array of +// key/value pairs, and the channel publishes whichever form was used. +function getH2Header(headers, name) { + if (Array.isArray(headers)) return headers[headers.indexOf(name) + 1]; + return headers?.[name]; +} + +function onHttp2ServerStreamFinish({ stream, headers }) { + const span = stream[kSpan]; + if (span == null) return; + + const statusCode = Number(getH2Header(headers, ':status')); + if (!Number.isFinite(statusCode)) return; + + span.setAttribute('http.response.status_code', statusCode); + + if (statusCode >= 500) { + span.setStatus(STATUS_ERROR, `HTTP ${statusCode}`); + span.setAttribute('error.type', `${statusCode}`); + } +} + +function onHttp2ServerStreamClose({ stream }) { + const span = stream[kSpan]; + if (span == null) return; + + // 'close' without a completed response means the stream was terminated + // before the response completed. The server stream is not ended through + // the usual stream API on aborts, so writableEnded cannot distinguish + // them; the aborted flag marks resets, and headersSent is false whenever + // the server never responded at all. + if (span.endTime === undefined && (stream.aborted || !stream.headersSent)) { + span.setStatus(STATUS_ERROR, 'request closed before response'); + } + + span.end(); +} + +function onHttp2ServerStreamError({ stream, error }) { + const span = stream[kSpan]; + if (span == null) return; + + if (span.endTime === undefined) { + span.setStatus(STATUS_ERROR, error?.message || 'stream error'); + span.end(); + } +} + // Undici's addHeader appends rather than replaces; update an existing // header in place so a caller-supplied value is overridden, not // duplicated. @@ -293,6 +398,16 @@ function enableInstrumentations() { dc.subscribe('http.client.request.error', onClientRequestError); } + // A filter of node:http2 covers node:http2/server through the prefix + // match in isModuleEnabled, the same way node:http covers its client and + // server subscopes. + if (isModuleEnabled('node:http2/server')) { + dc.subscribe('http2.server.stream.start', onHttp2ServerStreamStart); + dc.subscribe('http2.server.stream.finish', onHttp2ServerStreamFinish); + dc.subscribe('http2.server.stream.close', onHttp2ServerStreamClose); + dc.subscribe('http2.server.stream.error', onHttp2ServerStreamError); + } + // node:fetch is an alias for node:undici: both enable the same // channels, which cover every undici request, fetch() included. if (isModuleEnabled('node:undici') || isModuleEnabled('node:fetch')) { diff --git a/test/test-http2.js b/test/test-http2.js new file mode 100644 index 0000000..84736d2 --- /dev/null +++ b/test/test-http2.js @@ -0,0 +1,295 @@ +'use strict'; + +const assert = require('node:assert'); +const http2 = require('node:http2'); +const { after, before, describe, it } = require('node:test'); +const { + startTracing, + startHTTPServer, + flushAndCollect, + getClientSpan, + getServerSpan, + spanAttrs, + closeAll, +} = require('./common/otel'); + +// Starts a plain HTTP/2 server for traced requests. The handler receives +// (stream, headers). Exposes port and close(). +async function startHTTP2Server( + handler = (stream) => { + stream.respond({ ':status': 200 }); + stream.end('ok'); + }, +) { + const server = http2.createServer(); + server.on('stream', handler); + + // server.close() waits for open sessions, so they are closed first; + // a lingering client session would otherwise hang the close. + const sessions = new Set(); + server.on('session', (session) => { + sessions.add(session); + session.on('close', () => sessions.delete(session)); + }); + + await new Promise((resolve) => server.listen(0, '127.0.0.1', resolve)); + + return { + port: server.address().port, + close: () => + new Promise((resolve) => { + for (const session of sessions) session.close(); + server.close(() => resolve()); + }), + }; +} + +// Makes one traced HTTP/2 request and waits for the response body to end. +// extraHeaders are merged into the request headers, which is how tests +// supply a caller-written traceparent. +function h2Get(port, path, extraHeaders = { __proto__: null }) { + return new Promise((resolve, reject) => { + const session = http2.connect(`http://127.0.0.1:${port}`); + session.on('error', reject); + const stream = session.request({ ':path': path, ...extraHeaders }); + stream.setEncoding('utf8'); + let body = ''; + stream.on('data', (chunk) => { + body += chunk; + }); + stream.on('end', () => { + session.close(); + resolve(body); + }); + stream.on('error', reject); + }); +} + +describe('otel HTTP/2 server spans', () => { + let collector; + + before(async () => { + collector = await startTracing(); + }); + + after(() => collector.close()); + + it('creates server spans for incoming HTTP/2 requests', async () => { + const target = await startHTTP2Server(); + + await h2Get(target.port, '/h2-path?a=1&b=2'); + + const spans = await flushAndCollect(collector); + + await target.close(); + + // HTTP/2 client requests are not instrumented, so the server span is + // the only one this request can produce. + assert.strictEqual( + spans.length, + 1, + `Expected exactly one span in: ${JSON.stringify(spans)}`, + ); + + const serverSpan = spans[0]; + assert.strictEqual(serverSpan.kind, 2); // SPAN_KIND_SERVER + assert.strictEqual(serverSpan.name, 'GET'); + + assert.ok(serverSpan.traceId); + assert.strictEqual(serverSpan.traceId.length, 32); + assert.ok(serverSpan.spanId); + assert.strictEqual(serverSpan.spanId.length, 16); + assert.ok(serverSpan.startTimeUnixNano); + assert.ok(serverSpan.endTimeUnixNano); + + assert.partialDeepStrictEqual(spanAttrs(serverSpan), { + 'http.request.method': 'GET', + 'url.path': '/h2-path', + 'url.query': 'a=1&b=2', + 'url.scheme': 'http', + 'network.protocol.version': '2.0', + 'http.response.status_code': '200', + 'server.address': `127.0.0.1:${target.port}`, + }); + }); + + it('reads the status code when respond() takes an array of headers', async () => { + const target = await startHTTP2Server((stream, headers) => { + const status = headers[':path'] === '/boom' ? 500 : 404; + stream.respond([':status', status]); + stream.end('body'); + }); + + await h2Get(target.port, '/boom'); + await h2Get(target.port, '/ok'); + + const spans = await flushAndCollect(collector); + await target.close(); + + const boomSpan = getServerSpan(spans, '/boom'); + assert.ok(boomSpan, 'Expected a server span for /boom'); + assert.strictEqual(spanAttrs(boomSpan)['http.response.status_code'], '500'); + assert.ok(boomSpan.status, 'Expected error status on the 5xx'); + assert.strictEqual(boomSpan.status.code, 2); + + const okSpan = getServerSpan(spans, '/ok'); + assert.ok(okSpan, 'Expected a server span for /ok'); + assert.strictEqual(spanAttrs(okSpan)['http.response.status_code'], '404'); + assert.strictEqual(okSpan.status, undefined); + }); + + it('parents fetch spans to the HTTP/2 server span in the same trace', async () => { + const traceId = '0123456789abcdef0123456789abcdef'; + + const fetchTarget = await startHTTPServer(); + // A fetch made while handling a traced HTTP/2 request. + const h2Server = await startHTTP2Server((stream, headers) => { + fetch(`http://127.0.0.1:${fetchTarget.port}/down`) + .then((res) => res.text()) + .then(() => { + stream.respond({ ':status': 200 }); + stream.end('ok'); + }) + .catch(() => stream.close()); + }); + + await h2Get(h2Server.port, '/up', { + traceparent: `00-${traceId}-0123456789abcdef-01`, + }); + + const spans = await flushAndCollect(collector); + await fetchTarget.close(); + await h2Server.close(); + + // The full chain, asserted on the exported spans: the HTTP/2 server + // span parents the fetch client span, and the fetch span parents the + // downstream server span, all in the incoming trace. + const serverSpan = getServerSpan(spans, '/up'); + const fetchSpan = getClientSpan(spans, '/down'); + const downstreamSpan = getServerSpan(spans, '/down'); + assert.ok(serverSpan, 'Expected an HTTP/2 server span'); + assert.ok(fetchSpan, 'Expected a client span for the fetch'); + assert.ok(downstreamSpan, 'Expected a server span downstream'); + + assert.strictEqual(serverSpan.traceId, traceId); + assert.strictEqual(fetchSpan.traceId, traceId); + assert.strictEqual(fetchSpan.parentSpanId, serverSpan.spanId); + assert.strictEqual(downstreamSpan.traceId, traceId); + assert.strictEqual(downstreamSpan.parentSpanId, fetchSpan.spanId); + }); + + it('parents the server span to an inbound traceparent', async () => { + const traceId = '0123456789abcdef0123456789abcdef'; + const parentSpanId = '0123456789abcdef'; + + const target = await startHTTP2Server(); + + await h2Get(target.port, '/parented', { + traceparent: `00-${traceId}-${parentSpanId}-01`, + tracestate: 'vendor=state', + }); + + const spans = await flushAndCollect(collector); + + await target.close(); + + const serverSpan = getServerSpan(spans, '/parented'); + assert.ok(serverSpan, 'Expected a server span'); + assert.strictEqual(serverSpan.traceId, traceId); + assert.strictEqual(serverSpan.parentSpanId, parentSpanId); + assert.notStrictEqual(serverSpan.spanId, parentSpanId); + }); + + it('starts a fresh trace without traceparent and rejects invalid ones', async () => { + const target = await startHTTP2Server(); + + await h2Get(target.port, '/fresh'); + await h2Get(target.port, '/invalid', { + // Version ff is not defined by the W3C spec and must be rejected. + traceparent: `ff-${'0'.repeat(32)}-${'0'.repeat(16)}-01`, + }); + + const spans = await flushAndCollect(collector); + + await target.close(); + + for (const path of ['/fresh', '/invalid']) { + const serverSpan = getServerSpan(spans, path); + assert.ok(serverSpan, `Expected a server span for ${path}`); + assert.strictEqual( + serverSpan.parentSpanId, + undefined, + `${path} must not have a remote parent`, + ); + assert.match(serverSpan.traceId, /^[0-9a-f]{32}$/); + } + + // Both requests must start independent traces. + const fresh = getServerSpan(spans, '/fresh'); + const invalid = getServerSpan(spans, '/invalid'); + assert.notStrictEqual(fresh.traceId, invalid.traceId); + }); + + // Per OTel semantic conventions, server spans set STATUS_ERROR only for + // >= 500; 4xx is the caller's mistake, not the server's. + it('marks 5xx responses as errors but not 4xx', async () => { + const target = await startHTTP2Server((stream, headers) => { + const status = headers[':path'] === '/boom' ? 500 : 404; + stream.respond({ ':status': status }); + stream.end('body'); + }); + + await h2Get(target.port, '/boom'); + await h2Get(target.port, '/missing'); + + const spans = await flushAndCollect(collector); + + await target.close(); + + const errorSpan = getServerSpan(spans, '/boom'); + assert.ok(errorSpan, 'Expected a server span'); + assert.strictEqual(errorSpan.status.code, 2); // STATUS_ERROR + assert.strictEqual(errorSpan.status.message, 'HTTP 500'); + assert.strictEqual(spanAttrs(errorSpan)['error.type'], '500'); + + const notFoundSpan = getServerSpan(spans, '/missing'); + assert.ok(notFoundSpan, 'Expected a server span'); + assert.strictEqual(notFoundSpan.status, undefined); + assert.strictEqual(spanAttrs(notFoundSpan)['error.type'], undefined); + }); + + it('ends an aborted stream with error status', async () => { + const target = await startHTTP2Server((stream) => { + // Never responds: the client resets the stream instead. + stream.resume(); + }); + + await new Promise((resolve) => { + const session = http2.connect(`http://127.0.0.1:${target.port}`); + session.on('error', () => {}); + const stream = session.request({ ':path': '/aborted' }); + stream.on('error', () => {}); + // HEADERS then RST_STREAM are queued in order, so the server sees + // the request before the reset arrives. + stream.close(http2.constants.NGHTTP2_CANCEL); + setTimeout(() => { + session.close(); + resolve(); + }, 50); + }); + + const spans = await flushAndCollect(collector); + + await target.close(); + + const abortedSpan = getServerSpan(spans, '/aborted'); + assert.ok(abortedSpan, 'Expected a server span'); + assert.ok(abortedSpan.status, 'Aborted span should have error status'); + assert.strictEqual(abortedSpan.status.code, 2); // STATUS_ERROR + assert.strictEqual( + spanAttrs(abortedSpan)['http.response.status_code'], + undefined, + 'No response was sent, so no status code', + ); + }); +});