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

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.

11. Is the daemon under memory pressure?

curl -s 'http://127.0.0.1:4170/daemon/status' | \
  jq '.runtime.memory.pressure'

level is normal / soft / hard / critical, classified from ratio — the worse of rssRatio (RSS against detected cgroup/host memory, which is what the OOM killer watches) and heapRatio (V8 heap used against this process's heap_size_limit — the whole heap, not only the old space that --max-old-space-size names). source says which one produced it. Check source before acting: unknown means the daemon could measure neither side, so normal there is the absence of a reading, not evidence of health. A side is only reported when both its numerator and its denominator were usable, so source is also what tells a zero rssBytes / heapUsedBytes apart from a real one.

rssRatio is only as good as its denominator, and limits.memory.availableMemorySource is what grades it. Under a cgroup (constrained) it is exactly the limit the OOM killer enforces, so the ratio means what it says. On bare metal (host) it is the size of the whole machine, while the daemon actually dies when the machine runs out — which depends on every other process on the box. A daemon holding 20% of a 64 GB host beside a 55 GB neighbour reports level: normal, source: rss right up until it is killed. Under source: 'host', read rssRatio as a lower bound on real pressure. This is separate from the thresholds being uncalibrated: no threshold choice fixes a denominator that is measuring the wrong thing.

Two further things this does not cover. It is the daemon root process only, so a daemon whose qwen --acp children are the ones growing can report normal throughout — read runtime.memory.children beside it, which sums the live children's own RSS (and says via sampled how many actually reported). And nothing remediates: leaving normal raises a daemon_memory_pressure warning and changes no behaviour.

Under --memory-pressure-mode off every figure above is still reported and the issue is not raised, so the top-level status stays whatever it would have been. Use off while calibrating thresholds against a real workload, or if you alert on status and do not want an uncalibrated signal moving it.

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;
QWEN_SERVE_DEBUG=1 + reproduce"]
    E -->|no| EW["check /workspace/mcp,
/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

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