qwen-code/docs/developers/daemon/19-observability.md

Observability & Debugging

Overview

qwen serve currently ships with OpenTelemetry span instrumentation, structured file logs (DaemonLogger), per-request access logs, debug stderr logs, structured preflight cells, and an in-memory permission audit ring. This page is a practical guide to the current observability surface and the gaps to remember during triage.

What exists today

Surface	Location	Purpose
QWEN_SERVE_DEBUG stderr logs	bridge.ts and call sites	Env values 1 / true / on / yes (case-insensitive) print qwen serve debug: ... lines to stderr.
OpenTelemetry span instrumentation	server.ts daemonTelemetryMiddleware	Classified daemon API requests that reach the telemetry middleware are wrapped in withDaemonRequestSpan; attributes include canonical route, workspace hash when resolved, sessionId, clientId, and status code. Permission routes have dedicated spans. Prompt lifecycle is traced end-to-end. Configuration lives in settings.json telemetry.
OpenTelemetry daemon perf metrics	telemetry/*event-loop-lag*, daemon-metrics	Event loop lag gauges for daemon and ACP child processes, plus daemon-child pipe message byte histograms.
DaemonLogger structured file logs	serve/daemon-logger.ts	Appends to a stable, size-rotated daemon.log. File records include runId and PID. Boot prints the selected stable/fallback path; full status exposes health, issues, and file-copy loss counters.
Per-request access-log middleware	server/access-log.ts	Logs method/path, status, duration, session, and first raw client ID after each request. A 60-token burst / 2-per-second bucket aggregates excess traffic into five fixed status counters. Health, heartbeat, and successful SSE exclusions remain.
/health	server.ts route	Liveness probe; ?deep=1 returns extended details.
/capabilities	server.ts route	Preflight feature discovery. See 11-capabilities-versioning.md.
/workspace/preflight	Route -> DaemonStatusProvider	Structured readiness cells: Node version, CLI entry, ripgrep, git, npm, plus ACP-level cells once a child is alive.
/workspace/env	Route -> DaemonStatusProvider	Daemon process env snapshot. Secret env vars report only presence; proxy URL credentials are stripped.
/workspace/mcp	Route -> bridge extMethod	Pool, budget, and refusal snapshot.
/workspace/skills, /workspace/providers	Routes	ACP-side live snapshots; return empty idle data when no session exists.
Per-session SSE	GET /session/:id/events	Real-time event stream.
/demo debug console	GET /demo (packages/cli/src/serve/demo.ts)	Browser-accessible single-page console: chat, event log, workspace inspector, and permission UX. On loopback, http://127.0.0.1:4170/demo is the quickest end-to-end validation path without writing SDK code. Registration rules are in 02-serve-runtime.md.
PermissionAuditRing	permission-audit.ts	In-memory FIFO of 512 permission decisions.
Mediator decisionReason audit	permissionMediator.ts	Internal structured record explaining why a permission request resolved the way it did.

What does not exist today

• No Prometheus / metrics endpoint. OTel metrics can be exported, but the daemon does not expose a Prometheus scrape endpoint.
• No external audit sink for PermissionAuditRing. The ring exists, but fan-out hooks to SIEM or external storage are not wired.

Debugging recipes

1. Is the daemon alive?

curl -s http://127.0.0.1:4170/health
# {"status":"ok"}

curl -s 'http://127.0.0.1:4170/health?deep=1' | jq
# {"status":"ok","workspaceCount":N,"sessions":N,...}

Deep health totals all managed workspace runtimes, including runtimes still draining. It is an informational counter snapshot, not per-workspace readiness; use /daemon/status when individual workspace or transport diagnostics matter.

A 401 on loopback means --require-auth is likely enabled. Use QWEN_SERVE_DEBUG=1 at startup to see boot logs.

2. Which features are advertised?

curl -s http://127.0.0.1:4170/capabilities | jq

Check mcp_workspace_pool (F2 pool on?), require_auth (hardened?), permission_mediation.modes (supported policies), and policy.permission (active policy).

3. Is daemon-host readiness healthy?

curl -s http://127.0.0.1:4170/workspace/preflight | jq

status: 'not_started' cells are ACP-level and populate only after the first session attaches. status: 'fail' cells include a closed errorKind; render structured remediation from 18-error-taxonomy.md.

4. Tail a session SSE stream

curl -N -H 'Accept: text/event-stream' \
     -H 'Authorization: Bearer XYZ' \
     -H 'X-Qwen-Client-Id: debug-tail' \
     -H 'Last-Event-ID: 0' \
     'http://127.0.0.1:4170/session/<sid>/events'

-N disables curl output buffering. Last-Event-ID: 0 requests replay for ring events with id > 0.

5. Why did a permission request resolve this way?

PermissionAuditRing is in-memory and has no HTTP surface today. Enable QWEN_SERVE_DEBUG=1 and reproduce; the mediator prints structured lines for each vote and decision, including decisionReason.type. A later PR can expose the ring through HTTP.

6. Which consumer is slow?

slow_client_warning fires once per overflow episode when the queue reaches 75%. Subscribe to the session SSE stream and look for the synthetic frame; payload includes queueSize, maxQueued, and lastEventId. Repeated warnings point at a stuck consumer, usually a blocked SDK for await loop.

7. Why was an MCP server refused?

Combine /workspace/mcp per-cell disabledReason: 'budget', the refusedServerNames list, and mcp_child_refused_batch SSE events. Compare them with /capabilities mcp_guardrails.modes (enforce active?) and the live --mcp-client-budget state visible through getReservedSlots().

8. The daemon will not shut down

The first signal triggers graceful shutdown (see 02-serve-runtime.md). If it hangs past 10s, check:

• ACP child process did not respond to graceful close.
• Long SSE connections kept HTTP server.close() open past SHUTDOWN_FORCE_CLOSE_MS (5s).

A second SIGTERM/SIGINT intentionally triggers bridge.killAllSync() + process.exit(1).

9. Is the daemon event loop, prompt queue, or ACP pipe overloaded?

GET /daemon/status may include runtime.perf when the production daemon runtime injects the perf snapshot provider:

{
  "runtime": {
    "perf": {
      "eventLoop": { "meanMs": 1.2, "p50Ms": 1.0, "p99Ms": 9.5, "maxMs": 25 },
      "promptQueueWait": {
        "count": 3,
        "meanMs": 12.5,
        "maxMs": 35,
        "lastMs": 4
      },
      "pipe": {
        "inbound": { "count": 42, "totalBytes": 100000, "maxBytes": 12000 },
        "outbound": { "count": 41, "totalBytes": 90000, "maxBytes": 11000 }
      }
    }
  }
}

The status payload is daemon-only. promptQueueWait summarizes prompt FIFO queue wait samples observed in the daemon process. ACP child event loop lag is intentionally not aggregated into /daemon/status; it is visible through OTel gauge qwen-code.acp.event_loop.lag and through stderr stall lines forwarded into daemon logs.

10. Did file logging degrade or lose records?

Use full daemon status:

curl -s 'http://127.0.0.1:4170/daemon/status?detail=full' | \
  jq '{status, issues, daemon: {runId: .daemon.runId, logMode: .daemon.logMode, logHealth: .daemon.logHealth, logPath: .daemon.logPath, logIssues: .daemon.logIssues, droppedRecords: .daemon.logDroppedRecords, droppedBytes: .daemon.logDroppedBytes}}'

stable is the normal owner, fallback means another daemon owns the stable family, and stderr-only means file logging is disabled or unavailable. fallback/ok is expected under intentional concurrency. A daemon_log_degraded warning contains no path; request full detail for the actual path and logger issue codes. Use runId to separate restarts inside the stable file.

New OTel metric names:

• qwen-code.daemon.event_loop.lag, gauge in milliseconds with stat=mean|p50|p99|max.
• qwen-code.acp.event_loop.lag, gauge in milliseconds with stat=mean|p50|p99|max.
• qwen-code.daemon.prompt.queue_wait, histogram in milliseconds.
• qwen-code.daemon.pipe.message_bytes, histogram in bytes with direction=inbound|outbound.

Flow

Typical triage flow

flowchart TD
    A[User reports issue] --> B{daemon alive?}
    B -->|no| BD[check process; check boot logs]
    B -->|yes| C{capabilities match expectations?}
    C -->|no| CD["check --require-auth, QWEN_SERVE_NO_MCP_POOL, settings.json"]
    C -->|yes| D{preflight all green?}
    D -->|no| DD["fix the errorKind cell"]
    D -->|yes| E{issue is session-specific?}
    E -->|yes| ES["tail SSE for that session;<br/>QWEN_SERVE_DEBUG=1 + reproduce"]
    E -->|no| EW["check /workspace/mcp,<br/>/workspace/env"]

State and lifecycle

• QWEN_SERVE_DEBUG is read on every check through isServeDebugMode() from debug-mode.ts; toggling it does not require restart. Boot logs are not available unless the env was set at boot.
• PermissionAuditRing is bounded at 512 FIFO entries; older records are silently dropped.
• DaemonStatusProvider rebuilds cells per request and does not cache; avoid unnecessary high-frequency polling.

Dependencies

• process.stderr.write for debug stderr.
• DaemonLogger for structured file logs.
• OpenTelemetry SDK through initializeTelemetry and createDaemonBridgeTelemetry.
• node:perf_hooks.monitorEventLoopDelay for daemon and ACP event loop lag gauges.
• node:process for env and signal inspection.

Configuration

Knob	Effect
QWEN_SERVE_DEBUG	Enables verbose stderr logs. See 17-configuration.md.
settings.json telemetry	Controls OTel behavior: enabled, otlpEndpoint, otlpProtocol, and per-signal endpoints.
DaemonLogger log path	Stable debug/daemon/daemon.log, or a run-specific fallback selected at boot.
PermissionAuditRing size	Hard-coded to 512 today.
slow_client_warning threshold	0.75 / 0.375, hard-coded in eventBus.ts.

Caveats and known limits

• DaemonLogger file logs are structured and can be filtered by route, sessionId, and clientId. QWEN_SERVE_DEBUG stderr logs remain unstructured text.
• DaemonLogger retention is size based, not age based. The active file and four archives are bounded per family; live fallback owners are never deleted.
• Access summaries are intentional loss accounting. A WARN access logs suppressed represents individual access records omitted from both stderr and file; it does not indicate dropped HTTP requests.
• External logrotate must not mutate the active family. Use a shipper that reads/copies and reopens the stable pathname after replacement.
• OpenTelemetry spans include per-request correlation. Classified daemon API requests that pass bearer authentication, rate limiting, and body parsing carry canonical route, sessionId, clientId, and (when uniquely resolved) qwen-code.workspace.hash attributes. Requests rejected by an earlier middleware gate do not have these request spans.
• HTTP metrics are daemon-global. OpenTelemetry HTTP request metrics and the Web Shell status metrics ring do not include a workspace dimension. A successful session SSE connection has a request span but is excluded from ordinary request count/duration metrics because its lifetime is not request latency; failed SSE handshakes are counted normally.
• runtime.perf is daemon-only. Child event loop lag is not reported there by design; use OTel or forwarded stderr stall warnings for ACP child stalls.
• ACP-level /workspace/preflight cells require a live session. On an idle daemon, auth / MCP / skills / providers may show status: 'not_started'; this is expected.
• /workspace/env only reports secret presence, not values. Do not expose the response where the mere presence of a secret is sensitive.
• The audit ring is process-local and history is lost on daemon restart.
• No load-test recipe is documented here. The performance baseline lives on the test/perf-daemon-baseline branch.

References

• packages/cli/src/serve/daemon-status-provider.ts
• packages/cli/src/serve/daemon-logger.ts (DaemonLogger, buildDaemonLogLine)
• packages/cli/src/serve/debug-mode.ts (isServeDebugMode)
• packages/acp-bridge/src/permissionMediator.ts (PermissionDecisionReason)
• packages/cli/src/serve/server.ts (daemonTelemetryMiddleware, access-log middleware)
• Configuration: 17-configuration.md
• Error taxonomy: 18-error-taxonomy.md
• User operations guide: ../../users/qwen-serve.md