perf(cli): Defer ACP telemetry initialization - #7558
Conversation
Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
|
Thanks for the PR — clean, well-documented change. Template looks good ✓ (all sections + Chinese translation present). Problem: observed, not theoretical. Real benchmark — 30 alternating paired cold starts on a constrained 2-vCPU host, Direction: aligned — ACP startup latency is actively tracked (#7264 candidate 2, contributes to #4748), and editors that gate "agent ready" on the initialize response feel this boundary directly. No direct CHANGELOG reference for telemetry-deferral optimization, but the area is clearly relevant. Flag: this touches telemetry behavior (initialized-gate drop window gets longer) and core config ( Size: touches core paths. Production logic: 43 lines ( Approach: scope feels right and notably minimal — reuses the existing Moving on to code review. 🔍 中文说明感谢贡献——干净、文档完善的改动。 模板 完整 ✓(所有章节 + 中文翻译齐全)。 问题: 已观测到,非理论性。真实基准——受限 2-vCPU 主机上 30 组交替配对冷启动, 方向: 对齐——ACP 启动延迟有活跃跟踪(#7264 candidate 2,推进 #4748),以 initialize 响应作为 "agent 就绪" 门槛的编辑器直接感受此边界。CHANGELOG 无 telemetry 延迟优化的直接引用,但该领域明显相关。提醒: 触及 telemetry 行为(initialized-gate 丢弃窗口变长)和核心配置( 规模: 触及核心路径。生产逻辑:43 行( 方案: 范围合理且精简——复用现有 进入代码审查 🔍 — Qwen Code · qwen3.8-max-preview Reviewed at |
Code reviewBefore reading the diff, my independent proposal from the title + motivation: (a) reuse the existing I verified the load-bearing assumptions against the code, not just the PR description:
No correctness bugs, no security concerns, no regressions spotted. Reuse is good — nothing duplicated, logic lives in the right package. No AGENTS.md violations. The diff is exactly the minimal set for the stated goal (no drive-by changes; the design doc is appropriate for a behavioral change). Real-scenario testing
1. Focused unit tests (real runs, PR branch code): 2. Real ACP child smoke test (before/after, outfile telemetry enabled): This pair is discriminating: on 中文说明代码审查在读 diff 之前,我根据标题和动机给出的方案是:(a) 复用现有 我对照代码(而非仅凭 PR 描述)验证了关键假设:
未发现正确性 bug、安全隐患或回归。复用良好——无重复代码,逻辑放在正确的包中。无 AGENTS.md 违规。diff 恰好是达成目标所需的最小集合(无顺手改动;行为改动配设计文档是恰当的)。 真实场景测试本主机未安装 1. 聚焦单元测试(真实运行,PR 分支代码): 28 个 telemetry 配置测试通过(含新增 "should defer telemetry for ACP startup"),300 个 ACP agent 测试通过(含新增 "starts telemetry only after a matching successful initialize response is sent"),11 个 NDJSON 传输测试通过(sent 钩子在写入后触发,写入失败时跳过)。 2. 真实 ACP 子进程冒烟测试(before/after,开启 outfile telemetry):
这组对照具有区分度:在 — Qwen Code · qwen3.8-max-preview Reviewed at |
|
Confidence: 4/5 — clean review, solid execution, real-process smoke confirms the promised behavior. Docking one point because it touches core config + telemetry behavior on a fork PR, which needs maintainer sign-off rather than auto-approve. Stepping back: this is good work. The approach matches what I'd have proposed independently, the implementation is minimal and reuses existing machinery (the My one reservation is the cost/benefit, and it's a judgment call I won't make unilaterally: the gain is ~44 ms on Why I'm deferring instead of approving: the change touches ⏸️ Deferring to @wenshao @yiliang114 — needs a human call on two things: (1) sign-off on a fork PR touching core config + telemetry behavior (policy gate), and (2) whether the narrow, end-to-end-neutral 中文说明置信度:4/5 —— 审查干净、执行扎实,真实进程冒烟证实了承诺的行为。扣一分因为它在 fork PR 上触及核心配置 + telemetry 行为,需要 maintainer 签字而非自动批准。 退一步看:这是好工作。方案与我独立提出的一致,实现精简、复用现有机制( 我唯一的保留是成本收益,这是一个我不会单方面拍板的判断:收益是 为什么我选择 defer 而非 approve:改动触及 ⏸️ 转交 @wenshao @yiliang114 —— 需要人工拍板两件事:(1) 对一个触及核心配置 + telemetry 行为的 fork PR 签字(策略闸门);(2) 这个窄幅、端到端中性的 — Qwen Code · qwen3.8-max-preview Reviewed at |
Review & Local Verification Report代码审查设计评价:严谨的性能优化工程。 本 PR 将 ACP 子进程的遥测初始化从 Config 构造函数延迟到 protocol 核心设计(transport-defined boundary):
安全门控(5 个不触发条件):
基准测试(30 对交替冷启动,2C4G):
28/30 对中 initialize 更快,session 请求中性——优化不引入端到端回归。 设计文档质量极高: 包含问题定义、所有权分析、6 个被拒替代方案、完整的失败/兼容行为矩阵、原始数据路径。 结论LGTM。 教科书级的性能优化 PR:transport 层保证(非调度假设)、完整的失败分析、30 对基准测试、被拒方案记录。 |
qwen-code-ci-bot
left a comment
There was a problem hiding this comment.
— qwen3.7-max via Qwen Code /review
|
[codex] Thanks — no action needed; CI has since completed successfully (10/10 passing) at the reviewed SHA. The PR remains ready for maintainer review. |
Local verification report — real bundles, real ACP clientI built both sides from source and drove the release bundles with a genuine ACP client ( Verdict: the mechanism works and the win reproduces — but the PR silently kills every OpenTelemetry metric in ACP children. One line needs to move; everything else looks good.
1. What reproduces ✅Telemetry now starts strictly after the
The latency win reproduces, at roughly 2/3 the size the PR reports (expected — this host is faster than the 2 vCPU validation box even when pinned): Tests / lint / types. The new tests are not vacuous — 6 of 7 one-line mutations of the PR source turn the new test red: 2. Finding — ACP children now emit zero metrics 🔴This is the one blocking item. Same ACP child, telemetry enabled, Mechanism.
Result: for the whole process lifetime an ACP child records no metrics at all. Spans are unaffected (trace API has a proxy), which is why This is the exact hazard the repo already documents for the daemon path —
Blast radius: every ACP child — Causal proof, not inference. I rebuilt two more bundles from the PR source (columns 3 and 4 above):
The fix I verified: initializeRequestId = undefined;
if ('result' in message) {
- void initializeTelemetry(config);
+ void initializeTelemetry(config).then(() => {
+ registerAcpEventLoopLagGauge(() => eventLoopMonitor.snapshot());
+ });
}…with the unconditional call at line 2738 removed. (Optional hardening for the underlying trap: have 3. Smaller notesa. b. Test gap ( c. Design-doc precision. The doc says cleanup "does not promise to flush that in-flight SDK". True, but the reason is worth naming: 4. Not covered hereWindows runtime behaviour; live prompts against real providers; OTLP/gRPC exporter paths (I used Recommendation: fix §2 (one-line move, verified above), then this is good to merge — the deferral itself is correct, well-tested, and the latency win is real. 中文完整版本地验证报告 —— 真实构建产物 + 真实 ACP 客户端我把两侧都从源码构建成 release bundle,并用真正的 ACP 客户端( 结论:机制本身是对的,收益也复现了 —— 但本 PR 会让 ACP 子进程的 OpenTelemetry metrics 全部静默失效。 需要挪动一行;其余部分都没问题。
1. 可以复现的部分 ✅telemetry 确实推迟到
延迟收益复现了,幅度约为 PR 所报数字的 2/3(符合预期:即使 pin 到 2 核,这台机器仍比对方的 2 vCPU 验证机快):BASE P50/P95 = 1151.3 / 1161.9 ms,PR = 1123.1 / 1131.3 ms,P50 −28.2 ms,配对中位数 −29.3 ms,20/20 组 PR 更快。 测试 / lint / 类型。 新增测试不是空转 —— 对 PR 源码做的 7 个单行变异中有 6 个能让新测试变红(见截图 4)。 2. 问题 —— ACP 子进程现在一条 metric 都发不出来 🔴这是唯一的阻塞项。同一个 ACP 子进程、开启 telemetry、
成因。
结果:ACP 子进程在整个生命周期内一条 metric 都不会产生。span 不受影响(trace API 有 proxy),所以 仓库其实已经为 daemon 路径记录过同一个陷阱 ——
影响范围: 所有 ACP 子进程 —— 这是因果验证,不是推断。 我从 PR 源码另外构建了两个 bundle(上表第 3、4 列):
我验证过的修法: initializeRequestId = undefined;
if ('result' in message) {
- void initializeTelemetry(config);
+ void initializeTelemetry(config).then(() => {
+ registerAcpEventLoopLagGauge(() => eventLoopMonitor.snapshot());
+ });
}同时删掉 2738 行处的无条件调用。(针对底层陷阱的可选加固:让 3. 次要问题a. b. 测试覆盖缺口( c. 设计文档的措辞。 文档说清理逻辑"不保证 flush 尚未完成的 SDK"。这个结论正确,但原因值得写明: 4. 未覆盖Windows 运行时行为;针对真实 provider 的 live prompt;OTLP/gRPC exporter 路径(我用的是 建议: 修掉第 2 节的问题(一行位置调整,已验证),之后即可合入 —— 推迟机制本身是正确的、测试扎实,延迟收益也是真实的。 |
Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
|
@wenshao Addressed the review findings in
Validation on the pushed commit:
The PR description and #7264 candidate 2 entry now contain the corrected final measurements and explicit tradeoffs. |
qwen-code-ci-bot
left a comment
There was a problem hiding this comment.
— qwen3.7-max via Qwen Code /review
|
@qwen-code /triage |
|
Triage re-run completed without a new review. The stage comments above were updated with the latest result. View workflow run. |
Code Review —
|
| return; | ||
| } | ||
| if ( | ||
| direction !== 'sent' || |
There was a problem hiding this comment.
[Suggestion] Good fix moving registerAcpEventLoopLagGauge behind initializeTelemetry — prevents registering on a cached no-op meter. If initializeTelemetry rejects, the gauge silently never registers. Consider a .catch that logs a warning, so a telemetry SDK failure is at least visible in stderr rather than silently disabling metrics.
— qwen3.8-max-preview via Qwen Code /review
yiliang114
left a comment
There was a problem hiding this comment.
LGTM. Clean deferral using transport-level write confirmation — no timing assumptions. Event-loop gauge moving behind SDK init fixes the cached no-op meter issue. Tests cover all edge cases (no start on receipt/unrelated/error, start only on matching success). Design doc with benchmark data is thorough (-44ms P50 on channel.initialize). One inline nit on adding a .catch for telemetry rejection visibility.
— qwen3.8-max-preview via Qwen Code /review




What this PR does
This PR defers telemetry SDK initialization in ACP children until the successful protocol
initializeresponse has been written to stdout. The existing NDJSON transport observation boundary records the incoming initialize request ID and starts the existing single-flight telemetry facade only after the matching result is sent.Other startup modes retain their current behavior: ordinary interactive TUI startup still defers telemetry until after first paint, prompt-interactive and headless modes initialize eagerly, and the daemon parent keeps its existing deferred runtime initialization.
Why it's needed
ACP previously started telemetry from the bootstrap
Configconstructor. Although initialization is fire-and-forget, loading and evaluating the telemetry implementation and exporter chain competes with ACP bootstrap work on the same event loop and CPU. On the constrained 2-vCPU validation host, moving that work behind the protocol boundary reducedchannel.initializeP50 by 43.8 ms and its paired median by 44.2 ms across 30 alternating cold pairs. Cold process-to-first-session time did not show a statistically demonstrated change, so this PR claims a direct ACP initialization improvement rather than a broader end-to-end startup reduction.Reviewer Test Plan
How to verify
Run the focused CLI configuration and ACP agent tests and confirm telemetry is deferred for ACP, does not start on receipt, unrelated responses, agent-to-client requests with a colliding ID, or rejected initialization, and starts exactly once after a matching successful response. Confirm the ACP event-loop gauge is not registered until telemetry initialization settles. Run the ACP NDJSON transport tests and confirm sent observations occur only after the underlying write succeeds and do not run when it rejects. Build and type-check the workspace, then start a bundled ACP child with outfile telemetry enabled: a successful initialize response should be emitted before telemetry starts, while EOF before initialize should exit cleanly without creating telemetry output. After creating a session and waiting for one metric export interval, both the session counter and ACP event-loop lag gauge should appear in the outfile.
Observed validation: 593 focused CLI tests passed, 11 ACP transport tests passed, focused ESLint and Prettier checks passed, and the full workspace build and typecheck passed. A release-bundle smoke using the official ACP client waited past the metric export interval and confirmed both
qwen-code.session.countandqwen-code.acp.event_loop.lagare exported after deferred initialization. On Linux, 30 alternating cold pairs improvedchannel.initializefrom 942.1 / 1245.0 ms to 898.3 / 1002.4 ms P50/P95; cold process-to-first-session changed from 1833.1 / 2190.6 ms to 1845.5 / 2417.0 ms, with a +13.8 ms paired median whose bootstrap 95% interval (-2.8 to +27.5 ms) crossed zero. The same run's 30-pair preheated phase improved initialization P50 by 42.1 ms while its process-to-session paired median was +1.0 ms. All 120 telemetry-enabled benchmark runs produced valid profiles and non-empty outfiles. Concurrency, telemetry-disabled, legacy single-session, early-disconnect, cleanup, and two live-prompt smoke checks passed without residual processes.Evidence (Before & After)
N/A — no TUI or other user-visible rendering changes.
Tested on
Environment (optional)
macOS local workspace with Node.js 22 for unit tests, lint, formatting, build, typecheck, and bundled ACP smoke tests. Linux 6.6 x64 host with 2 vCPUs, approximately 3.5 GiB RAM, no swap, and bundled Node.js 22.23.1 for the 2C4G benchmark, functional matrix, and live-prompt smoke tests.
Risk & Scope
qwen-code.authevent and one earlyqwen-code.configevent, are therefore permanently absent from ACP telemetry rather than delayed. If the ACP child exits immediately after the response while initialization is still in flight,Config.shutdown()can skip that in-flight SDK even though the lower-level telemetry shutdown can await it.Linked Issues
Implements candidate 2 from #7264 and contributes to #4748 without closing either tracking issue.
中文说明
本 PR 的改动
本 PR 将 ACP 子进程中的 telemetry SDK 初始化推迟到协议
initialize成功响应已经写入 stdout 之后。实现复用现有 NDJSON 传输层的消息观察边界,记录收到的 initialize 请求 ID,并且只在匹配的 result 发送完成后启动现有的单飞 telemetry 门面。其他启动模式保持现有行为:普通交互式 TUI 仍在首屏渲染后推迟启动 telemetry,带初始 prompt 的交互模式和 headless 模式仍会提前初始化,daemon 父进程也继续使用现有的延迟运行时初始化。
为什么需要
ACP 之前会从启动
Config构造函数中开始 telemetry。虽然初始化是 fire-and-forget,但加载和执行 telemetry 实现及 exporter 链仍会在同一个事件循环和 CPU 上与 ACP 启动工作竞争。在受限的 2 vCPU 验证机器上,将这部分工作移到协议边界之后,使 30 组交替冷启动中的channel.initializeP50 降低 43.8 ms、配对中位数降低 44.2 ms。冷启动进程到首个 session 的耗时没有显示出统计上已证实的变化,因此本 PR 只声明直接改善 ACP 初始化,不扩大为整体端到端启动收益。Reviewer 测试计划
如何验证
运行聚焦的 CLI 配置和 ACP agent 测试,确认 ACP 会推迟 telemetry,在收到请求、无关响应、ID 碰撞的 agent 到 client 请求或初始化被拒绝时不会启动,并且仅在匹配的成功响应之后启动一次。确认 ACP event-loop gauge 在 telemetry 初始化完成前不会注册。运行 ACP NDJSON 传输测试,确认 sent 观察只在底层写入成功后发生,写入失败时不会触发。构建整个工作区并执行类型检查,然后在开启 outfile telemetry 的情况下启动打包后的 ACP 子进程:成功的 initialize 响应应先于 telemetry 启动发出,而 initialize 前收到 EOF 时应干净退出且不创建 telemetry 输出。创建 session 并等待一个指标导出周期后,session counter 和 ACP event-loop lag gauge 都应出现在 outfile 中。
实际验证结果:593 个聚焦 CLI 测试通过,11 个 ACP 传输测试通过,聚焦 ESLint 和 Prettier 检查通过,完整工作区 build 和 typecheck 通过。使用官方 ACP client 的 release bundle 冒烟测试等待超过 metric 导出间隔后,确认延迟初始化后
qwen-code.session.count和qwen-code.acp.event_loop.lag均能导出。在 Linux 上,30 组交替冷启动使channel.initializeP50/P95 从 942.1 / 1245.0 ms 降至 898.3 / 1002.4 ms;冷启动进程到首个 session 从 1833.1 / 2190.6 ms 变为 1845.5 / 2417.0 ms,其配对中位数为 +13.8 ms,但 bootstrap 95% 区间(-2.8 到 +27.5 ms)跨过 0。同一次测试的 30 组预热阶段使初始化 P50 降低 42.1 ms,而进程到 session 的配对中位数为 +1.0 ms。120 次开启 telemetry 的基准运行均生成有效 profile 和非空 outfile。并发、关闭 telemetry、旧版单 session、提前断开、清理以及两次真实 prompt 冒烟检查均通过,且没有残留进程。证据(改动前后)
N/A——没有 TUI 或其他用户可见的渲染变化。
测试平台
环境(可选)
macOS 本地工作区使用 Node.js 22 完成单元测试、lint、格式检查、build、typecheck 和打包 ACP 冒烟测试。Linux 6.6 x64 主机使用 2 vCPU、约 3.5 GiB 内存、无 swap 和打包 Node.js 22.23.1,完成 2C4G 基准、功能矩阵和真实 prompt 冒烟测试。
风险与范围
qwen-code.auth事件和一条较早的qwen-code.config事件,会永久缺失于 ACP telemetry,而不只是延迟。如果 ACP 子进程在响应后、初始化仍进行时立即退出,即使底层 telemetry shutdown 能等待初始化,Config.shutdown()仍可能跳过这个进行中的 SDK。关联 Issue
实现 #7264 的 candidate 2,并推进 #4748,但不关闭这两个跟踪 issue。