perf(core): Add session start profiler - #6349
Merged
Merged
Conversation
Add an opt-in internal profiler for GeminiClient.startChat so session initialization can be broken down by bounded stages before choosing the next #6312 optimization. The profiler writes best-effort JSONL records only when QWEN_CODE_PROFILE_SESSION_START=1 and avoids sensitive values such as prompts, paths, session IDs, hook output, model responses, and tool names. Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
wenshao
marked this pull request as ready for review
July 5, 2026 17:02
Collaborator
|
Thanks for the PR! (Re-run — post-maintainer-feedback review.) Template looks good ✓ Problem: Well-evidenced measurement need. Issue #6312 tracks per-session overhead reduction, and this profiler provides the stage-level breakdown needed to choose the next optimization target. A prior 12-iteration measurement already identified Direction: Aligned. Performance profiling of session startup is squarely within scope ( Approach: Scope is tight — one new module (248 lines), targeted integration into Size note: ~897 lines across core paths, bulk is test coverage (~535 lines), source change is 248 lines. A maintainer has already engaged with specific code review feedback and the author has addressed it across multiple commits — the gate's purpose (maintainer oversight) is served. Feedback addressed since last run:
Moving to final verdict. 🔍 中文说明感谢贡献！（Re-run——maintainer 反馈修复后复查。） 模板完整 ✓ 问题：有充分证据的测量需求。#6312 跟踪 per-session 开销优化，这个 profiler 提供阶段级拆解。此前 12 轮测量已定位 方向：对齐。Session startup 性能分析在 scope 内。profiler 为 opt-in，输出有边界的 JSONL，不含敏感数据，禁用时零开销。 方案：范围紧凑——一个新模块（248 行）、精准集成、完整测试（14 个专项 + 8 个新 client 测试）。无无关改动。 已修复反馈： 进入最终判定 🔍 — Qwen Code · qwen3.7-max |
Collaborator
Code Review(Re-run — full re-evaluation after maintainer feedback addressed.) Maintainer's critical finding — resolved ✓ @wenshao flagged that Review suggestions — addressed:
Remaining review suggestions (lower priority, non-blocking):
Reuse check: No issues. The profiler is a purpose-built module with a factory pattern (disabled singleton + enabled class). No pre-existing profiling utility was duplicated. No critical blockers or AGENTS.md violations found. Test ResultsCI on ubuntu-latest (Node 22.x) passed — 9m23s runtime. Coverage: Core 85.34% lines. The profiler-specific test suite (14 tests in Real-Scenario NoteThis is a non-TUI change — an internal profiler activated only by — Qwen Code · qwen3.7-max |
Contributor
Code Coverage Summary
CLI Package - Full Text ReportCore Package - Full Text ReportFor detailed HTML reports, please see the 'coverage-reports-22.x-ubuntu-latest' artifact from the main CI run. |
Collaborator
|
(Re-run — final verdict after all maintainer feedback addressed.) Stepping back: this PR adds an opt-in session startup profiler to help #6312's next optimization decision. The maintainer (@wenshao) flagged a critical issue — The maintainer's follow-up review suggestions were also partially addressed across new commits: double-finish idempotency test, throwing timeSync preservation test, debug breadcrumb on write failure, and stage rename. The remaining suggestions (error-code helper reuse, activation log, My independent proposal for this problem would have been essentially the same: a factory returning a no-op or enabled profiler, The profiler does one thing well and costs nothing when disabled. The integration into This is ready to ship. 中文说明（Re-run——所有 maintainer 反馈已修复后的最终判定。） 回顾：maintainer (@wenshao) 指出了 critical 问题—— 后续 review 建议也部分修复：double-finish 幂等性测试、throwing timeSync 保留测试、写入失败的 debug breadcrumb、阶段重命名。剩余建议（error-code helper 复用、启用日志、 我的独立方案与此基本一致：工厂返回 no-op 或 enabled profiler， profiler 只做一件事，禁用时零开销。集成精准，测试全面。CI 通过。可以合入。 — Qwen Code · qwen3.7-max |
qwen-code-ci-bot
previously approved these changes
Jul 5, 2026
qwen-code-ci-bot
left a comment
qwen-code-ci-bot
left a comment
Collaborator
There was a problem hiding this comment.
LGTM, looks ready to ship. ✅
qwen-code-ci-bot
added
category/performance
wenshao
requested changes
Jul 5, 2026
Collaborator
Suggestions — commit
|
| File | Issue | Suggested fix |
|---|---|---|
session-start-profiler.ts:80-93 |
assertSafeExistingProfileFile never tests the append happy path (second session same day) — only ENOENT and symlink branches are covered |
Add a test creating a real JSONL file, then running a second profiler that appends to the same file |
client.ts:1357 |
finishProfile(false) with non-zero partial counts untested — all failure tests fail before deferredReminderCount/snapshotEntries are populated |
Add a test where setTools rejects, asserting non-zero partial metadata |
session-start-profiler.ts:80-93 |
Inline error-code narrowing (typeof error === 'object' && 'code' in error) should use isNodeError() from ../utils/errors.js for consistency |
Import and use isNodeError() for both assertSafeExistingProfileFile and finish() catch blocks |
session-start-profiler.ts:213-218 |
finish() catch logs at debug level without target path or directory context — operators diagnosing profiling failures lack key info |
Log at warn level and include source and output directory in the log payload |
session-start-profiler.ts:237-248 |
No activation log when profiler is enabled — misspelled env var is indistinguishable from write failure | Emit debugLogger.info('session-start-profiler enabled', { source }) on creation |
session-start-profiler.ts:197 |
totalMs covers wall-clock while stages covers only profiled callbacks — the gap is undocumented |
Add unattributedMs field or a JSDoc comment explaining sum(stages) <= totalMs |
session-start-profiler.ts:57-64 |
O_APPEND | O_NOFOLLOW may silently disable O_NOFOLLOW on Linux — the lstatSync check still provides TOCTOU protection, but the kernel-level guard is weaker than intended |
Drop O_APPEND, use lseek(fd, 0, SEEK_END) + write() instead, or add post-open inode comparison |
— qwen3.7-max via Qwen Code /review
Wrap session-start profiler finish metadata collection in the same best-effort boundary as record writes, and cover repeat finish plus sync failure handling in tests. Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
Contributor
There was a problem hiding this comment.
Pull request overview
Adds an opt-in, core-internal session-start profiler that records bounded JSONL timing breakdowns for GeminiClient.startChat() when QWEN_CODE_PROFILE_SESSION_START=1 is set, enabling evidence-based optimization work for #6312 without changing normal runtime behavior.
Changes:
- Introduces
createSessionStartProfiler()and a small profiling helper that records static stage timings and bounded aggregate counts to JSONL under the runtime base dir. - Instruments
GeminiClient.startChat()stages (sync + async) and finalizes a profile record on both success and failure paths. - Adds focused unit tests for the profiler helper and
startChat()integration/mocking to ensure correctness and safety boundaries.
Reviewed changes
Copilot reviewed 5 out of 5 changed files in this pull request and generated no comments.
Show a summary per file
| File | Description |
|---|---|
| packages/core/src/core/session-start-profiler.ts | New opt-in profiler helper that records bounded per-stage + total timings to JSONL, swallowing write failures. |
| packages/core/src/core/session-start-profiler.test.ts | Unit tests covering disabled behavior, stage timing capture, error preservation, bounded JSONL output, and finish idempotency. |
| packages/core/src/core/client.ts | Instruments GeminiClient.startChat() with profiling wrappers and ensures finish() runs for both success and error paths. |
| packages/core/src/core/client.test.ts | Adds mocking + assertions to verify startChat() passes correct sources, records expected stage names, and finalizes profiles without changing thrown errors. |
| .qwen/design/2026-07-06-session-start-profiler.md | Design note documenting measurement shape, safety boundaries, and non-goals for the profiler. |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
Deduplicate startChat profile finalization attributes and add coverage for repeated stage duration accumulation. Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
qwen-code-ci-bot
left a comment
qwen-code-ci-bot
left a comment
Collaborator
There was a problem hiding this comment.
— qwen3.7-max via Qwen Code /review
Strengthen session-start profiler tests for first-failure tracking and startChat sync-stage failure finalization. Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
Restrict session-start profiler JSONL output permissions and add review-requested tests for optional fields and first-stage warm failures. Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
qwen-code-ci-bot
left a comment
qwen-code-ci-bot
left a comment
Collaborator
There was a problem hiding this comment.
No critical findings — implementation is clean and well-tested. One minor suggestion below.
— qwen3.7-max via Qwen Code /review
Use the profiler env constant in the JSONL test so the test cannot drift from the runtime gate. Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
Add coverage for fractional session profiler rounding and the absence of session context application timing when SessionStart returns no additional context. 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
qwen-code-ci-bot
left a comment
Collaborator
There was a problem hiding this comment.
— qwen3.7-max via Qwen Code /review
Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
qwen-code-ci-bot
left a comment
qwen-code-ci-bot
left a comment
Collaborator
There was a problem hiding this comment.
Downgraded from Approve to Comment: CI failing (Test (ubuntu-latest, Node 22.x)).
No critical findings — implementation is clean and well-tested. 252 tests pass locally, build/typecheck/lint all clean. Four low-confidence observations noted in terminal review (unprotected this.now() in finally blocks, misleading "write failed" log label, unnecessary ?? 0 on fs.constants, deferredReminderCount timing).
— qwen3.7-max via Qwen Code /review
qwen-code-ci-bot
left a comment
qwen-code-ci-bot
left a comment
Collaborator
There was a problem hiding this comment.
No new review findings. Downgraded from Approve to Comment: CI still running.
Implementation is clean and well-tested — typecheck, eslint, build, and all 252 tests pass. The code has been through multiple thorough review rounds with maintainer approval. No new critical or high-confidence issues found beyond the previously discussed items.
— qwen3.7-max via Qwen Code /review
wenshao
previously approved these changes
Jul 6, 2026
Collaborator
|
@qwne-code /triage |
qwen-code-ci-bot
left a comment
qwen-code-ci-bot
left a comment
Collaborator
There was a problem hiding this comment.
One new suggestion — no critical findings. Implementation is clean and well-tested through 13+ review rounds with maintainer feedback. CI still pending (30 checks).
— qwen3.7-max via Qwen Code /review
Co-authored-by: Qwen-Coder <qwen-coder@alibabacloud.com>
qwen-code-ci-bot
left a comment
qwen-code-ci-bot
left a comment
Collaborator
There was a problem hiding this comment.
qwen-code-ci-bot
left a comment
qwen-code-ci-bot
left a comment
Collaborator
There was a problem hiding this comment.
No new review findings. Downgraded from Approve to Comment: CI still running.
Implementation is clean and well-tested through 15+ review rounds with maintainer feedback. Typecheck (tsc) and linter (eslint) pass with 0 findings, build succeeds, and all 255 tests pass. The profiler module has comprehensive test coverage including sync/async error paths, symlink protection, double-finish guards, and sensitive-field exclusion.
— qwen3.7-max via Qwen Code /review
Collaborator
|
@qwne-code /triage |
Collaborator
✅ Maintainer verification — Linux end-to-end (covers the untested matrix row)I built real tests for this PR in an isolated worktree off Verdict: LGTM. The env gate, bounded & non-sensitive output, best-effort write, symlink-attack defense, and restrictive permissions all hold on Linux, and a disabled session is unaffected (no output, no high-res clock read). 1) Focused unit tests — 255/255 on Linux
The two symlink defenses are gated 2) Real session under tmux — profiler ON writes one bounded recordBooted the real TUI ( {"timestamp":"2026-07-07T04:21:13.676Z","source":"startup","ok":true,"totalMs":46.78,"stages":{"tool_registry_warm":38.04,"resume_deferred_tool_reveal":0.04,"deferred_reminder_setup":0.2,"initial_chat_history":5.85,"skill_reminder_seed":0.03,"agent_reminder_seed":1.21,"system_instruction":0.64,"gemini_chat_construct":0.08,"orphan_tool_use_repair":0.09,"session_start_hook":0.07,"set_tools":0.32},"extraHistoryLength":0,"historyLength":1,"snapshotEntryCount":9,"deferredReminderCount":46}Stage breakdown (sorted, % of Useful signal for #6312: on a realistic project (46 deferred tools, 9 skills) 3) Env gate (A/B) — disabled = zero outputSame session, only difference is the env var: 4) Output is bounded & non-sensitiveThe record contains only static field/stage names + numbers. Extracting every string value in the JSON tree yields just the timestamp and the static source enum: 5) Restrictive permissions (POSIX)6) Symlink-attack defense at runtime (O_NOFOLLOW + lstat) — on the real write pathPlanted a symlink at the exact target filename pointing at a secret file, then ran a real profiled session: Environment
Scope noteThis verifies the runtime behavior/safety claims end-to-end on Linux. It does not re-review every line, and (per the PR's own scope) does not benchmark an end-to-end 中文版（合并参考）✅ 维护者验证 —— Linux 端到端（补齐未测的矩阵行）我在 结论：LGTM。 环境变量开关、有边界且非敏感的输出、best-effort 写入、符号链接攻击防御、受限权限在 Linux 上全部成立；关闭时会话行为完全不受影响（不写文件、不读高精度时钟）。 1) 聚焦单测 —— Linux 上 255/255
2) tmux 下真实会话 —— 开启 profiler 会写出一条有边界的记录 3) 开关 A/B —— 关闭即零输出 4) 输出有边界且不含敏感信息 5) 受限权限（POSIX） 6) 运行期符号链接攻击防御（O_NOFOLLOW + lstat）—— 在真实写入路径上 环境： 范围说明：本次在 Linux 上端到端验证的是运行期行为/安全；未逐行复审，也（按 PR 自身范围）未对 |
wenshao
approved these changes
Jul 7, 2026
Collaborator
|
@qwen-code /triage |
Collaborator
|
Thanks for the PR! (Re-run — full re-evaluation after all maintainer feedback addressed.) Template looks good ✓ Problem: This addresses a real, observed measurement gap — #6312 needs per-stage Direction: Aligned. Performance instrumentation gated behind an explicit opt-in env var ( Size: 340 production lines ( Approach: Scope is tight. The profiler is a single-purpose module with a clean disabled/enabled split. The Moving on to code review. 🔍 中文说明感谢贡献！（重新运行——在所有 maintainer 反馈已处理后的完整重新评估。） 模板完整 ✓ 问题：这是真实存在的测量缺口——#6312 需要 方向：对齐。通过显式 opt-in 环境变量控制的性能 instrumentation 是低风险、高价值的补充，直接为 #6312 的后续工作提供数据支撑。 规模：340 行生产代码，797 行测试代码，35 行设计文档。低于 500 行生产代码阈值——无需升级。 方案：范围紧凑。profiler 是单一用途模块，disabled/enabled 分离清晰。 进入代码审查 🔍 — Qwen Code · qwen3.7-max |
Collaborator
Code Review(Re-run — full re-evaluation after all maintainer feedback addressed.) Independent proposal: To add opt-in session start profiling, I would create a standalone profiler module with a factory that returns either a real or no-op implementation based on an env var. The profiler would wrap Comparison with the PR: The PR's approach matches this proposal closely. The Reuse check: No existing profiling utility in the repo covers this use case. The implementation uses only Node stdlib ( Findings: No critical blockers. The two previously-flagged criticals are fully resolved:
Test coverage is thorough: 19 dedicated profiler tests + 9 new client integration tests covering success, failure, partial-count, and env-var gating scenarios. Real-Scenario Testing (Linux)Unit testsBuild, typecheck, lintAll pass cleanly — Profiler ENABLED (tmux)Permissions: 700 (dir), 600 (file) ✓. Output bounded — only static stage names + numbers, no prompts/paths/session IDs. Profiler DISABLED (tmux)No profiler directory created when env var is unset. Session runs identically. ✓ 中文说明代码审查（重新运行——在所有 maintainer 反馈已处理后的完整重新评估。） 独立方案： 我会创建一个独立的 profiler 模块，基于环境变量返回真实或空实现。profiler 用 timing wrapper 包裹 与 PR 对比： PR 的方案与此高度一致。 发现： 无关键阻断。此前标记的两个关键问题已完全修复。测试覆盖充分：19 个专项 profiler 测试 + 9 个新 client 集成测试。 实测（Linux）
— Qwen Code · qwen3.7-max |
Collaborator
|
(Re-run — final verdict after all maintainer feedback addressed.) Stepping back: this is a well-scoped, well-tested instrumentation PR that does exactly what it says — adds an opt-in profiler so the next optimization for #6312 can be chosen from measured evidence rather than guesswork. The maintainer's Linux verification independently confirmed every behavioral and security claim, including the POSIX-only hardening paths. The two critical issues from the initial review (error escaping My independent proposal (standalone module + wrapper insertions + best-effort writes) matches the PR's approach closely. The implementation is clean enough that I wouldn't curse the author in six months — I'd thank them for the stage breakdown data. The tmux tests confirm: profiler ON writes bounded JSONL with correct permissions; profiler OFF is a complete no-op. 255/255 unit tests pass. Build, typecheck, and lint are clean. No concerns remaining. Approving. 中文说明（重新运行——在所有 maintainer 反馈已处理后的最终决定。） 退后来看：这是一个范围明确、测试充分的 instrumentation PR，完全兑现了描述——添加 opt-in profiler，让 #6312 的下一步优化能基于实测数据而非猜测来选择。维护者在 Linux 上的独立验证确认了所有行为和安全声明，包括仅 POSIX 的加固路径。 初始审查的两个关键问题（error 逃逸 tmux 测试确认：profiler 开启写出有边界的 JSONL，权限正确；profiler 关闭是完全的 no-op。255/255 单测通过。Build、typecheck、lint 全部干净。 无剩余顾虑。批准。 — Qwen Code · qwen3.7-max |
qwen-code-ci-bot
approved these changes
Jul 7, 2026
qwen-code-ci-bot
left a comment
qwen-code-ci-bot
left a comment
Collaborator
There was a problem hiding this comment.
LGTM, looks ready to ship. ✅
This was referenced Jul 7, 2026
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
What this PR does
This PR adds an opt-in, core-internal profiler for session startup. When
QWEN_CODE_PROFILE_SESSION_START=1is set,GeminiClient.startChat()records bounded JSONL stage timings under the runtime output directory so session initialization can be broken down without enabling debug logs or changing normal behavior.The recorded data is intentionally limited to static stage names, source, success state, total and per-stage durations, and small aggregate counts. It avoids prompts, paths, session IDs, model responses, hook output, and tool names.
Why it's needed
Issue #6312 needs the next optimization to be chosen from measured evidence. Recent measurement showed the remaining light-config cost sits inside
GeminiClient.initialize(), but it did not identify whichstartChat()stage dominates. This PR adds the measurement hook needed to decide whether to optimize system instruction construction, initial history assembly, tool syncing, hooks, or another stage.Reviewer Test Plan
How to verify
Run the focused core tests and confirm the profiler helper records only when enabled, preserves errors, swallows output-write failures, and that
startChat()finalizes both success and failure profiles with bounded counts.Optionally run a local initialization with
QWEN_CODE_PROFILE_SESSION_START=1and an isolatedQWEN_RUNTIME_DIR; confirm asession-start-perf/session-start-YYYY-MM-DD.jsonlfile is produced and contains static stage names plus aggregate counts only.Evidence (Before & After)
N/A for UI. Local verification completed with
cd packages/core && npx vitest run src/core/session-start-profiler.test.ts src/core/client.test.tspassing 236 tests,npm run build && npm run typecheckpassing, andnpm run lintpassing. A local 12-iteration profiler run was posted to #6312 and showedsystem_instructionas the dominant light-fixture stage.Tested on
Environment (optional)
Node v22.22.3, npm 10.9.8. Local verification used built dist output and isolated
QWEN_HOME/QWEN_RUNTIME_DIRfor the profiler smoke measurement.Risk & Scope
startChat(), but the helper is disabled unlessQWEN_CODE_PROFILE_SESSION_START=1and performs no file writes or high-resolution clock reads when disabled.GeminiClient.initialize()or implement Part B extension caching, Part C skill body lazy-loading, daemon protocol changes, or an end-to-end/sessionlatency benchmark.Linked Issues
Refs #6312
中文说明
What this PR does
这个 PR 增加了一个 core 内部的可选 session startup profiler。设置
QWEN_CODE_PROFILE_SESSION_START=1后，GeminiClient.startChat()会在 runtime output 目录下记录有边界的 JSONL 阶段耗时，这样可以拆解 session 初始化路径，而不需要启用 debug log，也不改变正常行为。记录的数据有意限制在静态阶段名、来源、成功状态、总耗时/阶段耗时以及少量聚合计数。输出不会包含 prompt、路径、session ID、模型响应、hook 输出或工具名。
Why it's needed
#6312 的下一步优化需要基于实测证据选择。最近的测量显示轻配置下剩余成本位于
GeminiClient.initialize()内，但还没有定位到startChat()的具体主耗时阶段。这个 PR 增加所需的测量 hook，用于判断后续应优化 system instruction 构造、initial history assembly、tool syncing、hooks，还是其他阶段。Reviewer Test Plan
How to verify
运行聚焦 core 测试，确认 profiler helper 只在启用时记录、保留原错误、吞掉输出写入失败，并确认
startChat()在成功和失败路径都会用有边界的计数完成 profile。也可以设置
QWEN_CODE_PROFILE_SESSION_START=1并使用隔离的QWEN_RUNTIME_DIR跑一次本地初始化；预期会生成session-start-perf/session-start-YYYY-MM-DD.jsonl，且内容只包含静态阶段名和聚合计数。Evidence (Before & After)
UI 变化不适用。本地验证已完成：
cd packages/core && npx vitest run src/core/session-start-profiler.test.ts src/core/client.test.ts通过 236 个测试，npm run build && npm run typecheck通过，npm run lint通过。一次本地 12 轮 profiler 运行结果已评论到 #6312，显示轻配置 fixture 中system_instruction是主要阶段。Tested on
Environment (optional)
Node v22.22.3，npm 10.9.8。本地验证使用 built dist 输出，并为 profiler smoke measurement 使用隔离的
QWEN_HOME/QWEN_RUNTIME_DIR。Risk & Scope
startChat()内增加了 wrapper 调用，但 helper 只有在QWEN_CODE_PROFILE_SESSION_START=1时才启用；禁用时不会写文件，也不会读取高精度时钟。GeminiClient.initialize()，不实现 Part B extension caching、Part C skill body lazy-loading、daemon protocol changes，也不是端到端/session延迟基准。Linked Issues
Refs #6312