feat(daemon): Trace cold first-session startup - #6907
Conversation
Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
E2E Test ReportTested the bundled CLI on macOS arm64 with Node.js v22.22.3, a loopback daemon, the local OpenTelemetry file exporter, and the existing authenticated provider configuration. Cold Session immediately after health
Explicitly preheated Session
Telemetry disabled
Automated verification
The ACP child printed a pipe |
|
Thanks for the PR! Template looks good ✓ Problem: This is an observed gap, not a theoretical concern. The PR links to #4748 and includes concrete timing data from a downstream deployment (2,534ms P50 cold vs 222ms preheated) and a local dry-run showing 700–800ms unattributed latency. Browser timing cannot separate daemon, channel, and child work — that's a real observability blind spot. Direction: Cold-start observability is squarely within the daemon performance story. Standard W3C trace context propagation and extending the existing Size: Cross-package change (cli, core, acp-bridge) touching core paths ( Approach: The scope feels appropriate for the stated goal. Each addition maps to a specific gap in the trace tree: deferred-runtime request timing, channel-wait classification (spawned/joined/reused), W3C trace context into the ACP child, bounded child stage profiling, and session ID correlation. The One note: the Moving on to code review. 🔍 中文说明感谢贡献! 模板完整 ✓ 问题:这是一个已观测到的缺口,不是理论性担忧。PR 关联了 #4748 并包含来自下游部署的具体计时数据(冷启动 P50 2,534ms vs 预热后 222ms)以及本地 dry-run 显示的 700–800ms 无法归因的延迟。浏览器计时无法区分 daemon、channel 和子进程的工作——这是一个真实的可观测性盲区。 方向:冷启动可观测性是 daemon 性能故事的核心部分。使用标准 W3C trace context 传播并扩展现有的 规模:跨包改动(cli、core、acp-bridge),触及核心路径。生产代码约 340 行(远低于 500 阈值),测试约 348 行,设计文档约 194 行。总增加约 803 行——整体是一个大 PR,但大部分体积来自测试和文档。鉴于跨包 + telemetry 范围,标记供 maintainer 关注。 方案:范围与目标匹配。每个新增都对应 trace 树中的特定缺口:延迟 runtime 请求计时、channel 等待分类(spawned/joined/reused)、W3C trace context 传播到 ACP 子进程、有界子进程阶段分析、session ID 关联。 进入代码审查 🔍 — Qwen Code · qwen3.7-max Reviewed at |
Code ReviewThe implementation is clean and well-structured. Each change maps to a specific gap in the cold-start trace tree, and the telemetry paths are defensively guarded so they can never affect session creation. Correctness: The Security: No issues. Session IDs and channel UUIDs are diagnostic span attributes only — not added to metric labels or public API responses. Reuse note: No critical blockers found. VerificationThis is a telemetry-only change (no TUI or Web UI output change), so tmux before/after is not applicable. Verification focused on build integrity and unit tests: All 1,113 tests pass across the three affected packages. The new tests cover: deferred-runtime request timing propagation into spans, channel-wait path classification (spawned/joined/reused), ACP channel UUID correlation, W3C trace context propagation into the ACP child, bounded stage profiling with failure recording, and session ID in JSONL records. 中文说明代码审查实现干净且结构良好。每个改动都对应冷启动 trace 树中的特定缺口,telemetry 路径都有防御性保护,不会影响 session 创建。 正确性: 安全性: 无问题。Session ID 和 channel UUID 仅作为诊断 span 属性,不会添加到指标标签或公共 API 响应中。 复用说明: 未发现关键阻塞问题。 验证这是仅 telemetry 的变更(无 TUI 或 Web UI 输出变化),因此 tmux before/after 不适用。验证集中在构建完整性和单元测试:构建 ✓、类型检查 ✓、Lint ✓、1,113 个测试全部通过(core 276 + acp-bridge 394 + cli 443)。 — Qwen Code · qwen3.7-max Reviewed at |
|
Confidence: 4/5 — Clean across every stage; the 4/5 reflects the cross-package + telemetry scope needing a maintainer's sign-off, not quality concerns. This PR closes a real and measured observability gap (#4748) — cold first-session latency of 2,534ms P50 that browser timing cannot attribute. The implementation adds tracing spans at exactly the right boundaries: deferred-runtime request timing, channel-wait classification, W3C trace context into the ACP child, and bounded child stage profiling. Every addition maps to a specific gap in the trace tree. The code is clean. Telemetry paths are defensively guarded (try/catch on every setAttribute, span?. optional chaining), the The design doc is genuinely useful — it documents the architecture, downstream consumers reviewed, and the verification plan. The My only reservation is procedural: this crosses core/bridge/CLI package boundaries and touches telemetry infrastructure, which warrants a maintainer's eye on the architectural decision even though the production logic change is ~340 lines and well-contained. Deferring to the maintainer for final approval. 中文说明置信度:4/5 — 各阶段均通过;4/5 反映的是跨包 + telemetry 范围需要 maintainer 签字,而非质量顾虑。 本 PR 填补了一个已测量的可观测性缺口(#4748)——冷启动首 Session P50 延迟 2,534ms,浏览器计时无法归因。实现在恰当的边界添加了追踪 span:延迟 runtime 请求计时、channel 等待分类、W3C trace context 传播到 ACP 子进程、有界子进程阶段分析。每个新增都对应 trace 树中的特定缺口。 代码干净。Telemetry 路径有防御性保护, 设计文档有实际价值。唯一保留是程序性的:此改动跨越 core/bridge/CLI 包边界并触及 telemetry 基础设施,即使生产逻辑变更仅约 340 行且范围明确,仍需 maintainer 对架构决策的最终确认。 转交 maintainer 做最终审批。 — Qwen Code · qwen3.7-max Reviewed at |
|
⏸️ Deferring to @chinesepowered — this is a clean |
qwen-code-ci-bot
left a comment
There was a problem hiding this comment.
Reviewed — no blockers. Suggestions are inline.
— qwen3.7-max via Qwen Code /review
Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
qwen-code-ci-bot
left a comment
There was a problem hiding this comment.
Reviewed — no blockers. Suggestions are inline.
— qwen3.7-max via Qwen Code /review
Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
qwen-code-ci-bot
left a comment
There was a problem hiding this comment.
Reviewed — no blockers. Suggestions are inline.
— qwen3.7-max via Qwen Code /review
Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
doudouOUC
left a comment
There was a problem hiding this comment.
Reviewed. Suggestions are inline. Not reviewed: removed-behavior audit — Agent 1b failed twice.
— qwen3.7-max via Qwen Code /review
Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
qwen-code-ci-bot
left a comment
There was a problem hiding this comment.
Reviewed — no blockers. Suggestions are inline. 1 Suggestion-level finding(s) could not be anchored to the diff; see the terminal output.
— qwen3.7-max via Qwen Code /review
Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
qwen-code-ci-bot
left a comment
There was a problem hiding this comment.
No issues found. LGTM! ✅
— qwen3.7-max via Qwen Code /review
Independent maintainer verification — build + live E2E ✅I reproduced this PR end-to-end on a maintainer machine against the real built binary (no mocks, no stubs). I booted a live Setup: isolated worktree at PR head 1 · One cold
|
Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
🩺 serve daemon A/BBuilt the PR base vs this PR head ✅ No response changes against the PR base across 4 scenario(s). — Qwen Code · serve A/B |
qwen-code-ci-bot
left a comment
There was a problem hiding this comment.
No issues found. LGTM! ✅
— qwen3.7-max via Qwen Code /review




What this PR does
This PR adds an end-to-end cold first-session trace across deferred daemon runtime admission, ACP channel startup or reuse, ACP
session/new, and the existing detailedstartChatprofile. A request that arrives before the runtime mounts now backdates its HTTP span to bootstrap arrival and records whether it started or joined runtime loading. The bridge records whether the Session spawned, joined, or reused an ACP channel, correlates independently-started preheat work with a daemon-generated channel UUID, and propagates W3C trace context into the ACP child. The child records bounded stage durations for settings, Config setup, authentication, file-system setup, Session registration, and response construction. The opt-in session-start JSONL record gains an optional opaque Session ID for trace correlation.The implementation preserves
/healthreadiness, Session response shapes, ACP lifecycle behavior, and telemetry-disabled behavior. It does not add a new protocol or profiling format.Why it's needed
Issue #4748 still has a post-health cold first-session gap that browser timing cannot attribute. A first Session may wait for deferred runtime loading and an in-flight ACP preheat, then perform per-session child initialization. Existing spans start too late to separate bootstrap wait from proxy or network time, do not identify the current request's channel-wait path, and do not connect
session/newto the detailedstartChatprofile. This change closes that observability gap so follow-up optimization can target the measured dominant stage instead of adding speculative caching or changing readiness semantics.Reviewer Test Plan
How to verify
Build and bundle the CLI, enable telemetry with a local outfile plus
QWEN_CODE_PROFILE_SESSION_START=1, startqwen serve, and sendPOST /sessionimmediately after the first successful/health. The Session should succeed with the unchanged response shape. Its request span should includeruntime.pathand a non-negativeruntime.wait_mswhen it crosses deferred runtime admission, followed bychannel.wait,session.new, and a directly parented ACP-childsession_startspan. The completion event and JSONL record should contain the returned Session ID.Repeat after
POST /workspace/acp/preheat; the Session trace should reportchannel.wait.path=reused, and the preheat and Session traces should share the same ACP channel UUID. Then disable telemetry and JSONL profiling; Session creation should still succeed, no telemetry outfile should be created, and the profile file should remain unchanged.Local verification completed with
npm run lint,npm run build,npm run typecheck,npm run bundle, and focused Vitest runs covering 276 core tests, 443 CLI tests, and 394 ACP bridge tests. The final rebased bundled smoke recordedruntime.path=started_on_request,runtime.wait_ms=98.27,channel.wait.path=joined, and a child span directly parented tosession.newin the same trace.Evidence (Before & After)
N/A — telemetry-only change with no TUI or Web UI output change.
Tested on
Environment (optional)
macOS arm64, Node.js v22.22.3, npm 10.9.8, bundled CLI, loopback daemon, local OpenTelemetry file exporter, existing authenticated provider configuration.
Risk & Scope
_metaremains optional, the JSONLsessionIdis additive and opt-in, and telemetry-disabled behavior is unchanged.Linked Issues
Part of #4748
中文说明
本 PR 做了什么
本 PR 为冷启动首个 Session 增加了端到端链路追踪,覆盖 daemon 延迟 runtime 准入、ACP channel 启动或复用、ACP
session/new,以及现有的startChat详细分析。若请求在 runtime 挂载前到达,HTTP span 现在会回溯到 bootstrap 收到请求的时刻,并记录该请求是发起还是加入了 runtime 加载。Bridge 会记录 Session 是触发、加入还是复用了 ACP channel,用 daemon 生成的 channel UUID 关联独立启动的预热工作,并把 W3C trace context 传播到 ACP 子进程。子进程会记录设置加载、Config 初始化、认证、文件系统初始化、Session 注册和响应构建等有界阶段耗时。已有的可选 session-start JSONL 记录新增可选的不透明 Session ID,用于与 trace 关联。实现保持
/health就绪语义、Session 响应结构、ACP 生命周期行为以及关闭 telemetry 时的行为不变;没有增加新的协议或分析格式。为什么需要它
#4748 仍存在健康检查完成后的冷启动首 Session 延迟,而浏览器计时无法归因。首个 Session 可能需要等待延迟 runtime 加载和正在进行的 ACP 预热,之后还要执行子进程内的逐 Session 初始化。现有 span 启动过晚,无法把 bootstrap 等待与代理或网络时间分开,也无法标识当前请求的 channel 等待路径,或将
session/new与详细startChat分析关联起来。本改动补齐了该可观测性缺口,使后续优化可以针对实测的主要阶段,而不是引入推测性的缓存或改变就绪语义。Reviewer 测试计划
如何验证
构建并 bundle CLI,启用指向本地文件的 telemetry 和
QWEN_CODE_PROFILE_SESSION_START=1,启动qwen serve,并在第一次/health成功后立即发送POST /session。Session 应成功并保持原有响应结构。若请求经过延迟 runtime 准入,其 request span 应包含runtime.path和非负的runtime.wait_ms,之后依次出现channel.wait、session.new,以及直接以其为父 span 的 ACP 子进程session_startspan。完成事件和 JSONL 记录应包含返回的 Session ID。在调用
POST /workspace/acp/preheat后重复测试;Session trace 应记录channel.wait.path=reused,预热 trace 与 Session trace 应共享同一个 ACP channel UUID。随后关闭 telemetry 和 JSONL 分析;Session 仍应成功,不应创建 telemetry outfile,profile 文件也应保持不变。本地已完成
npm run lint、npm run build、npm run typecheck、npm run bundle,以及覆盖 276 个 core 测试、443 个 CLI 测试和 394 个 ACP bridge 测试的聚焦 Vitest。最终在 rebase 后生成的 bundle smoke 中记录到runtime.path=started_on_request、runtime.wait_ms=98.27、channel.wait.path=joined,并确认 child span 在同一 trace 中直接以session.new为父 span。证据(修改前后)
N/A — 仅 telemetry 变更,没有 TUI 或 Web UI 输出变化。
测试平台
环境(可选)
macOS arm64、Node.js v22.22.3、npm 10.9.8、bundled CLI、loopback daemon、本地 OpenTelemetry 文件 exporter、已有的认证 provider 配置。
风险与范围
_meta仍为可选,JSONLsessionId是可选增量字段,关闭 telemetry 时的行为不变。关联 Issue
#4748 的一部分