Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
142 changes: 142 additions & 0 deletions docs/design/2026-08-18-daemon-http-inbound-trace-context.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,142 @@
# Daemon HTTP inbound trace context

## Motivation

The daemon already _propagates_ trace context outbound: prompt requests carry a
`traceparent` inside JSON-RPC `_meta`, and the daemon extracts it to parent its
bridge spans (`extractDaemonTraceContext`). The HTTP surface, however, only
_records_ request spans — every `qwen-code.daemon.request` span starts a new
trace. An HTTP caller that forwards the standard W3C `traceparent` header
(corporate proxies, OTel-instrumented clients, ACP gateways) gets no linkage:
the server-side span cannot be joined back to the caller's trace, so
cross-service debugging falls back to timestamps.

W3C Trace Context extraction at the HTTP server edge is standard
`SpanKind.SERVER`-adjacent behavior per the OTel HTTP semantic conventions, and
the plumbing already exists: `withDaemonSpan` accepts an explicit
`parentContext`.

## Design

1. **Core** (`daemon-tracing.ts`): the existing `_meta` extraction logic
(global `propagation.extract` first, then a direct
`W3CTraceContextPropagator` instance as fallback, so acceptance rules —
future traceparent versions, `tracestate`, all-zero ids — are identical
with and without a registered global propagator) moves into a shared
`contextFromTraceparentValues` helper. A new
`extractDaemonHttpTraceContext(headers)` reads `traceparent`/`tracestate`
from a Node-style (lowercased) header object and reuses that helper.
`DaemonRequestSpanOptions` gains an optional `parentContext` passed straight
through to `withDaemonSpan`.
2. **Serve middleware**: `daemonTelemetryMiddleware` extracts from
`req.headers` per request (fail-closed to `undefined`, telemetry never
affects handling) and passes the context only when extraction succeeded —
requests without a valid header keep the exact current span shape.
Span-context extraction is gated on `isTelemetrySdkInitialized()`, so
telemetry-off deployments pay no OTel machinery on the hot path — only the
single-regex trace-id capture described under Log correlation — and a
present-but-invalid header emits a debug daemon log
(`qwen-code.daemon.traceparent.invalid`) so a rejected header is
diagnosable from daemon logs alone.

Note the whole subtree relocates with the request span, not just
`daemon.request` itself: session-subprocess spans reached via `_meta`
(prompt / model / tool) also join the caller's trace, so anything
aggregating or alerting by `traceId` sees session-side spans change
ownership too.

## Log correlation

Daemon log lines already carry a `[trace_id=… span_id=…]` prefix when written
inside an active recording span (`getActiveTraceContext`, #9084). Telemetry
on, this PR closes the loop end to end: the request span parents to the
caller's trace, so every daemon log line for that request — including the
access log's `request completed` — is prefixed with the caller's trace id.
(The access log's `finish` listener reads the active span through the same
AsyncLocalStorage propagation as the logger, so ordering of the two `finish`
listeners is irrelevant for the prefix.)

Telemetry off — the default — there is no span, so the prefix never fires.
A separate lightweight path keeps the log-based join alive with no telemetry
config and no trace backend: the middleware parses the `traceparent` header
with a plain regex (`extractInboundTraceId`, acceptance mirroring the vendored
W3C propagator — same shape/all-zero/`ff` rejections, single optional
leading/trailing whitespace, trailing extension fields above version `00` —
so a header either joins on both paths or neither; `tracestate` stays in the
propagator path since a log line only needs a plausible trace id) and stores
the trace id on the per-response telemetry context (the same
symbol the workspace hash uses). The access log's `finish` callback reads it
back and emits it as the camelCase `traceId` field of `request completed` —
distinct from the logger's reserved snake_case `trace_id` prefix keys, so a
caller cannot spoof the span-derived prefix. The camelCase field is captured
in both telemetry modes whenever a valid header parses, so one log query
shape works for every deployment; with telemetry on the snake_case span
prefix carries the same id redundantly. The field is omitted, not
empty, when no valid header is present, and every step stays fail-closed
(telemetry must not affect request handling).

## Sampling policy

The caller's `sampled` bit is not adopted verbatim on the HTTP path. Under
the default `parentbased_always_on` sampler (the daemon SDK configures no
sampler), a remote unsampled parent delegates to `AlwaysOffSampler` and would
silently delete the request span, everything under `next()`, and — via the
`_meta` forwarding — the session-subprocess spans. `sampled=0` is simply the
caller's head-based ratio sampling, so inbound HTTP parents force
`TraceFlags.SAMPLED` through the same `shouldForceSampled()` decision matrix
as the synthetic session root: `parentbased_*` defaults and `always_on` force
sampling; `parentbased_always_off` honors the operator's opt-out;
non-parentbased samplers (e.g. `traceidratio`) keep the caller's flags and
decide per span. The `_meta` path applies the same forcing: for the
in-process bridge (daemon → subprocess) it is a no-op — that parent is our
own span, already SAMPLED under this policy — while direct ACP clients can
also attach `_meta` with a caller-controlled `sampled=0`, which is external
input exactly like the HTTP header and gets the same protection.

## Non-goals

- No new span kinds or attributes: existing `qwen-code.daemon.request` spans
stay `SpanKind.INTERNAL` with the same attributes; only the parent link
changes when a valid header is present.
- No `traceparent` _response_ injection and no W3C `tracingresponse` support.
- No new sampling configuration surface: the inbound policy reuses the
existing `shouldForceSampled()` matrix (see above); the SDK's own sampler
remains the only sampler authority.

## Alternatives considered

- Changing the request span to `SpanKind.SERVER` per HTTP semconv: **known
gap** — `qwen-code.daemon.request` is the daemon's only SERVER-adjacent
span (`HttpInstrumentation` never patches the server side here because the
SDK loads lazily), so backends deriving service topology / RED metrics
from SERVER spans (Tempo service-graph, ARMS) will not recognize the
daemon as a service inside the caller's trace. Switching would mutate the
shape of every existing daemon.request span and can shift backend
grouping; deferred as a follow-up.
- Extracting inside the core `withDaemonRequestSpan` from a raw header bag:
rejected because core request-span options are transport-primitive today;
the middleware is the only place that knows the carrier is HTTP headers.

## Testing

- Unit: header extraction (valid / absent / malformed / all-zero ids / array
value / version `ff` / version `00` with extension field / future version
`01` / inbound `tracestate`), request-span parenting through
`withDaemonRequestSpan`, the sampled-flag decision matrix (default forced,
`parentbased_always_off` and `traceidratio` verbatim, `_meta` path forced
under the default sampler and verbatim on opt-out), middleware pass-through
(present vs omitted key, telemetry-off
skip, rejected-header debug log), and a type-level guard keeping
`parentContext` on `DaemonRequestSpanOptions`.
- Unit (telemetry-off log join): `extractInboundTraceId` (valid / absent /
malformed / all-zero ids / version `ff` / array value / future version,
plus no-propagator-needed in the fresh-module state), middleware capture
(telemetry off with and without a header, telemetry on emitting the
camelCase field alongside the span prefix),
handler-resolved context initialization not clobbering the stored id), and
the access log emitting / omitting the `traceId` field.
- Dry run: `serve` with `QWEN_TELEMETRY_OUTFILE`, one curl with a fixed
`traceparent` — exported span must share the header's traceId and parent to
its spanId; a control request without the header must stay on its own trace.
With telemetry disabled, the same curl must still log
`request completed` with `traceId` matching the header.
39 changes: 39 additions & 0 deletions docs/developers/development/telemetry.md
Original file line number Diff line number Diff line change
Expand Up @@ -403,6 +403,45 @@ established the principle: "telemetry's scope of work doesn't include
sending identifiers to LLM providers"; correlation-header work moves to
its own design discussion rather than landing under telemetry.

## Inbound correlation (daemon HTTP API)

The daemon HTTP API accepts the standard W3C `traceparent` header on every
request. Two consumers read it independently:

- **Request span re-parenting (telemetry enabled).** When the telemetry SDK
is initialized, a valid header is extracted as the request span's remote
parent, so daemon spans attach under the caller's trace instead of
starting a new one. The `_meta` forwarding path reads the same parent
chain, so session subprocess spans forwarded through a daemon request
inherit it too.
- **Access-log `traceId` field (both modes).** A dedicated pre-auth capture
middleware parses the header on every request — including ones
short-circuited at auth (401), the rate limiter (429), the JSON body
parser (400), or never matched by any route (404) — and the access log
emits the caller trace id as a camelCase `traceId` field. With telemetry
disabled this field is the only join between a daemon log line and the
caller's logs (or trace backend), so one saved query works for both modes
with no telemetry configuration.

An invalid-but-present header is rejected (the span stays parentless) and
leaves a rate-limited DEBUG breadcrumb
(`qwen-code.daemon.traceparent.invalid`) recording the rejected value, so a
broken cross-service join is diagnosable from daemon logs alone.

### Forced sampling under inbound parents

Under the default `parentbased_always_on` sampler (and other parentbased
defaults), a remote parent's `sampled=0` flag is a head-based decision on
the caller's side, not a request to drop daemon telemetry, so extraction
forces the SAMPLED flag on inbound parents. The only opt-out is
`OTEL_TRACES_SAMPLER=parentbased_always_off`, which honors the caller's
flags — note it also disables root-span sampling for the whole daemon, not
just inbound-linked requests.

**Warning:** a constant `traceparent` (e.g. hardcoded in a load-test
client) re-parents every daemon request into one single trace; generate a
fresh header per request.

## Aliyun Telemetry

### Manual OTLP Export
Expand Down
1 change: 1 addition & 0 deletions package-lock.json

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

11 changes: 10 additions & 1 deletion packages/cli/src/serve/server.ts
Original file line number Diff line number Diff line change
Expand Up @@ -181,7 +181,10 @@ import {
parseClientIdHeader,
safeBody,
} from './server/request-helpers.js';
import { daemonTelemetryMiddleware } from './server/telemetry.js';
import {
daemonInboundTraceIdCaptureMiddleware,
daemonTelemetryMiddleware,
} from './server/telemetry.js';
import { installAccessLogMiddleware } from './server/access-log.js';
import { setupDeviceFlowRegistry } from './server/device-flow-registry.js';
import {
Expand Down Expand Up @@ -1722,6 +1725,12 @@ export function createServeApp(

installAccessLogMiddleware(app, daemonLog);

// Capture the caller trace id BEFORE authenticate / rate limiter / body
// parser: those layers short-circuit (401/429/400) before the telemetry
// middleware ever runs, and the access log still needs the captured id
// to join their log lines (and 404s) with the caller's trace.
app.use(daemonInboundTraceIdCaptureMiddleware);

// Serve the Web Shell static assets (/ and /assets) BEFORE bearerAuth. The
// static shell carries no secrets and a browser cannot attach an
// Authorization header to a `<script src>` subresource or an address-bar
Expand Down
37 changes: 37 additions & 0 deletions packages/cli/src/serve/server/access-log.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -9,10 +9,23 @@ import { context, ROOT_CONTEXT } from '@opentelemetry/api';
import type { Application, RequestHandler } from 'express';
import { afterEach, describe, expect, it, vi } from 'vitest';
import type { DaemonLogContext, DaemonLogger } from '../daemon-logger.js';

const telemetryMocks = vi.hoisted(() => ({
getDaemonTelemetryInboundTraceId: vi.fn((): string | undefined => undefined),
}));

// The access log reads the caller trace id through this seam; mocking it
// keeps the suite off the real telemetry module (and its core import graph).
vi.mock('./telemetry-context.js', () => ({
getDaemonTelemetryInboundTraceId:
telemetryMocks.getDaemonTelemetryInboundTraceId,
}));

import { installAccessLogMiddleware } from './access-log.js';

afterEach(() => {
vi.restoreAllMocks();
telemetryMocks.getDaemonTelemetryInboundTraceId.mockReset();
});

function fakeLogger(): DaemonLogger {
Expand Down Expand Up @@ -115,6 +128,30 @@ describe('installAccessLogMiddleware', () => {
);
});

it('joins the request log line to the caller trace when telemetry is off', () => {
telemetryMocks.getDaemonTelemetryInboundTraceId.mockReturnValueOnce(
'3'.repeat(32),
);
const h = harness();
h.begin({ path: '/traced' }).response.emit('finish');

expect(h.logger.info).toHaveBeenCalledWith(
'request completed',
expect.objectContaining({ traceId: '3'.repeat(32) }),
);
});

it('omits the traceId field when no inbound trace id was captured', () => {
const h = harness();
h.begin({ path: '/untraced' }).response.emit('finish');

const context = vi.mocked(h.logger.info).mock.calls[0]?.[1] as
| DaemonLogContext
| undefined;
expect(context).toBeDefined();
expect('traceId' in (context ?? {})).toBe(false);
});

it('caps UTF-8 fields, uses the first raw client header, and tolerates clock retreat', () => {
const h = harness();
const sessionId = '你'.repeat(100);
Expand Down
7 changes: 7 additions & 0 deletions packages/cli/src/serve/server/access-log.ts
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@ import { performance } from 'node:perf_hooks';
import { context, ROOT_CONTEXT } from '@opentelemetry/api';
import type { Application } from 'express';
import type { DaemonLogContext, DaemonLogger } from '../daemon-logger.js';
import { getDaemonTelemetryInboundTraceId } from './telemetry-context.js';

const SESSION_ID_RE = /\/session\/([^/]+)/;
const ACCESS_LOG_BURST = 60;
Expand Down Expand Up @@ -158,6 +159,11 @@ export function installAccessLogMiddleware(
const clientId = rawClientId
? truncateUtf8(rawClientId, CLIENT_ID_MAX_BYTES)
: undefined;
// With telemetry on, the daemon request span stamps the trace prefix
// on this line already; this field covers telemetry-off deployments,
// where it is the only traceId link between a daemon log line and the
// caller that sent the traceparent header.
const inboundTraceId = getDaemonTelemetryInboundTraceId(res);
Comment thread
chiga0 marked this conversation as resolved.
Comment thread
chiga0 marked this conversation as resolved.
const ctx = {
route: route.value,
...(route.originalBytes
Expand All @@ -179,6 +185,7 @@ export function installAccessLogMiddleware(
: {}),
}
: {}),
...(inboundTraceId ? { traceId: inboundTraceId } : {}),
Comment thread
chiga0 marked this conversation as resolved.
status,
durationMs: Math.max(0, Math.round(monotonicNow() - startMs)),
};
Expand Down
51 changes: 51 additions & 0 deletions packages/cli/src/serve/server/telemetry-context.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,51 @@
/**
* @license
* Copyright 2026 Qwen Team
* SPDX-License-Identifier: Apache-2.0
*/

import type { Response } from 'express';

// This module must stay import-light: the access log (inside the serve
// fast-path's pre-listen static closure) reads the captured trace id from
// here, so it cannot reach the telemetry middleware's core import graph.
export interface DaemonTelemetryResponseContext {
workspaceCwd?: string;
}

export const daemonTelemetryResponseContext = Symbol(
'daemonTelemetryResponseContext',
);

export type TelemetryResponse = Response & {
[daemonTelemetryResponseContext]?: DaemonTelemetryResponseContext;
};

// The captured caller trace id lives under its own symbol: the presence of
// the telemetry response context doubles as the opt-in gate for
// handler-resolved workspace attribution (see setDaemonTelemetryWorkspace),
// so capturing a trace id must never create it — otherwise a caller merely
// sending a traceparent header would silently change span attribution.
export const daemonInboundTraceIdContext = Symbol(
'daemonInboundTraceIdContext',
);

export type InboundTraceIdResponse = Response & {
[daemonInboundTraceIdContext]?: string;
};

/**
* The caller trace id captured from a valid inbound `traceparent` header,
* in both telemetry modes. The access log reads it so a request's log line
* still joins with the caller's logs (or trace backend) with no daemon-side
* telemetry at all.
*/
export function getDaemonTelemetryInboundTraceId(
res: Response,
): string | undefined {
try {
return (res as InboundTraceIdResponse)[daemonInboundTraceIdContext];
} catch {
return undefined;
}
}
Loading
Loading