diff --git a/.gitattributes b/.gitattributes index deab5ae88bd..3c21e997137 100644 --- a/.gitattributes +++ b/.gitattributes @@ -9,6 +9,9 @@ *.bash eol=lf Makefile eol=lf +# Windows cmd.exe expects batch installers to be checked out with CRLF. +scripts/installation/install-qwen-standalone.bat text eol=crlf + # Explicitly declare binary file types to prevent Git from attempting to # normalize their line endings. *.png binary diff --git a/.github/release.yml b/.github/release.yml new file mode 100644 index 00000000000..05c7dc55e67 --- /dev/null +++ b/.github/release.yml @@ -0,0 +1,6 @@ +# Configuration for GitHub's automatic release notes generation +# PRs with 'skip-changelog' label will be excluded from release notes +changelog: + exclude: + labels: + - 'skip-changelog' diff --git a/.github/workflows/release.yml b/.github/workflows/release.yml index 59e7dac8361..782c6afe92a 100644 --- a/.github/workflows/release.yml +++ b/.github/workflows/release.yml @@ -57,7 +57,7 @@ jobs: steps: - name: 'Checkout' - uses: 'actions/checkout@de0fac2e4500dabe0009e67214ff5f5447ce83dd' # v6.0.2 + uses: 'actions/checkout@de0fac2e4500dabe0009e67214ff5f5447ce83dd' # v6.0.2 with: ref: '${{ github.event.inputs.ref || github.sha }}' fetch-depth: 0 @@ -89,7 +89,7 @@ jobs: echo "is_dry_run=${is_dry_run}" >> "${GITHUB_OUTPUT}" - name: 'Setup Node.js' - uses: 'actions/setup-node@48b55a011bda9f5d6aeb4c2d9c7362e8dae4041e' # v6.4.0 + uses: 'actions/setup-node@48b55a011bda9f5d6aeb4c2d9c7362e8dae4041e' # v6.4.0 with: node-version-file: '.nvmrc' cache: 'npm' @@ -153,13 +153,13 @@ jobs: steps: - name: 'Checkout' - uses: 'actions/checkout@de0fac2e4500dabe0009e67214ff5f5447ce83dd' # v6.0.2 + uses: 'actions/checkout@de0fac2e4500dabe0009e67214ff5f5447ce83dd' # v6.0.2 with: ref: '${{ github.event.inputs.ref || github.sha }}' fetch-depth: 0 - name: 'Setup Node.js' - uses: 'actions/setup-node@48b55a011bda9f5d6aeb4c2d9c7362e8dae4041e' # v6.4.0 + uses: 'actions/setup-node@48b55a011bda9f5d6aeb4c2d9c7362e8dae4041e' # v6.4.0 with: node-version-file: '.nvmrc' cache: 'npm' @@ -206,13 +206,13 @@ jobs: steps: - name: 'Checkout' - uses: 'actions/checkout@de0fac2e4500dabe0009e67214ff5f5447ce83dd' # v6.0.2 + uses: 'actions/checkout@de0fac2e4500dabe0009e67214ff5f5447ce83dd' # v6.0.2 with: ref: '${{ github.event.inputs.ref || github.sha }}' fetch-depth: 0 - name: 'Setup Node.js' - uses: 'actions/setup-node@48b55a011bda9f5d6aeb4c2d9c7362e8dae4041e' # v6.4.0 + uses: 'actions/setup-node@48b55a011bda9f5d6aeb4c2d9c7362e8dae4041e' # v6.4.0 with: node-version-file: '.nvmrc' cache: 'npm' @@ -247,13 +247,13 @@ jobs: steps: - name: 'Checkout' - uses: 'actions/checkout@de0fac2e4500dabe0009e67214ff5f5447ce83dd' # v6.0.2 + uses: 'actions/checkout@de0fac2e4500dabe0009e67214ff5f5447ce83dd' # v6.0.2 with: ref: '${{ github.event.inputs.ref || github.sha }}' fetch-depth: 0 - name: 'Setup Node.js' - uses: 'actions/setup-node@48b55a011bda9f5d6aeb4c2d9c7362e8dae4041e' # v6.4.0 + uses: 'actions/setup-node@48b55a011bda9f5d6aeb4c2d9c7362e8dae4041e' # v6.4.0 with: node-version-file: '.nvmrc' cache: 'npm' @@ -317,13 +317,13 @@ jobs: steps: - name: 'Checkout' - uses: 'actions/checkout@de0fac2e4500dabe0009e67214ff5f5447ce83dd' # v6.0.2 + uses: 'actions/checkout@de0fac2e4500dabe0009e67214ff5f5447ce83dd' # v6.0.2 with: ref: '${{ github.event.inputs.ref || github.sha }}' fetch-depth: 0 - name: 'Setup Node.js' - uses: 'actions/setup-node@48b55a011bda9f5d6aeb4c2d9c7362e8dae4041e' # v6.4.0 + uses: 'actions/setup-node@48b55a011bda9f5d6aeb4c2d9c7362e8dae4041e' # v6.4.0 with: node-version-file: '.nvmrc' cache: 'npm' @@ -386,6 +386,63 @@ jobs: RELEASE_VERSION: '${{ needs.prepare.outputs.release_version }}' run: 'npm run package:standalone:release -- --version "${RELEASE_VERSION}" --out-dir dist/standalone' + - name: 'Verify Installation Release Assets' + run: 'npm run verify:installation-release -- --dir dist/standalone' + + - name: 'Package Hosted Installation Assets' + env: + RELEASE_VERSION: '${{ needs.prepare.outputs.release_version }}' + run: 'npm run package:hosted-installation -- --out-dir dist/installation --version "${RELEASE_VERSION}"' + + - name: 'Install ossutil' + if: |- + ${{ needs.prepare.outputs.is_dry_run == 'false' }} + env: + OSSUTIL_URL: "${{ vars.OSSUTIL_URL || 'https://gosspublic.alicdn.com/ossutil/1.7.19/ossutil-v1.7.19-linux-amd64.zip' }}" + OSSUTIL_SHA256: "${{ vars.OSSUTIL_SHA256 || 'dcc512e4a893e16bbee63bc769339d8e56b21744fd83c8212a9d8baf28767343' }}" + run: |- + set -euo pipefail + + tmp_dir="$(mktemp -d)" + curl -fsSL --connect-timeout 15 --max-time 300 "${OSSUTIL_URL}" -o "${tmp_dir}/ossutil.zip" + echo "${OSSUTIL_SHA256} ${tmp_dir}/ossutil.zip" | sha256sum -c - + unzip -q "${tmp_dir}/ossutil.zip" -d "${tmp_dir}" + + ossutil_path="$(find "${tmp_dir}" -type f \( -name 'ossutil' -o -name 'ossutil64' \) -print -quit)" + if [[ -z "${ossutil_path}" ]]; then + echo "::error::ossutil binary not found in downloaded archive" + exit 1 + fi + + chmod +x "${ossutil_path}" + mkdir -p "${HOME}/.local/bin" + install -m 0755 "${ossutil_path}" "${HOME}/.local/bin/ossutil" + echo "${HOME}/.local/bin" >> "${GITHUB_PATH}" + rm -rf "${tmp_dir}" + "${HOME}/.local/bin/ossutil" >/dev/null + + - name: 'Configure Aliyun OSS Credentials' + if: |- + ${{ needs.prepare.outputs.is_dry_run == 'false' }} + env: + ALIYUN_OSS_ACCESS_KEY_ID: '${{ secrets.ALIYUN_OSS_ACCESS_KEY_ID }}' + ALIYUN_OSS_ACCESS_KEY_SECRET: '${{ secrets.ALIYUN_OSS_ACCESS_KEY_SECRET }}' + ALIYUN_OSS_ENDPOINT: "${{ vars.ALIYUN_OSS_ENDPOINT || 'https://oss-cn-hangzhou.aliyuncs.com' }}" + run: |- + set -euo pipefail + + if [[ -z "${ALIYUN_OSS_ACCESS_KEY_ID}" || -z "${ALIYUN_OSS_ACCESS_KEY_SECRET}" ]]; then + echo "::error::Missing Aliyun OSS credentials. Set ALIYUN_OSS_ACCESS_KEY_ID and ALIYUN_OSS_ACCESS_KEY_SECRET in the production-release environment secrets." + exit 1 + fi + + ossutil config \ + -e "${ALIYUN_OSS_ENDPOINT}" \ + -i "${ALIYUN_OSS_ACCESS_KEY_ID}" \ + -k "${ALIYUN_OSS_ACCESS_KEY_SECRET}" \ + -L EN \ + -c "${RUNNER_TEMP}/.ossutilconfig" + - name: 'Publish @qwen-code/qwen-code' working-directory: 'dist' run: |- @@ -411,21 +468,139 @@ jobs: IS_NIGHTLY: '${{ needs.prepare.outputs.is_nightly }}' IS_PREVIEW: '${{ needs.prepare.outputs.is_preview }}' run: |- + set -euo pipefail + PRERELEASE_FLAG="" if [[ "${IS_NIGHTLY}" == "true" || "${IS_PREVIEW}" == "true" ]]; then PRERELEASE_FLAG="--prerelease" fi + mapfile -t release_assets < <(node scripts/verify-installation-release.js --dir dist/standalone --list-release-asset-paths) + gh release create "${RELEASE_TAG}" \ dist/cli.js \ - dist/standalone/qwen-code-* \ - dist/standalone/SHA256SUMS \ + "${release_assets[@]}" \ --target "${RELEASE_BRANCH}" \ --title "Release ${RELEASE_TAG}" \ --notes-start-tag "${PREVIOUS_RELEASE_TAG}" \ --generate-notes \ ${PRERELEASE_FLAG} + - name: 'Sync Release Assets to Aliyun OSS' + if: |- + ${{ needs.prepare.outputs.is_dry_run == 'false' }} + env: + ALIYUN_OSS_BUCKET: "${{ vars.ALIYUN_OSS_BUCKET || 'qwen-code-assets' }}" + RELEASE_TAG: '${{ needs.prepare.outputs.release_tag }}' + run: |- + set -euo pipefail + + mapfile -t release_assets < <(node scripts/verify-installation-release.js --dir dist/standalone --list-release-asset-paths) + node scripts/upload-aliyun-oss-assets.js \ + --bucket "${ALIYUN_OSS_BUCKET}" \ + --config "${RUNNER_TEMP}/.ossutilconfig" \ + --prefix "releases/qwen-code/${RELEASE_TAG}" \ + "${release_assets[@]}" + + - name: 'Verify Aliyun OSS Release Assets' + if: |- + ${{ needs.prepare.outputs.is_dry_run == 'false' }} + env: + ALIYUN_OSS_PUBLIC_BASE_URL: "${{ vars.ALIYUN_OSS_PUBLIC_BASE_URL || 'https://qwen-code-assets.oss-cn-hangzhou.aliyuncs.com' }}" + RELEASE_TAG: '${{ needs.prepare.outputs.release_tag }}' + run: |- + set -euo pipefail + + npm run verify:installation-release -- --base-url "${ALIYUN_OSS_PUBLIC_BASE_URL}/releases/qwen-code/${RELEASE_TAG}" + + - name: 'Sync Hosted Installation Assets to Aliyun OSS' + if: |- + ${{ needs.prepare.outputs.is_dry_run == 'false' && needs.prepare.outputs.is_nightly == 'false' && needs.prepare.outputs.is_preview == 'false' }} + env: + ALIYUN_OSS_BUCKET: "${{ vars.ALIYUN_OSS_BUCKET || 'qwen-code-assets' }}" + RELEASE_TAG: '${{ needs.prepare.outputs.release_tag }}' + run: |- + set -euo pipefail + + hosted_assets=( + dist/installation/install-qwen-standalone.sh + dist/installation/install-qwen-standalone.ps1 + dist/installation/install-qwen-standalone.bat + dist/installation/uninstall-qwen-standalone.sh + dist/installation/uninstall-qwen-standalone.ps1 + dist/installation/SHA256SUMS + ) + node scripts/upload-aliyun-oss-assets.js \ + --bucket "${ALIYUN_OSS_BUCKET}" \ + --config "${RUNNER_TEMP}/.ossutilconfig" \ + --prefix "installation/${RELEASE_TAG}" \ + "${hosted_assets[@]}" + node scripts/upload-aliyun-oss-assets.js \ + --bucket "${ALIYUN_OSS_BUCKET}" \ + --config "${RUNNER_TEMP}/.ossutilconfig" \ + --prefix "installation" \ + "${hosted_assets[@]}" + + - name: 'Verify Aliyun OSS Hosted Installation Assets' + if: |- + ${{ needs.prepare.outputs.is_dry_run == 'false' && needs.prepare.outputs.is_nightly == 'false' && needs.prepare.outputs.is_preview == 'false' }} + env: + ALIYUN_OSS_PUBLIC_BASE_URL: "${{ vars.ALIYUN_OSS_PUBLIC_BASE_URL || 'https://qwen-code-assets.oss-cn-hangzhou.aliyuncs.com' }}" + RELEASE_TAG: '${{ needs.prepare.outputs.release_tag }}' + run: |- + set -euo pipefail + + hosted_tmp_dir="$(mktemp -d)" + trap 'rm -rf "${hosted_tmp_dir}"' EXIT + mkdir -p "${hosted_tmp_dir}/versioned" "${hosted_tmp_dir}/global" + for asset in install-qwen-standalone.sh install-qwen-standalone.ps1 install-qwen-standalone.bat uninstall-qwen-standalone.sh uninstall-qwen-standalone.ps1 SHA256SUMS; do + url="${ALIYUN_OSS_PUBLIC_BASE_URL}/installation/${RELEASE_TAG}/${asset}" + global_url="${ALIYUN_OSS_PUBLIC_BASE_URL}/installation/${asset}" + curl -fsSL --connect-timeout 15 --max-time 300 "${url}" -o "${hosted_tmp_dir}/versioned/${asset}" + curl -fsSL --connect-timeout 15 --max-time 300 "${global_url}" -o "${hosted_tmp_dir}/global/${asset}" + done + cmp -s "dist/installation/SHA256SUMS" "${hosted_tmp_dir}/versioned/SHA256SUMS" || { + echo "::error::Hosted installation SHA256SUMS does not match local dist/installation/SHA256SUMS" + diff -u "dist/installation/SHA256SUMS" "${hosted_tmp_dir}/versioned/SHA256SUMS" || true + exit 1 + } + cmp -s "dist/installation/SHA256SUMS" "${hosted_tmp_dir}/global/SHA256SUMS" || { + echo "::error::Global hosted installation SHA256SUMS does not match local dist/installation/SHA256SUMS" + diff -u "dist/installation/SHA256SUMS" "${hosted_tmp_dir}/global/SHA256SUMS" || true + exit 1 + } + (cd "${hosted_tmp_dir}/versioned" && sha256sum -c SHA256SUMS) + (cd "${hosted_tmp_dir}/global" && sha256sum -c SHA256SUMS) + + - name: 'Publish Aliyun OSS Latest VERSION' + # Run last so the `latest/VERSION` pointer only flips after every + # release asset and hosted installer object has been uploaded and + # verified. If any earlier step fails, the pointer keeps referring + # to the previously-good release. + if: |- + ${{ needs.prepare.outputs.is_dry_run == 'false' && needs.prepare.outputs.is_nightly == 'false' && needs.prepare.outputs.is_preview == 'false' }} + env: + ALIYUN_OSS_BUCKET: "${{ vars.ALIYUN_OSS_BUCKET || 'qwen-code-assets' }}" + ALIYUN_OSS_PUBLIC_BASE_URL: "${{ vars.ALIYUN_OSS_PUBLIC_BASE_URL || 'https://qwen-code-assets.oss-cn-hangzhou.aliyuncs.com' }}" + RELEASE_TAG: '${{ needs.prepare.outputs.release_tag }}' + run: |- + set -euo pipefail + + printf '%s\n' "${RELEASE_TAG}" > "${RUNNER_TEMP}/qwen-code-latest-version" + ossutil cp "${RUNNER_TEMP}/qwen-code-latest-version" "oss://${ALIYUN_OSS_BUCKET}/releases/qwen-code/latest/VERSION" -c "${RUNNER_TEMP}/.ossutilconfig" -f --acl public-read + + latest_version="$(curl -fsSL --connect-timeout 15 --max-time 300 "${ALIYUN_OSS_PUBLIC_BASE_URL}/releases/qwen-code/latest/VERSION" | tr -d '[:space:]')" + if [[ "${latest_version}" != "${RELEASE_TAG}" ]]; then + echo "::error::Aliyun latest VERSION points to ${latest_version}, expected ${RELEASE_TAG}" + exit 1 + fi + + - name: 'Cleanup Aliyun OSS Credentials' + if: |- + ${{ always() && needs.prepare.outputs.is_dry_run == 'false' }} + run: |- + rm -f "${RUNNER_TEMP}/.ossutilconfig" + - name: 'Create PR to merge release branch into main' if: |- ${{ needs.prepare.outputs.is_dry_run == 'false' && needs.prepare.outputs.is_nightly == 'false' && needs.prepare.outputs.is_preview == 'false' }} diff --git a/.gitignore b/.gitignore index 6ff1d950be2..9734c670574 100644 --- a/.gitignore +++ b/.gitignore @@ -56,6 +56,9 @@ bundle junit.xml packages/*/coverage/ +# PR body draft +pr_body.md + # Generated files packages/cli/src/generated/ packages/core/src/generated/ diff --git a/docs/design/2026-05-15-async-memory-recall-design.md b/docs/design/2026-05-15-async-memory-recall-design.md new file mode 100644 index 00000000000..f11b2ac5d23 --- /dev/null +++ b/docs/design/2026-05-15-async-memory-recall-design.md @@ -0,0 +1,206 @@ +# Async Memory Recall — Design Spec + +**Date:** 2026-05-15 +**Status:** Approved +**Related issues:** #3761, #3759 +**Related PRs:** #3814, #3866 + +--- + +## Problem + +`relevanceSelector.ts` uses `AbortSignal.timeout(1_000)` (introduced by #3866). On first-session cold starts, qwen3.5-flash averages ~908 ms — consistently hitting the 1 s threshold. The outer 2.5 s deadline in `resolveAutoMemoryWithDeadline` means every UserQuery can block for up to 2.5 s even when recall always fails. + +Root cause: the main-agent request path `await`s the recall result before sending to the model. Any slowness in the recall side-query directly adds to user-visible latency. + +--- + +## Design + +### Core idea + +Fire recall on UserQuery and never await it. Consume the result at two opportunistic points — whichever fires first: + +1. **UserQuery consume point** — synchronous `settledAt !== null` check just before `turn.run()`. Zero-wait: if already settled, use it; if not, skip. +2. **ToolResult inject point** — same check on every ToolResult turn. Injects memory as a `system-reminder` **appended after** the functionResponse parts in `requestToSend`, giving the model memory context before its next response. (Append, not prepend: the Qwen API requires the functionResponse to immediately follow the model's functionCall — see the existing `hasPendingToolCall` IDE-context skip for the same constraint.) + +This matches the pattern used by Claude Code upstream (`startRelevantMemoryPrefetch` / `settledAt` polling in `query.ts`). + +--- + +## Data structures + +### New type `MemoryPrefetchHandle` (in `client.ts`) + +```typescript +type MemoryPrefetchHandle = { + promise: Promise; + /** Set by promise.finally(). null until the promise settles. */ + settledAt: number | null; + /** True after memory has been injected — prevents double-inject. */ + consumed: boolean; + controller: AbortController; +}; +``` + +### Field change on `GeminiClient` + +| Remove | Add | +| ------------------------------------------------------------ | ---------------------------------------------------------- | +| `pendingRecallAbortController: AbortController \| undefined` | `pendingMemoryPrefetch: MemoryPrefetchHandle \| undefined` | + +--- + +## Changes + +### 1. `client.ts` — remove `resolveAutoMemoryWithDeadline` + +Delete the function entirely. It is replaced by the `settledAt` flag mechanism. + +### 2. `client.ts` — UserQuery fire path + +Replace the `resolveAutoMemoryWithDeadline` call with: + +```typescript +// Abort any in-flight prefetch from a previous UserQuery before installing +// the new handle (prevents orphan side-queries when the user types again +// before recall settles). +this.pendingMemoryPrefetch?.controller.abort(); +this.pendingMemoryPrefetch = undefined; + +const controller = new AbortController(); +// Bridge the caller's signal into the prefetch controller so a user abort +// (Ctrl-C / Esc) on the parent turn also terminates the recall side-query. +const onParentAbort = () => controller.abort(); +if (signal.aborted) { + controller.abort(); +} else { + signal.addEventListener('abort', onParentAbort, { once: true }); +} + +const promise = this.config + .getMemoryManager() + .recall(projectRoot, partToString(request), { + config: this.config, + excludedFilePaths: this.surfacedRelevantAutoMemoryPaths, + abortSignal: controller.signal, + }) + .catch((error: unknown) => { + if (!(error instanceof DOMException && error.name === 'AbortError')) { + debugLogger.warn('Managed auto-memory recall prefetch failed.', error); + } + return EMPTY_RELEVANT_AUTO_MEMORY_RESULT; + }); + +const handle: MemoryPrefetchHandle = { + promise, + settledAt: null, + consumed: false, + controller, +}; +void promise.finally(() => { + handle.settledAt = Date.now(); + signal.removeEventListener('abort', onParentAbort); +}); +this.pendingMemoryPrefetch = handle; +// no await — continue immediately +``` + +### 3. `client.ts` — UserQuery consume point (replaces `await relevantAutoMemoryPromise`) + +```typescript +const prefetchHandle = this.pendingMemoryPrefetch; +if ( + prefetchHandle && + prefetchHandle.settledAt !== null && + !prefetchHandle.consumed +) { + prefetchHandle.consumed = true; + this.pendingMemoryPrefetch = undefined; + const result = await prefetchHandle.promise; // already settled, returns immediately + if (result.prompt) { + // unshift, not push: keep memory at the front of systemReminders so + // it leads the system-reminder block on UserQuery turns. (ToolResult + // turns instead append to requestToSend to preserve functionCall / + // functionResponse pairing — see below.) + systemReminders.unshift(result.prompt); + for (const doc of result.selectedDocs) { + this.surfacedRelevantAutoMemoryPaths.add(doc.filePath); + } + } +} +``` + +### 4. `client.ts` — ToolResult inject point (new) + +After `requestToSend` is assembled, before `turn.run()`, add: + +```typescript +if (messageType === SendMessageType.ToolResult) { + const prefetchHandle = this.pendingMemoryPrefetch; + if ( + prefetchHandle && + prefetchHandle.settledAt !== null && + !prefetchHandle.consumed + ) { + prefetchHandle.consumed = true; + this.pendingMemoryPrefetch = undefined; + const result = await prefetchHandle.promise; + if (result.prompt) { + // Append (not prepend) so functionResponse parts stay first + // and the model's functionCall/functionResponse pairing + // isn't broken on the native Gemini path. + requestToSend = [...requestToSend, result.prompt]; + for (const doc of result.selectedDocs) { + this.surfacedRelevantAutoMemoryPaths.add(doc.filePath); + } + } + } +} +``` + +### 5. `client.ts` — cleanup paths + +The handle is released by two distinct mechanisms: + +**5 abort-and-clear sites** (the prefetch is still pending, abort the controller before dropping the reference). Replace `pendingRecallAbortController?.abort()` + `= undefined` with: + +```typescript +this.pendingMemoryPrefetch?.controller.abort(); +this.pendingMemoryPrefetch = undefined; +``` + +Sites: `resetChat()`, `MaxSessionTurns` early-return, `boundedTurns=0` early-return, `SessionTokenLimitExceeded` early-return, Arena control-signal early-return. The fire path itself also performs this abort-then-replace when a new UserQuery arrives while the previous prefetch is still in flight. + +**2 clear-only sites** (the prefetch has already settled and we're consuming it — no controller to abort, just drop the reference): + +```typescript +prefetchHandle.consumed = true; +this.pendingMemoryPrefetch = undefined; +``` + +Sites: UserQuery consume point, ToolResult inject point. + +### 6. `relevanceSelector.ts` — remove `AbortSignal.timeout(1_000)` + +Remove the combined `AbortSignal.any([AbortSignal.timeout(1_000), callerAbortSignal])` and pass `callerAbortSignal` directly. + +--- + +## Behaviour comparison + +| Scenario | Before | After | +| -------------------------------------------- | ------------------------------ | ------------------------------------------------------ | +| recall completes before model prep | inject on UserQuery, ~0 wait | inject on UserQuery, ~0 wait | +| recall slow (cold start) | block up to 2.5 s | skip UserQuery, inject on first ToolResult | +| recall times out (1 s) | abort, empty result, no memory | no hard timeout; inject whenever settled | +| no tool calls, recall slow | block up to 2.5 s, then skip | skip UserQuery, no ToolResult opportunity — miss | +| user sends 2nd message before recall settles | 2nd recall races 1st handle | 1st handle aborted when 2nd UserQuery fires new handle | + +--- + +## Out of scope + +- Changing the memory injection format from `system-reminder` to `tool-result` attachment (CC style) +- Per-session byte budget skip gate +- Single-word prompt skip gate diff --git a/docs/design/auto-compaction-threshold-redesign.md b/docs/design/auto-compaction-threshold-redesign.md new file mode 100644 index 00000000000..79bd6a8afc4 --- /dev/null +++ b/docs/design/auto-compaction-threshold-redesign.md @@ -0,0 +1,418 @@ +# Auto-Compaction Threshold Redesign + +**Status:** Draft · 2026-05-14 + +## 背景 + +当前 qwen-code 的自动压缩仅使用单一比例阈值 `COMPRESSION_TOKEN_THRESHOLD = 0.7`（`chatCompressionService.ts:33`），所有窗口大小共用同一比例。对比 claude-code 的「绝对 token 梯子」（autoCompact.ts:62-65），qwen-code 存在三个具体问题： + +1. **大窗口下预留过多**：1M 模型 70% 阈值在 700K 触发，剩余 300K 远超摘要 + 输出实际所需的 ~33K +2. **失败 1 次永久锁**：`hasFailedCompressionAttempt = true` 之后整个 session 不再尝试 auto-compact（geminiChat.ts:504），比 claude-code 的「连续 3 次熔断」更严苛 +3. **tip 系统与 auto 阈值脱钩**：`tipRegistry.ts` 里的三条 `context-*` tip 使用固定的 50/80/95 百分比，与 auto-compact 阈值（70%）完全独立。这意味着在「auto 正常工作」的主路径上 80% / 95% tip 极少触发，而在「auto 失败 / 反应式兜底」的边缘路径上又缺乏与阈值对齐的语义 +4. **压缩调用本身没有输出预算控制**：[chatCompressionService.ts:374-376](packages/core/src/services/chatCompressionService.ts:374) 显式开启 `thinkingConfig.includeThoughts = true`（注释：「Compression quality drives every subsequent main turn」），同时 sideQuery 调用未设 `maxOutputTokens` 上限。代码注释（[:436-437](packages/core/src/services/chatCompressionService.ts:436)）也承认 `compressionOutputTokenCount may include non-persisted tokens (thoughts)`。在压缩接近窗口顶时，总输出可能膨胀，使 buffer 预留缺乏可预测上限。

更糟糕的是跨 provider 行为不一致：Anthropic 的 thinking budget 与 max_tokens 完全独立；OpenAI 的 reasoning tokens 不受 max_completion_tokens 限制；Gemini 的行为又因模型版本而异。这意味着「单靠加 maxOutputTokens 就能控制总输出」在 qwen-code 这种多 provider 项目里不成立 + +5. **阈值判断使用的 `lastPromptTokenCount` 系统性下偏。** [geminiChat.ts:1217-1232](packages/core/src/core/geminiChat.ts:1217) 表明这个数来自上一轮 API response 的 `usageMetadata.totalTokenCount`。两个 gap：(a) 不包含本轮即将加入的 user message，每次 cheap-gate 判断都比真实 prompt 小一段；(b) 首轮初始值是 0，`--continue` 恢复巨大 session / sub-agent 继承大量历史时第一次 send 永远绕过所有阈值。对比 claude-code 的 `tokenCountWithEstimation`（[query.ts:638](src/query.ts:638)）走「最后一条 assistant API usage + 之后新增 message 估算」的双轨制能闭合这两个 gap + +## 设计目标 + +- 引入「比例 + 绝对」混合阈值，让大窗口模型由绝对值接管，小窗口仍走比例兜底 +- 新增 warn / hard 两层（auto 保留为主触发点），形成三层梯子 +- 把 tip 系统重写为跟随新阈值的触发条件 +- 失败处理从「1 次永久锁」升级为「3 次熔断 + 自动恢复」 +- **压缩调用关闭 thinking 并加 `maxOutputTokens` 上限**：与 claude-code 对齐，让总输出受单一参数约束、buffer 预算可预测；接受压缩质量可能下降的代价 +- **加 token 估算补偿**：消除 `lastPromptTokenCount` 的「滞后一轮」和「首轮为 0」两个系统性下偏，让阈值判断更贴近真实 prompt 大小 +- 删除 settings 里的 `contextPercentageThreshold` 配置入口（内部 PCT 常量保留） +- **不引入** env 覆盖通道、**不**新增显式 enabled 开关 + +## 三层阈值梯子 + +``` + window (raw context window) + │ + │ ← SUMMARY_RESERVE = 20K + ▼ + effectiveWindow + │ + │ ← HARD_BUFFER = 3K + ▼ + hard_threshold = effectiveWindow - 3K + │ + │ ← (AUTOCOMPACT_BUFFER - HARD_BUFFER) = 10K + ▼ +auto_threshold = max(PCT * window, effectiveWindow - AUTOCOMPACT_BUFFER) + │ + │ ← WARN_BUFFER = 20K + ▼ +warn_threshold = max((PCT - WARN_OFFSET) * window, auto_threshold - WARN_BUFFER) + │ + ▼ + 0 +``` + +### 三层语义 + +| 层 | 触发条件 | 行为 | +| -------- | ------------------------------ | -------------------------------------------------------- | +| **warn** | `tokenCount >= warn_threshold` | UI 提示「距自动压缩还剩 X tokens」，不改变 send 行为 | +| **auto** | `tokenCount >= auto_threshold` | 在 send 前 `tryCompress(force=false)`，正常压缩流程 | +| **hard** | `tokenCount >= hard_threshold` | 在 send 前 `tryCompress(force=true)`，重置失败锁强制压缩 | + +`hard` 层等同于把现有 reactive overflow（geminiChat.ts:711）的兜底逻辑提前到 send 前，避免一次失败的 oversized request round-trip。 + +## 内部常量 + +```ts +// chatCompressionService.ts +const DEFAULT_PCT = 0.7; // auto 比例兜底 +const WARN_PCT_OFFSET = 0.1; // warn 比例 = PCT - WARN_OFFSET = 0.6 +const COMPACT_MAX_OUTPUT_TOKENS = 20_000; // 压缩 sideQuery 输出硬上限（thinking + summary 合计） +const SUMMARY_RESERVE = 20_000; // 阈值梯子从窗口顶减去的输出预留 = maxOutput +const AUTOCOMPACT_BUFFER = 13_000; // auto 与 effectiveWindow 间距 +const WARN_BUFFER = 20_000; // warn 与 auto 间距 +const HARD_BUFFER = 3_000; // hard 与 effectiveWindow 间距 +const MAX_CONSECUTIVE_FAILURES = 3; // 失败熔断阈值 +``` + +数值来源：全部沿用 claude-code 的实测值（[autoCompact.ts:30,62-65](src/services/compact/autoCompact.ts:30)）。 + +`SUMMARY_RESERVE = COMPACT_MAX_OUTPUT_TOKENS` 是关键关系：模型受 `maxOutputTokens` 硬限制约束，输出不可能超出 20K，因此 reserve 不需要额外 safety margin。注意：本设计关闭 thinking 后该等式成立（output budget 全部给 summary）；若保留 thinking，`thinking + summary` 共享预算（Gemini SDK / 多数 provider 的 `maxOutputTokens` 语义），模型自行在两者间分配，此时 summary 的实际可用空间小于 20K（见「风险与注意事项」第 1、2 条）。 + +## 计算函数 + +```ts +export interface CompactionThresholds { + warn: number; + auto: number; + hard: number; // 当 hard < auto 时等于 auto（小窗口退化） + effectiveWindow: number; +} + +export function computeThresholds(window: number): CompactionThresholds { + const effectiveWindow = window - SUMMARY_RESERVE; + + const absAuto = effectiveWindow - AUTOCOMPACT_BUFFER; + const auto = Math.max(DEFAULT_PCT * window, absAuto); + + const absWarn = auto - WARN_BUFFER; + const warn = Math.max((DEFAULT_PCT - WARN_PCT_OFFSET) * window, absWarn); + + const rawHard = effectiveWindow - HARD_BUFFER; + const hard = Math.max(rawHard, auto); // 小窗口下退化为 auto + + return { warn, auto, hard, effectiveWindow }; +} +``` + +### 实测数据 + +| 窗口 | warn | auto | hard | 备注 | +| ---- | ----------- | ----------- | ------------ | ------------------------------- | +| 32K | 19.2K (pct) | 22.4K (pct) | 22.4K (退化) | 比例兜底 | +| 64K | 38.4K (pct) | 44.8K (pct) | 44.8K (退化) | 比例兜底 | +| 128K | 76.8K (pct) | 95K (abs) | 105K (abs) | 混合（warn=pct, auto/hard=abs） | +| 200K | 147K (abs) | 167K (abs) | 177K (abs) | 绝对接管 | +| 256K | 203K (abs) | 223K (abs) | 233K (abs) | 绝对接管 | +| 1M | 947K (abs) | 967K (abs) | 977K (abs) | 全绝对 | + +`(pct)` 表示该层由比例公式决定，`(abs)` 表示由绝对值公式决定。 + +## 用户配置 + +### ChatCompressionSettings 变更 + +```ts +// packages/core/src/config/config.ts:217 +export interface ChatCompressionSettings { + /** 保留（与本设计无关，由 compactionInputSlimming 使用） */ + imageTokenEstimate?: number; +} +``` + +**删除：** `contextPercentageThreshold` 字段。理由： + +1. 新公式下，对主流窗口（>= 128K）该字段几乎无影响——绝对值接管 +2. 小窗口下用户配置反而可能让阈值"更早"压缩，与节省 token 直觉相反 +3. claude-code 没有暴露此字段，无类似的用户面配置先例 + +### Breaking change 处理 + +启动时 `Config` 加载发现 `chatCompression.contextPercentageThreshold` 存在： + +- 写入 stderr 一行警告：`"chatCompression.contextPercentageThreshold has been removed and is now controlled by built-in thresholds."` +- **不**报错、**不**阻塞启动 +- 字段值被忽略 + +## Token 估算补偿 + +qwen-code 的 `lastPromptTokenCount` 来自上一轮 API response 的 `usageMetadata.totalTokenCount`（[geminiChat.ts:1217-1232](packages/core/src/core/geminiChat.ts:1217)）。这导致： + +1. **滞后一轮**：cheap-gate 用 `lastPromptTokenCount` 判断，但本次 send 实际 prompt = 它 + 本轮 user message。少算的部分可能让阈值判断 false-negative +2. **首轮为 0**：初始值是 0，第一次 send 时无论历史多大都不会触发任何阈值（含 `--continue` 恢复 / sub-agent 继承场景） + +引入轻量本地估算函数 `estimatePromptTokens`，在 send 前 cheap-gate / hard 判断时补足这两段缺失： + +```ts +// chatCompressionService.ts（或新文件 packages/core/src/services/tokenEstimation.ts） + +const BYTES_PER_TOKEN = 4; // 通用 char/4 估算（claude-code 同此） +const BYTES_PER_TOKEN_JSON = 2; // JSON / tool_call input 更密集 + +/** + * 估算一组 Content 的 token 数，用于补偿 API usage metadata 的滞后。 + * 对 image / document 复用现有 imageTokenEstimate（默认 1600）。 + */ +export function estimateContentTokens( + contents: Content[], + imageTokenEstimate = DEFAULT_IMAGE_TOKEN_ESTIMATE, +): number { + // 复用 estimateContentChars（compactionInputSlimming.ts），再除以 bytesPerToken + // 内部对 functionCall / functionResponse 用 BYTES_PER_TOKEN_JSON + // ... +} + +/** + * cheap-gate 与 hard 判断的统一入口。 + * 主路径：lastPromptTokenCount 准 + 本轮 user message 估算 + * 首轮路径：full history 估算 + */ +export function estimatePromptTokens( + history: Content[], + userMessage: Content, + lastPromptTokenCount: number, +): number { + if (lastPromptTokenCount > 0) { + return lastPromptTokenCount + estimateContentTokens([userMessage]); + } + return estimateContentTokens([...history, userMessage]); +} +``` + +应用位置： + +- `chatCompressionService.compress()` 的 cheap-gate：把 `originalTokenCount` 来源换成 `estimatePromptTokens(history, userMessage, lastPromptTokenCount)` +- `geminiChat.sendMessageStream` 入口的 hard 判断（见下一节） + +**估算只用于提前触发，不用于「跳过触发」。** 因为 char/4 是粗略下界估计，作为 false-positive 一侧是安全的（宁可早一点压），作为 false-negative 则不可靠。 + +## 触发链路改动 + +### chatCompressionService.ts + +1. **导出 `computeThresholds`**，供 cheap-gate / UI / 命令复用 +2. **`compress()` cheap-gate** (line 221-249)： + ```ts + if (consecutiveFailures >= MAX_CONSECUTIVE_FAILURES && !force) { + return NOOP; + } + const { auto } = computeThresholds(contextLimit); + const effectiveTokens = estimatePromptTokens( + curatedHistory, + userMessage, + originalTokenCount, + ); + if (!force && effectiveTokens < auto) return NOOP; + ``` +3. **`compress()` 的 runSideQuery 调用** (line 356-380)：关闭 thinking + 加 `maxOutputTokens`： + + ```ts + const summaryResult = await runSideQuery(config, { + // ... + config: { + thinkingConfig: { includeThoughts: false }, // 关闭 thinking（与 claude-code 一致） + maxOutputTokens: COMPACT_MAX_OUTPUT_TOKENS, // 硬上限 20K + }, + // ... + }); + ``` + + 或者直接删掉 `thinkingConfig` 让 `runSideQuery` 默认值（[sideQuery.ts:118](packages/core/src/utils/sideQuery.ts:118) 默认 `includeThoughts: false`）接管。 + + 关 thinking 后，`maxOutputTokens` 直接约束总输出（不存在 thinking 单独 budget 的问题），`SUMMARY_RESERVE = maxOutput = 20K` 是干净的硬关系。 + + 同时更新 [chatCompressionService.ts:374-376](packages/core/src/services/chatCompressionService.ts:374) 的注释，从「Compression quality drives every subsequent main turn — keep reasoning on」改为说明「为保证跨 provider 可预测的输出上限，与 claude-code 设计对齐」。 + + token math 一段（[:436-437](packages/core/src/services/chatCompressionService.ts:436)）的 "may include non-persisted tokens (thoughts)" 注释也可以同步清理 + +### geminiChat.ts: `sendMessageStream` 入口（line 562） + +```ts +// 替换前：tryCompress(force=false) +// 替换后：用估算 token 判断是否触发 hard，决定 force 标志 + +const { hard } = computeThresholds(contextLimit); +const effectiveTokens = estimatePromptTokens( + this.getHistory(true), + createUserContent(params.message), + this.lastPromptTokenCount, +); +const shouldForceFromHard = effectiveTokens >= hard; + +if (shouldForceFromHard) { + // 重置熔断器，等同 force compress + this.consecutiveFailures = 0; +} + +compressionInfo = await this.tryCompress( + prompt_id, + model, + shouldForceFromHard, + params.config?.abortSignal, +); +``` + +### 失败处理升级 (`geminiChat.ts:504-510`) + +```ts +// 替换前 +hasFailedCompressionAttempt: boolean; + +// 替换后 +consecutiveFailures: number; // 默认 0 + +// 失败分支 +} else if (isCompressionFailureStatus(info.compressionStatus)) { + if (!force) { + this.consecutiveFailures += 1; + } +} + +// 成功分支 +this.consecutiveFailures = 0; +``` + +`force=true` 调用失败不计入计数（保持现有 reactive / manual 不"占额"的语义）。 + +## UI 改动 + +### tipRegistry.ts 重写三条 context-\* tip + +三层阈值正好与三条 tip 一一对应。映射关系（按 token 数从低到高）： + +| Tip ID | 当前条件 | 新条件 | 文案变化 | +| ------------------ | --------------------------------------------- | ------------------------------------------------------------------- | ----------------------------------------------------------------- | +| `compress-intro` | `pct >= 50 && < 80 && sessionPromptCount > 5` | `tokenCount >= warn && tokenCount < auto && sessionPromptCount > 5` | 保持不变 | +| `context-high` | `pct >= 80 && < 95` | `tokenCount >= auto && tokenCount < hard` | 保持不变 | +| `context-critical` | `pct >= 95` | `tokenCount >= hard` | 加一句「Auto-compact will force on next send.」反映新 hard 层行为 | + +**对触发频率的影响：** + +- 主路径（auto 正常工作）：`tokenCount` 跨越 auto 后立即触发压缩，下一轮 tokenCount 回落，所以 `context-high` 仅在「触发到压缩生效之间」短暂可见 +- 边缘路径（auto 失败 / 熔断 / reactive 来不及）：`tokenCount` 持续上涨，会依次穿过 warn → auto → hard 触发三条 tip，跟用户视角的"上下文越来越紧"一致 +- `context-critical` 触发时 hard 层已经在 send 前 force compress（spec 触发链路改动一节），所以这条 tip 实际上是「post-rescue 告知」而非「pre-rescue 警告」，文案补一句说明 + +`TipContext` 接口增加： + +```ts +export interface TipContext { + lastPromptTokenCount: number; + contextWindowSize: number; + sessionPromptCount: number; + sessionCount: number; + platform: string; + // 新增：让 isRelevant 函数能拿到阈值。 + // computeThresholds 在调用方算好后注入，避免 tipRegistry 直接依赖 core。 + thresholds?: CompactionThresholds; +} +``` + +`AppContainer.tsx:1150` 构造 `TipContext` 时同步注入。 + +### /context 命令同步 (`contextCommand.ts:177-183`) + +```ts +// 替换硬编码 (1 - threshold) * contextWindowSize +const { warn, auto, hard, effectiveWindow } = + computeThresholds(contextWindowSize); + +// 显示四行： +// Effective window: 180K (window − 20K reserve) +// Warn threshold: 147K (...) +// Auto threshold: 167K ← 当前位置 +// Hard threshold: 177K +// 标记当前 token count 落在哪个 tier +``` + +### Footer 持续提示（可选 follow-up） + +本 spec 不强制实现 footer 持续提示，理由： + +- 现有 tip 系统已经能在 history 里给出提示 +- Footer 持续提示需要改 ink 渲染、增加重绘频率 +- 可作为本 spec 后置 follow-up（独立 PR） + +如果后续要做，建议触发条件 `tokenCount >= warn && tokenCount < auto`，超过 auto 后隐藏（压缩已开始）。 + +## 测试覆盖 + +### 单元测试（chatCompressionService.test.ts） + +- `computeThresholds(32K)` → 比例兜底分支（warn/auto 均 pct，hard 退化） +- `computeThresholds(128K)` → 混合分支（warn=pct，auto=abs，hard=abs） +- `computeThresholds(200K)` → 绝对接管分支（warn/auto/hard 均 abs） +- `computeThresholds(1M)` → 全绝对分支 +- `computeThresholds(window=10K)` → 极小窗口（绝对值全负），公式不崩 +- 三层阈值始终满足 `warn <= auto <= hard` +- max() 公式在边界点（pct \* window == abs）稳定 + +### 单元测试（tokenEstimation.test.ts） + +- `estimateContentTokens` 对纯文本 / json / functionCall / functionResponse / image / document 分别走对应 bytesPerToken +- `estimatePromptTokens` 在 `lastPromptTokenCount > 0` 时走「主路径」，等于 0 时走「首轮路径」 +- 大 user message 在 cheap-gate 阶段被加上去后能跨越 auto 阈值 +- 估算与真实 API usage 的偏差在 ±30% 以内（用真实历史样本回归） + +### 集成测试（geminiChat.test.ts / chatCompressionService.test.ts） + +- 3 次连续失败后 cheap-gate NOOP；下一次 force 后恢复 +- 单次失败不再永久锁 +- 估算 token 跨越 hard 后 send 自动 force compress +- 压缩 sideQuery 调用 `maxOutputTokens = COMPACT_MAX_OUTPUT_TOKENS` 正确透传到 `runSideQuery`，`thinkingConfig.includeThoughts` 为 `false`（或被 sideQuery 默认值接管） +- **首轮覆盖**：构造一个 `lastPromptTokenCount = 0` 但 history 巨大的 chat（模拟 `--continue` 恢复），首次 send 时 auto 阈值能被估算路径触发 + +### 兼容性测试 + +- 设置 `contextPercentageThreshold = 0.5` 启动 → stderr 警告 + 字段被忽略，行为以内部 PCT 常量为准 + +### Tip 系统测试（tipRegistry.test.ts） + +- 三条 context-\* tip 在跨越 warn/auto/hard 时正确触发，且区间不重叠 +- 主路径下 auto 阈值触发压缩后 `context-high` 不持续可见 +- 边缘路径（熔断 + token 继续涨）下三条 tip 依次触发 +- TipContext 缺 `thresholds` 时（fallback）行为合理 + +## 实施分阶段 + +| Phase | 内容 | 独立性 | +| ----- | -------------------------------------------------------------------------------------------- | ------------------ | +| 1 | 内部常量 + `computeThresholds` + cheap-gate 改动（不含估算补偿） | 可独立合并 | +| 2 | 失败处理升级（1 → 3 熔断） | 可独立合并 | +| 3 | hard 层 force compress 提前 | 依赖 P1 + P7 | +| 4 | 配置面变更 + breaking change 警告 | 依赖 P1 | +| 5 | UI（tip 重写 + /context） | 依赖 P1 | +| 6 | 压缩 sideQuery 关 thinking + 加 `maxOutputTokens` 上限 | 独立可先于 P1 落地 | +| 7 | Token 估算补偿（`estimateContentTokens` + `estimatePromptTokens`，应用到 cheap-gate / hard） | 独立可与 P1 并行 | + +每个 Phase 可独立 PR。建议合并顺序 **P6 → P7 → P1 → P2 → P4 → P3 → P5**：先给压缩调用打上 `maxOutputTokens` 上限（让 buffer 假设可信）；再加估算补偿（让 token 数判断更可靠）；再把阈值基础设施落地；再做失败熔断、配置面变更；最后才打开 hard 层主动救场（这时已有可靠的 token 数 + 熔断器）。每个 PR 都能独立验证、独立回滚。 + +## 风险与注意事项 + +1. **关 thinking 可能影响摘要质量。** 原作者注释 "Compression quality drives every subsequent main turn — keep reasoning on" 表达过对此的担忧。本 spec 的判断是「可预测的 token 上限」优先于「最大化质量」，但落地后需要观察 telemetry 里 `compression_input_token_count` / `compression_output_token_count` 的分布，以及主对话在压缩后的质量变化（用户反馈、`COMPRESSION_FAILED_*` 状态率）。如果质量下降明显，再考虑回退到 thinking 开启 + provider-specific thinkingBudget 控制。 + +2. **`maxOutputTokens` 触顶可能导致 summary 被截断。** 关 thinking 后，20K 直接限制 summary 主体；claude-code 实测 p99.99 ≈ 17K，留 ~3K 安全冗余。但 qwen-code 的压缩 prompt 与 claude-code 不同，分布需要观测。建议在压缩失败分支（[chatCompressionService.ts:464-491](packages/core/src/services/chatCompressionService.ts:464)）追加「检测到 finish_reason = MAX_TOKENS」的 NOOP 路径，避免持久化半截 summary。 + +3. **跨 provider 的 maxOutputTokens 映射差异。** OpenAI compat (dashscope) → `max_tokens`、Anthropic → `max_tokens`、Gemini SDK → `maxOutputTokens`。当前 qwen-code 已有这层映射（[contentGenerator.ts:94](packages/core/src/core/contentGenerator.ts:94) 等），需要在 P6 实现时验证 sideQuery 路径上 `maxOutputTokens` 字段确实贯穿到所有 provider 的请求体。 + +4. **Token 估算是粗略下界，不应反向用作"跳过触发"的依据。** `char/4` 与各 provider 真实 tokenizer 偏差可能 ±30%。本 spec 只用估算来「让阈值更早触发」（false-positive 方向，宁可早压不可晚压）。所有「降低 token 计数 / 跳过压缩」的代码路径仍应使用 `lastPromptTokenCount`（API 权威值）。 + +5. **估算函数与现有 `estimateContentChars` 的关系。** [compactionInputSlimming.ts](packages/core/src/services/compactionInputSlimming.ts) 已经有 `estimateContentChars`（用于压缩 split point 计算），新增的 `estimateContentTokens` 应复用它（除以 bytesPerToken）而非新写一套，避免两套估算口径出现分歧。 + +## 不在本 spec 范围 + +- Env 变量覆盖通道（D 方案）：维持「配置面最小」原则 +- Footer 常驻可视化：留作 follow-up +- 摘要 prompt 改进、`MIN_COMPRESSION_FRACTION` 调整：与阈值设计正交 + +## 开放问题（等 review） + +1. **breaking change 强度**：警告 + 忽略字段 vs 启动报错。当前选警告，需要确认对企业部署/团队配置是否够友好 +2. **小窗口（32K）下 hard 与 auto 退化为同一值**：用户视角是否需要在 `/context` 明示「该窗口下 hard 已退化」 diff --git a/docs/design/telemetry-llm-request-timing-design.md b/docs/design/telemetry-llm-request-timing-design.md new file mode 100644 index 00000000000..4a41b082d16 --- /dev/null +++ b/docs/design/telemetry-llm-request-timing-design.md @@ -0,0 +1,538 @@ +# LLM Request Timing Decomposition Design (P3 Phase 4) + +> Issue #3731 — Phase 4 of hierarchical session tracing. Adds time-to-first-token, request-setup duration, sampling duration, and per-attempt retry telemetry to the `qwen-code.llm_request` span so operators can answer "why was this LLM call slow?" without guessing. +> +> Builds on Phase 1 (#4126), Phase 1.5 (#4302), Phase 2 (#4321). Independent of Phase 3 (#4410, in review) — recommended to land Phase 3 first so Phase 4's per-attempt fields aggregate cleanly under subagent subtrees. + +## Problem + +`qwen-code.llm_request` spans today carry only `model`, `prompt_id`, `input_tokens`, `output_tokens`, `success`, `error`, `duration_ms`. Operators reading a single trace cannot tell: + +1. **How much of `duration_ms` was the model thinking vs the network setup.** A 12-second `duration_ms` could be 11s of retries followed by 1s of fast generation, or 100ms of setup followed by 12s of slow streaming — the trace doesn't say. +2. **When the user saw the first token.** TTFT (time-to-first-token) is the standard latency SLO for chat UIs. We can't compute it; we don't capture it. +3. **What happened during retries.** `retryWithBackoff` (`utils/retry.ts:285`) only calls `debugLogger.warn` — no OTel event, no span attribute. The 4 LLM call sites that go through it (`client.ts:1540`, `baseLlmClient.ts:193,282`, `geminiChat.ts:1039`) have zero retry visibility in traces or metrics. `ContentRetryEvent` exists for content-recovery retries inside `geminiChat.ts:806,830` but not for the more common rate-limit / 5xx retries. +4. **That `api.request.breakdown` is dead code.** The metric is defined at `metrics.ts:242-251` with 4 `ApiRequestPhase` values, exported from `index.ts:117`, tested in `metrics.test.ts:646-675` — but `recordApiRequestBreakdown()` has zero callers in production code. The metric infrastructure is paid for; the data flow was never connected. + +These gaps make `qwen-code.llm_request` the least informative span in the trace tree. Tool spans (#4126/#4321) and subagent spans (#4410) both surface lifecycle phases; LLM spans collapse the entire request into one opaque duration. + +## Existing surface (no change) + +| Component | Location | Why we don't touch it | +| ------------------------------------------------------------ | ---------------------------------------------------------------- | ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| LLM request span lifecycle | `session-tracing.ts` `startLLMRequestSpan` / `endLLMRequestSpan` | Phase 1 (#4126) established the helpers. We extend the metadata interface, don't restructure | +| Active span propagation into provider generators | `loggingContentGenerator.ts:213,287` | Phase 1 (#4126) replaced `withSpan('api.*')` with native helpers; the active context already reaches the stream wrapper | +| `ContentRetryEvent` schema + consumers | `types.ts:626`, `qwen-logger.ts:947`, `loggers.ts:717` | Existing event keeps its shape and downstreams; we add a sibling event class for the `retryWithBackoff` path | +| `LogToSpanProcessor` log-bridge spans | `log-to-span-processor.ts` | ContentRetryEvent's existing bridge continues to nest under the active LLM span. Phase 4 does not change this | +| `ApiRequestPhase` enum | `metrics.ts:330-334` | Public surface (4 values). We populate 3 of the 4 from production code; leave the enum unchanged for backward compatibility | +| Per-provider chunk normalization → `GenerateContentResponse` | `loggingContentGenerator.ts:286-393` | Each provider already normalizes to Google's `GenerateContentResponse` shape before LoggingContentGenerator sees the stream. TTFT detection runs centrally over this normalized shape; no per-provider code | +| `retryWithBackoff` general-purpose retry | `utils/retry.ts:140` | Used by both LLM callers and non-LLM (`channels/weixin/src/api.ts`). We extend with an opt-in `onRetry` callback rather than hard-coupling to LLM telemetry | +| Non-streaming `generateContent` | `loggingContentGenerator.ts:212` | TTFT is not meaningful for non-streaming; the new fields stay `undefined`. Span lifecycle and existing attrs unchanged | + +## Out-of-scope (deferred) + +- **SDK-level retries** (openai SDK `maxRetries=3`, google-genai SDK internal retries). These happen entirely inside the third-party SDK; observing them requires disabling SDK retries and reimplementing in `retryWithBackoff`. Separate decision, not Phase 4. +- **Per-token streaming metrics** (inter-token latency, per-chunk size). Useful for inference-engine perf debugging, not for the user-perceived latency questions Phase 4 targets. +- **Separate TTFT for reasoning/thinking blocks.** "First token" includes thinking content (see D1). A future enhancement could split `ttft_to_reasoning_ms` vs `ttft_to_answer_ms`, but only after we know there's demand. +- **Sampling phase as a dedicated child span.** Computable from `duration_ms - ttft_ms - request_setup_ms`; child span adds nothing for OTel-only backends (claude-code uses one for Perfetto only). Stored as a span attribute instead — see D6. +- **Persistent retry mode (`QWEN_CODE_UNATTENDED_RETRY`) event-level rate limiting.** A single LLM request can produce 50+ `ContentRetryEvent` / `ApiRetryEvent` records under persistent retry. Capping emission is a follow-up — Phase 4 emits all events; if production volumes prove unbearable, add a per-span emission cap with a "+N more attempts (truncated)" summary event in a follow-up PR. +- **`TOKEN_PROCESSING` breakdown phase.** Enum value exists but qwen-code has no real post-stream local processing worth measuring (<10ms typical). Skipped in production callers; enum value retained for future use or for callers we don't control. +- **Migrating `ContentRetryEvent` onto LLM span as span events.** Same reasoning as Phase 3's `subagent_execution` LogRecord: existing consumers (qwen-logger RUM, future metrics) are tightly coupled to the LogRecord. Bridge-span coverage is good enough. + +## References (decision evidence) + +| Source | Key takeaway | +| --------------------------------------------------------------------------------------------------------------------------- | ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| claude-code (Anthropic) `claude.ts:1762, 1789, 1982, 2882` | TTFT captured as `Date.now() - start` on `message_start` SSE event; `start` reset per retry attempt. `requestSetupMs = start - startIncludingRetries`. `attemptStartTimes` array preserved per attempt. Confirms feasibility of the approach; their TTFT semantic is "first stream event" (we diverge to "first content" — see D1) | +| claude-code `perfettoTracing.ts:549-671` | Renders Request Setup → Attempt N (retry) → First Token → Sampling as nested B/E pairs. Demonstrates the visual decomposition; qwen-code does the same decomposition with OTel attributes since we have no Perfetto | +| claude-code `sessionTracing.ts:447` | Only `ttft_ms` makes it onto the OTel span (not `requestSetupMs`, not `samplingMs`, not per-attempt timing). We deliberately put more on the span — claude-code has Perfetto for visualization; we don't | +| opencode (sst/opencode) `session/llm.ts`, `route/client.ts` | No TTFT measurement. Single `LLM.run` Effect span covers everything. Validates that the gap exists across competing tools; not a reference for what to do | +| [OTel GenAI Semantic Conventions](https://opentelemetry.io/docs/specs/semconv/gen-ai/) (status: Development / Experimental) | `gen_ai.usage.input_tokens` (Stable), `gen_ai.usage.output_tokens` (Stable), `gen_ai.usage.cached_tokens` (Experimental), `gen_ai.request.model` (Stable), `gen_ai.server.time_to_first_token` (Experimental, seconds as double). Dual-emit pattern follows #4410 precedent | +| [OTel Trace Spec — Span Events](https://opentelemetry.io/docs/specs/otel/trace/api/#add-events) | "Events SHOULD NOT be used to record information that's better captured as Span Attributes." Confirms per-attempt info belongs on the LLM span attributes + log-bridge spans, not as Span Events on the parent | +| Phase 3 design doc (`telemetry-subagent-spans-design.md`) | Established the dual-emit pattern (`qwen-code.subagent.id` + `gen_ai.agent.id`) and the "private name is authoritative" rule. Phase 4 follows the same convention for TTFT and token fields | + +## Design — seven decisions, each justified + +### D1 — TTFT semantic: "first chunk containing user-visible content" + +TTFT measures wall-clock from the **successful attempt's** request dispatch to the **first stream chunk that contains user-visible output**. A chunk is "user-visible" if any normalized `Part` in `candidates[0].content.parts` is one of: + +- `text` with non-empty string +- `functionCall` (tool use) +- `inlineData` (image, binary) +- `executableCode` +- `thought` / reasoning content (whatever the provider surfaces — Gemini's `thought`, Anthropic's `` block, OpenAI o1 reasoning chunk) + +Chunks containing only `role` metadata or only `usageMetadata` (final usage-summary chunk) do not trigger TTFT. + +**Why not "first stream event of any kind" (claude-code's choice)**: claude-code measures TTFT at `message_start`, an Anthropic-specific metadata event that fires 50–300ms before any actual content. Their internal `headlessProfiler.ts` already separates `time_to_first_response_ms` for the "user saw something" semantic, acknowledging the distinction. qwen-code spans multiple providers (Anthropic, OpenAI, Gemini, Qwen) — picking the metadata-event semantic means TTFT for Anthropic is fundamentally different from TTFT for OpenAI (which has no analogous metadata-only first event). The user-visible-content semantic is uniform across all 4 providers and matches "time-to-first-token" literally. + +**Why include `thought` / reasoning**: from the operator's perspective, reasoning chunks are still "the model produced output." Excluding them would understate TTFT for reasoning-heavy models (o1, Qwen thinking variants). Future split into `ttft_to_reasoning_ms` vs `ttft_to_answer_ms` is possible; not Phase 4. + +**Why include tool-call-only chunks**: agent tool-decision LLM calls (one `tool_use`, no text) are common in qwen-code's workflow. Excluding them means TTFT is undefined for these requests. The `functionCall` Part is meaningful output. + +**Cross-product comparison note**: design doc explicitly states `qwen-code.ttft_ms ≈ claude-code.time_to_first_response_ms ≠ claude-code.ttft_ms`. Operators comparing across products should align on the user-visible-content semantic. + +### D2 — TTFT measurement site: method-local variables in `LoggingContentGenerator.generateContentStream` + +The first-chunk detection runs inside the existing stream wrapper at `loggingContentGenerator.ts:393` (`async function* processStreamGenerator`). Per-call variables (`start`, `ttftMs`) live in the method's closure; **never as instance fields**. + +**Why never instance fields**: `LoggingContentGenerator` is instantiated **once per `ContentGenerator`** (`contentGenerator.ts:377`) and shared across all concurrent `generateContentStream` calls — subagent fan-out, warmup queries, side-queries from `geminiChat`. An instance field would be overwritten across concurrent calls, producing nonsense TTFT for one of every two interleaved requests. + +**Why not AsyncLocalStorage**: ALS would work but adds a context-management layer for a piece of state that doesn't need to escape the method. Method-local is simpler, zero overhead, zero risk of leakage. + +```ts +// loggingContentGenerator.ts — inside generateContentStream +const attemptStart = Date.now(); // per-call local +const requestEntryTime = Date.now(); // also per-call local — see D3 +let ttftMs: number | undefined; +const attemptStartTimes: number[] = [attemptStart]; +let retryTotalDelayMs = 0; +let finalAttempt = 1; +// stream wrapper inspects each chunk; first one matching hasUserVisibleContent: +// ttftMs = Date.now() - attemptStart; +``` + +`hasUserVisibleContent(chunk)` is a small standalone helper colocated with the wrapper, exported for tests: + +```ts +function hasUserVisibleContent(chunk: GenerateContentResponse): boolean { + const parts = chunk.candidates?.[0]?.content?.parts; + if (!parts?.length) return false; + return parts.some( + (p) => + (typeof p.text === 'string' && p.text.length > 0) || + p.functionCall !== undefined || + p.inlineData !== undefined || + p.executableCode !== undefined || + // @ts-expect-error — `thought` is not on all SDK versions but providers emit it + p.thought !== undefined, + ); +} +``` + +### D3 — `request_setup_ms` computation: entry-time vs successful-attempt-start + +`request_setup_ms` measures wall-clock from `generateContentStream`/`generateContent` entry to the **start of the successful attempt** — including all failed retries, backoff sleeps, and any pre-retry preparation work. + +```ts +request_setup_ms = attemptStart_of_successful_attempt - requestEntryTime; +``` + +When `attempt === 1` and no retries happened, `request_setup_ms` is small (just SDK setup). When retries occurred, it captures the entire retry-budget overhead. + +**Putting it on the OTel span (diverges from claude-code, which puts it only on Perfetto)**: rationale at three levels: + +1. **No Perfetto** — qwen-code has no out-of-band visualization layer. OTel attributes are the only channel. +2. **Single-trace debug** — operator sees `duration_ms=12000, request_setup_ms=11500, ttft_ms=200, sampling_ms=300` → instantly diagnoses "retries ate 11.5s, model itself was fast." Computing `request_setup_ms` from other fields requires also exposing `sampling_ms`, which we do anyway (D6). +3. **Negligible cost** — 1 INT64 attribute. Same order of magnitude as the existing `input_tokens`, `output_tokens` attributes. Backend ingest cost is not material. + +### D4 — Retry telemetry: `onRetry` callback option on `retryWithBackoff` + new `ApiRetryEvent` + +`retryWithBackoff` currently calls `logRetryAttempt` (`retry.ts:343`) which only writes to `debugLogger.warn`. We extend the `RetryOptions` interface with an opt-in callback: + +```ts +// utils/retry.ts +interface RetryOptions { + // ... existing fields ... + /** + * Optional. Called once per failed attempt, before the backoff sleep. + * Receives the attempt number (1-based), the error, and the delay before + * the next attempt. Use this to emit telemetry events for LLM call sites; + * leave undefined for non-LLM callers (e.g., channels/weixin) so they + * stay silent in LLM-specific telemetry channels. + */ + onRetry?: (info: RetryAttemptInfo) => void; +} + +interface RetryAttemptInfo { + attempt: number; // 1-based, matches debugLogger output + error: unknown; + errorStatus?: number; + delayMs: number; // backoff delay before next attempt +} +``` + +The 4 LLM call sites (`client.ts:1540`, `baseLlmClient.ts:193,282`, `geminiChat.ts:1039`) register a callback that emits a new `ApiRetryEvent`: + +```ts +// types.ts — new event class, sibling to ContentRetryEvent +export class ApiRetryEvent implements BaseTelemetryEvent { + 'event.name': typeof EVENT_API_RETRY; + 'event.timestamp': string; + model: string; + prompt_id?: string; + attempt_number: number; // 1-based + error_type: string; + error_message: string; // truncated to 256 chars + status_code?: number; + retry_delay_ms: number; + // ... duration_ms set to retry_delay_ms so LogToSpanProcessor renders + // a bridge span of meaningful width + duration_ms: number; +} +``` + +**Why a new event class, not extending `ContentRetryEvent`**: + +- `ContentRetryEvent` has 2 downstream consumers (qwen-logger, log-record export). Changing its payload risks breaking them. +- The naming "content retry" semantically refers to content-recovery retries (invalid stream, schema repair) — extending it to cover rate-limit retries would muddy the schema. +- New event is additive; no consumer surprise. + +**Why not embed callback IN `retry.ts`**: `retry.ts` is called by `channels/weixin/src/api.ts` too (microsoft messaging API retries). Hard-coupling LLM telemetry inside retry.ts would emit `ApiRetryEvent` for non-LLM retries. The `onRetry` callback is opt-in per caller — LLM callers opt in, weixin caller doesn't. + +**ContentRetryEvent coexistence**: ContentRetryEvent stays as-is for content-recovery retries inside `geminiChat.ts:806,830`. ApiRetryEvent covers the rate-limit / 5xx retries from `retryWithBackoff`. The two events fire from different layers and never duplicate. Existing log-bridge behavior for both events is preserved via `LogToSpanProcessor` — both events nest under the active LLM span automatically (Phase 1 wiring ensures the LLM span is active during retries). + +**Persistent retry mode (`QWEN_CODE_UNATTENDED_RETRY`)**: a single 429-loop request may emit 50+ events. Out of scope to rate-limit emission in Phase 4 — if production volumes prove unbearable, add a per-span cap with summary event in a follow-up PR. The aggregated `attempt` and `retry_total_delay_ms` on the parent LLM span (D5) remain accurate regardless of event cap. + +### D5 — Parent LLM span aggregation: scalar attributes only (no map-typed attrs) + +OTel span attributes are scalars (`string | number | boolean | array of these`). Map-typed attributes (like `retry_count_by_status: {429:2, 503:1}`) require JSON serialization and are awkward to query. Skip them. + +| Attribute | Type | Semantic | +| -------------------------- | ------ | ----------------------------------------------------------------------------------- | +| `attempt` | int | 1-based final attempt count (`attemptStartTimes.length`) | +| `retry_total_delay_ms` | int | Sum of all `delayMs` reported by `onRetry`; 0 if no retries | +| `ttft_ms` | int | TTFT per D1; undefined for non-streaming or aborted-before-first-chunk requests | +| `request_setup_ms` | int | Per D3 | +| `sampling_ms` | int | Per D6 | +| `output_tokens_per_second` | double | Derived; `output_tokens / (sampling_ms / 1000)`; undefined when `sampling_ms === 0` | + +Per-attempt status-code distribution (e.g., "2 of the 3 attempts were 429s") is queryable from log-bridge spans of `ApiRetryEvent` records. No need to duplicate it as a flattened attribute on the parent. + +**Why `sampling_ms` and `output_tokens_per_second` on the span**: derivable but cumbersome to compute in backend queries when summing across many spans. Same cost-benefit as `request_setup_ms` (D3). + +### D6 — Activate `recordApiRequestBreakdown()` for 3 of 4 phases + +In `endLLMRequestSpan` (or the wrapper that calls it), after computing TTFT/setup/sampling, emit: + +```ts +recordApiRequestBreakdown(config, model, [ + { phase: ApiRequestPhase.REQUEST_PREPARATION, durationMs: requestSetupMs }, + { phase: ApiRequestPhase.NETWORK_LATENCY, durationMs: ttftMs }, // ttftMs = network + first-token-generation + { phase: ApiRequestPhase.RESPONSE_PROCESSING, durationMs: samplingMs }, +]); +``` + +**Why skip `TOKEN_PROCESSING`**: qwen-code does stream chunk processing inline (consolidation happens in the wrapper at `loggingContentGenerator.ts:644`); the post-stream wrap-up phase is <10ms and not architecturally distinct. Filling it with a meaningless value pollutes the histogram. Leaving the enum value unused is safe — `apiRequestBreakdownHistogram.record(value, {model, phase})` is just a histogram with `phase` as a label; missing labels are simply absent in queries. + +**Why not redefine `NETWORK_LATENCY`**: the spec name is slightly misleading (it's network + first-token-generation, not pure network latency), but: + +- The enum is part of `metrics.ts:330-334` which is exported from `index.ts:117` and tested. +- Backend dashboards may already reference these phase names. +- Renaming or adding a new phase would be a breaking change for trivially marginal accuracy improvement. + +Document the semantic in the design doc; leave the enum unchanged. + +**Why on the span path, not parallel**: keeps `recordApiRequestBreakdown` colocated with span attribute writes — single gated emission point (see D7 idempotency), single ordering invariant. + +### D7 — `endLLMRequestSpan` idempotency: metric recording gated on existing double-end guard + +Phase 1.5 (#4302) established that `endLLMRequestSpan` may be called twice (abort path + error path collision). The existing guard at `session-tracing.ts:~470` (`if (!activeSpans.has(...)) return;`) prevents double `span.end()`. Phase 4 metric recording (D6) **must sit inside the same guarded block**, before `span.end()`: + +```ts +// session-tracing.ts — endLLMRequestSpan +const llmCtx = activeSpans.get(spanRef); +if (!llmCtx) return; // already ended — double-end guard +activeSpans.delete(spanRef); // claim the end + +// ... compute duration, set attributes ... +if (metadata) { + recordApiRequestBreakdown(config, llmCtx.attributes.model, [...]); // NEW — gated + recordTokenUsageMetrics(...); // existing +} + +span.end(); +``` + +This guarantees metric is recorded **exactly once** per LLM request, matching the span lifecycle. + +**Why not record in `loggingContentGenerator`**: it doesn't see the abort path. Recording at the span lifecycle layer ensures every LLM request that opens a span produces exactly one breakdown sample, regardless of success/failure/abort. + +### D8 — GenAI semantic conventions dual-emit (private name authoritative) + +Each Phase 4 attribute that corresponds to an OTel GenAI semconv attribute is written twice on the span: + +| qwen-code private (authoritative) | GenAI semconv (compat layer) | Unit conversion | Spec status | +| ------------------------------------------ | ----------------------------------------------- | --------------- | ------------ | +| `ttft_ms` (ms, int) | `gen_ai.server.time_to_first_token` (s, double) | `ttftMs / 1000` | Experimental | +| `input_tokens` (int) | `gen_ai.usage.input_tokens` (int) | identical | Stable | +| `output_tokens` (int) | `gen_ai.usage.output_tokens` (int) | identical | Stable | +| `cached_input_tokens` (int) (when present) | `gen_ai.usage.cached_tokens` (int) | identical | Experimental | +| `qwen-code.model` (string) | `gen_ai.request.model` (string) | identical | Stable | + +**Existing token attribute names** on the LLM span (set in `endLLMRequestSpan` before Phase 4): qwen-code uses bare `input_tokens` and `output_tokens` already. Phase 4 adds the `gen_ai.usage.*` siblings to match #4410's pattern. The bare names stay; **don't rename**. + +Fields with no GenAI semconv equivalent — `request_setup_ms`, `sampling_ms`, `retry_total_delay_ms`, `attempt`, `output_tokens_per_second` — are emitted only under the qwen-code namespace. + +**Why "private authoritative, semconv as compat"**: + +- Internal dashboards, SLOs, debugLogger output, qwen-logger RUM, ARMS queries — all reference `ttft_ms` etc. Treating those as canonical avoids a flag-day migration. +- The Experimental GenAI semconv may rename `gen_ai.server.time_to_first_token` before reaching Stable. If/when it does, we update the semconv emission; the qwen-code names don't move. +- Future spec-aware backends (Datadog AI views, Honeycomb AI, ARMS GenAI dashboards) auto-pick up the `gen_ai.*` attributes without our involvement. + +**Why dual-emit unit conversion** (ms ↔ seconds): GenAI semconv chose seconds-as-double for latency; qwen-code chose ms-as-int (matches `duration_ms` already on the span). Both representations have value; the conversion is cheap. + +## Helper API (additive to `session-tracing.ts`) + +```ts +// session-tracing.ts — LLMRequestMetadata interface extended (additive) +export interface LLMRequestMetadata { + // ... existing fields: inputTokens, outputTokens, cachedInputTokens, success, error, ... + + /** Time from successful attempt start to first user-visible content chunk (ms). Undefined for non-streaming or aborted-before-first-chunk requests. */ + ttftMs?: number; + + /** Time from generateContent entry to start of successful attempt (ms). Includes all failed retries + backoff. */ + requestSetupMs?: number; + + /** Final attempt number (1-based). 1 = no retries. */ + attempt?: number; + + /** Sum of all backoff delays before the successful attempt (ms). */ + retryTotalDelayMs?: number; +} + +// No new exported helpers — Phase 4 reuses startLLMRequestSpan / endLLMRequestSpan with extended metadata. +``` + +```ts +// types.ts — new event class +export class ApiRetryEvent implements BaseTelemetryEvent { + 'event.name': typeof EVENT_API_RETRY = EVENT_API_RETRY; + 'event.timestamp': string; + model: string; + prompt_id?: string; + attempt_number: number; + error_type: string; + error_message: string; + status_code?: number; + retry_delay_ms: number; + duration_ms: number; // = retry_delay_ms, drives LogToSpanProcessor bridge span width + + constructor(opts: { model: string; promptId?: string; attemptNumber: number; error: unknown; statusCode?: number; retryDelayMs: number }) { ... } +} + +// constants.ts +export const EVENT_API_RETRY = 'qwen-code.api_retry'; + +// loggers.ts +export function logApiRetry(config: Config, event: ApiRetryEvent): void { ... } +``` + +```ts +// utils/retry.ts — RetryOptions extension +interface RetryOptions { + // ... existing ... + onRetry?: (info: RetryAttemptInfo) => void; +} + +interface RetryAttemptInfo { + attempt: number; + error: unknown; + errorStatus?: number; + delayMs: number; +} + +// Inside retryWithBackoff, where logRetryAttempt is called today: +options.onRetry?.({ attempt, error, errorStatus, delayMs: actualDelay }); +logRetryAttempt(attempt, error, errorStatus); // existing debugLogger call unchanged +``` + +## Lifecycle wiring + +### Streaming path (the common case) + +```ts +// loggingContentGenerator.ts:283 — generateContentStream +async generateContentStream(req, userPromptId): Promise> { + const requestEntryTime = Date.now(); + let attemptStart = requestEntryTime; + const attemptStartTimes: number[] = [attemptStart]; + let retryTotalDelayMs = 0; + let finalAttempt = 1; + + // Use existing startLLMRequestSpan (Phase 1) + // Pass onRetry callback to whatever retry layer is in use: + const onRetry: RetryAttemptInfo & { invoke: ... } = (info) => { + finalAttempt = info.attempt + 1; // we're about to start attempt N+1 + retryTotalDelayMs += info.delayMs; + attemptStart = Date.now() + info.delayMs; // approximate; actual reset is at top of next attempt + attemptStartTimes.push(attemptStart); + // emit ApiRetryEvent + logApiRetry(this.config, new ApiRetryEvent({ + model: req.model, + promptId: userPromptId, + attemptNumber: info.attempt, + error: info.error, + statusCode: info.errorStatus, + retryDelayMs: info.delayMs, + })); + }; + + // stream wrapper detects first user-visible chunk: + return this.processStreamGenerator(stream, ..., { + onFirstUserVisibleChunk: (now) => { + ttftMs = now - attemptStart; + }, + }); +} +``` + +At span end (already in Phase 1's `endLLMRequestSpan` flow), include the new fields in `LLMRequestMetadata`: + +```ts +endLLMRequestSpan(llmSpan, { + success: true, + inputTokens, + outputTokens, + cachedInputTokens, + ttftMs, + requestSetupMs: attemptStart - requestEntryTime, + attempt: finalAttempt, + retryTotalDelayMs, +}); +``` + +### Non-streaming path + +`generateContent` (`loggingContentGenerator.ts:212`) does not produce streaming chunks. TTFT is `undefined`; `request_setup_ms` is still meaningful (captures retry overhead). The breakdown metric records 2 phases (REQUEST_PREPARATION + RESPONSE_PROCESSING where `RESPONSE_PROCESSING = duration_ms - request_setup_ms`), not 3. + +### Retry layer integration (4 sites) + +Each of the 4 LLM `retryWithBackoff` call sites adds `onRetry`: + +```ts +// client.ts:1540 (similar at baseLlmClient.ts:193, 282, geminiChat.ts:1039) +const result = await retryWithBackoff(apiCall, { + ...existingOptions, + onRetry: (info) => { + logApiRetry( + this.config, + new ApiRetryEvent({ + model, + promptId: userPromptId, + attemptNumber: info.attempt, + error: info.error, + statusCode: info.errorStatus, + retryDelayMs: info.delayMs, + }), + ); + // also feed back into LoggingContentGenerator's local retry accumulator + // (when in scope — for callers that don't go through LoggingContentGenerator, + // the LLM span still gets `attempt` and `retry_total_delay_ms` via the + // metadata path because endLLMRequestSpan is called at the LLM layer) + }, +}); +``` + +The non-LLM caller (`channels/weixin/src/api.ts`) **does not register `onRetry`** — no `ApiRetryEvent` is emitted for its retries, matching today's behavior. + +## Concurrent safety — the headline guarantee + +`LoggingContentGenerator` instance is shared (one per `ContentGenerator`, `contentGenerator.ts:377`). Three concurrent `generateContentStream` calls (e.g., 3 subagents fan out via `coreToolScheduler.runConcurrently`) execute three independent closures of `generateContentStream`: + +``` +call_A: attemptStart_A, ttftMs_A, ... (closure) +call_B: attemptStart_B, ttftMs_B, ... (closure) +call_C: attemptStart_C, ttftMs_C, ... (closure) +``` + +Per-call locals never overlap. Stream chunks are detected against the local `attemptStart` of each call. Span attributes are set at each call's own `endLLMRequestSpan`. + +`AsyncLocalStorageContextManager` (registered by NodeSDK at `sdk.ts:273`) already ensures the active OTel context — and thus the parent span passed to `startLLMRequestSpan` — is correct per fiber. + +## Files to change + +| File | Change | LOC est | +| -------------------------------------------------------------------------------- | ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | ------- | +| `packages/core/src/telemetry/constants.ts` | Add `EVENT_API_RETRY` constant | +2 | +| `packages/core/src/telemetry/types.ts` | Add `ApiRetryEvent` class + union member | +40 | +| `packages/core/src/telemetry/loggers.ts` | Add `logApiRetry()` function | +20 | +| `packages/core/src/telemetry/qwen-logger/qwen-logger.ts` | Add `logApiRetryEvent()` for RUM downstream consistency | +20 | +| `packages/core/src/telemetry/session-tracing.ts` | Extend `LLMRequestMetadata` (ttftMs, requestSetupMs, attempt, retryTotalDelayMs); extend `endLLMRequestSpan` to set new attrs + breakdown metric + dual-emit gen_ai.\* | +60 | +| `packages/core/src/telemetry/metrics.ts` | Wire `recordApiRequestBreakdown` callsite inside `endLLMRequestSpan` (no change to the existing recorder) | 0 | +| `packages/core/src/utils/retry.ts` | Add `onRetry?: (info: RetryAttemptInfo) => void` to RetryOptions; export `RetryAttemptInfo`; invoke callback in the existing logRetryAttempt site | +25 | +| `packages/core/src/core/loggingContentGenerator/loggingContentGenerator.ts` | TTFT capture: method-local accumulators + `hasUserVisibleContent` helper + first-chunk detection in stream wrapper; pass new metadata to `endLLMRequestSpan` | +80 | +| `packages/core/src/core/client.ts` | Wire `onRetry` callback at `retryWithBackoff` call site (`client.ts:1540`) | +15 | +| `packages/core/src/core/baseLlmClient.ts` | Wire `onRetry` callback at 2 `retryWithBackoff` call sites | +25 | +| `packages/core/src/core/geminiChat.ts` | Wire `onRetry` callback at `retryWithBackoff` call site (`geminiChat.ts:1039`) | +15 | +| `packages/core/src/telemetry/session-tracing.test.ts` | `endLLMRequestSpan` sets ttft_ms / request_setup_ms / attempt / retry_total_delay_ms / sampling_ms / output_tokens_per_second + gen_ai dual-emit + breakdown metric (each phase) + idempotent end | +120 | +| `packages/core/src/core/loggingContentGenerator/loggingContentGenerator.test.ts` | `hasUserVisibleContent` (text / functionCall / inlineData / executableCode / thought / role-only / usage-only); concurrent calls don't cross-contaminate; TTFT undefined when aborted before first chunk; TTFT undefined on non-streaming | +100 | +| `packages/core/src/utils/retry.test.ts` | `onRetry` invoked per failed attempt with correct `attempt`, `delayMs`, `error`, `errorStatus`; absence of `onRetry` is silent (no telemetry emitted) | +50 | +| `packages/core/src/telemetry/loggers.test.ts` | `logApiRetry` emits LogRecord with expected payload; bridges through LogToSpanProcessor to nested span under active LLM span | +40 | + +Total: 14 files, ~610 LOC. Larger than Phase 2 (#4321) but comparable to Phase 3 (#4410) and justified by the breadth of integration (4 retry sites + telemetry plumbing + streaming wrapper). + +If review pushes back on size: split into **Phase 4a + 4b + 4c**: + +- **4a** (~200 LOC): TTFT capture + extended `LLMRequestMetadata` + dual-emit. Self-contained value (TTFT visibility from day one). +- **4b** (~250 LOC): `onRetry` callback + `ApiRetryEvent` + 4 caller wiring. **Independently a bug fix** for the `retryWithBackoff` telemetry gap. +- **4c** (~160 LOC): `recordApiRequestBreakdown` activation + parent span aggregation attrs (`attempt`, `retry_total_delay_ms`, `sampling_ms`, `output_tokens_per_second`). Depends on 4a + 4b. + +## Testing strategy + +| Test | What it proves | +| -------------------------------------------------------------------------------------------------------------------------------------------- | ------------------------------------- | +| `hasUserVisibleContent` returns true for text/functionCall/inlineData/executableCode/thought | D1 semantics across part types | +| `hasUserVisibleContent` returns false for role-only and usage-only chunks | D1 negative cases | +| streaming: TTFT measured from attempt start to first user-visible chunk | End-to-end TTFT detection | +| streaming: TTFT undefined if stream aborts before any user-visible chunk | Edge case | +| streaming: TTFT computed from final attempt's start (not first attempt) | D3 — TTFT reset on retry | +| non-streaming: TTFT remains undefined | S3 decision | +| concurrent `generateContentStream` calls don't cross-contaminate TTFT | D2 — method-local guarantee | +| `endLLMRequestSpan` sets all Phase 4 attrs (ttft_ms, request_setup_ms, sampling_ms, attempt, retry_total_delay_ms, output_tokens_per_second) | Attribute presence | +| `endLLMRequestSpan` dual-emits gen_ai.server.time_to_first_token + gen_ai.usage.\* + gen_ai.request.model | D8 dual-emit | +| `endLLMRequestSpan` records breakdown metric with 3 phases for streaming, 2 for non-streaming | D6 | +| `endLLMRequestSpan` called twice: metric recorded exactly once, attrs not re-set | D7 idempotency | +| `retryWithBackoff` with `onRetry`: callback invoked per failed attempt with correct args | D4 callback contract | +| `retryWithBackoff` without `onRetry`: no telemetry emitted (silent for non-LLM callers) | P2 — channels/weixin scope protection | +| `client.ts` / `baseLlmClient.ts` / `geminiChat.ts` retry callsites emit `ApiRetryEvent` on retry | Integration of D4 at 4 sites | +| `ApiRetryEvent` LogRecord bridges via LogToSpanProcessor to a child span under active LLM span | Trace tree correctness | +| LLM span `attempt` field correctly reflects final attempt number under retries | D5 aggregation | +| LLM span `retry_total_delay_ms` correctly sums onRetry delays | D5 aggregation | +| `output_tokens_per_second` undefined when `sampling_ms === 0` (no streaming) | Avoid divide-by-zero | + +## Edge cases + +| Case | Handling | +| ----------------------------------------------------------------------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ | +| Stream aborts before any chunk arrives | `ttftMs = undefined`, `sampling_ms = undefined`, `output_tokens_per_second = undefined`. `attempt`, `request_setup_ms` still set. `success = false` | +| Stream aborts after first chunk | `ttftMs` set; `sampling_ms` = `duration_ms - ttftMs - request_setup_ms`; reflects partial response time. `success = false` | +| Retry succeeds on attempt 1 (no retries) | `attempt = 1`, `retry_total_delay_ms = 0`, no `ApiRetryEvent` emitted, breakdown metric records `request_setup_ms` close to 0 | +| Persistent retry mode 50+ attempts | 50+ `ApiRetryEvent` records emitted (out-of-scope cap deferred); LLM span `attempt = 51`, `retry_total_delay_ms = sum of all delays`. Operator sees aggregated view on span; full per-attempt detail in log-bridge spans | +| Non-LLM `retryWithBackoff` caller (channels/weixin) | No `onRetry` registered; only existing `debugLogger.warn` fires. No `ApiRetryEvent`; no breakdown metric (caller isn't an LLM site) | +| `endLLMRequestSpan` called twice (abort + error race) | Phase 1.5 guard at `activeSpans.delete()` returns early on second call; `recordApiRequestBreakdown` is inside the guard, recorded exactly once | +| Anthropic `message_start` chunk arrives before content | `hasUserVisibleContent` returns false for it (no parts with text/functionCall/etc.); TTFT not triggered until subsequent `content_block_delta` chunk | +| OpenAI first chunk with empty `delta.content` but `role` only | `hasUserVisibleContent` returns false; TTFT not triggered until first chunk with non-empty delta | +| Tool-call-only response (no text) | First chunk with `functionCall` Part triggers TTFT; `output_tokens_per_second` computed against tool-call token count | +| Concurrent subagents (3 calls in flight) | Each call's closure has its own `attemptStart`, `ttftMs`, `attemptStartTimes`. Per-call span receives its own metadata at `endLLMRequestSpan`. No interleaving (D2) | +| SDK-level retries inside openai-sdk (`maxRetries=3`) | Invisible to qwen-code telemetry — happens entirely inside SDK before retryWithBackoff sees the request. `attempt` reflects retryWithBackoff attempts only. Out of scope (see Out-of-scope) | +| `gen_ai.server.time_to_first_token` spec renames before reaching Stable | Single-file update: `session-tracing.ts:endLLMRequestSpan`. The qwen-code-native `ttft_ms` stays authoritative — no downstream impact | +| Subagent's LLM request | Parent is the subagent span (Phase 3). Phase 4 fields nest correctly. Aggregations grouped by `qwen-code.subagent.id` give per-subagent LLM perf — design-doc-future, easy follow-up | +| Reasoning model with long thought blocks | First `thought` Part triggers TTFT; `sampling_ms` includes both thinking + answer phases. Split into separate metrics deferred | + +## Rollback + +The change is additive at the OTel and metric level — every new attribute is optional, every new event is a new class. Existing dashboards that don't filter on the new fields keep working unchanged. + +Behavior-affecting changes: + +- New `ApiRetryEvent` LogRecord starts flowing → log volume increases proportional to retry rate (typically <1% of requests retry). Mitigate by sampling LogRecord at the SDK layer if needed. +- New breakdown metric `qwen-code.api.request.breakdown` starts producing time series → mild Prometheus cardinality bump (`{model, phase}` — bounded). +- `output_tokens_per_second` derived attribute may appear unusual on dashboards filtering "all attributes" — document. + +Rollback path: revert the single PR (or each of 4a/4b/4c independently). All new fields use defensive defaults (undefined / 0) and don't change span structure. + +## Sequencing + +- **After Phase 3 (#4410, in review)**: not a hard dependency. Phase 4 attributes attach to `qwen-code.llm_request` spans regardless of whether they're under a `qwen-code.subagent` (Phase 3) or `qwen-code.interaction` (Phase 1) parent. Recommend Phase 3 land first so per-attempt aggregation under subagent subtrees works naturally. +- **Independent of #4384** (`traceparent` + `X-Qwen-Code-Session-Id` outbound propagation). They touch the HTTP layer; Phase 4 touches the stream/retry/metric layer. +- **Independent of `clearDetailedSpanState` chat-compression follow-up** (#4097 follow-up). Different surface. + +## Open questions + +1. **`onRetry` callback firing semantics**: invoked **before** backoff sleep (current proposal) or **after** (when the next attempt is about to start)? Before is simpler — callback has all the info immediately; after would require capturing the just-completed delay separately. Pre-sleep is the recommendation; document in callback contract. +2. **Per-attempt timing on the LLM span**: should we add `attempt_durations_ms: number[]` array? OTel supports array-of-primitive attributes. Useful for "which attempt of N was slow" diagnostics. Defer until production data shows demand — log-bridge spans already carry the equivalent. +3. **Persistent retry mode emission cap**: at what `attempt > N` threshold should we start sampling? `N = 5` then 1-in-10? `N = 10` then summary-only? Defer until we have production volume data. +4. **`TOKEN_PROCESSING` phase**: keep enum value dormant or wire it to something (e.g., consolidation time)? Defer — wait for a real use case. +5. **Subagent-level LLM rollups**: trivial follow-up once Phase 4 lands — sum `ttft_ms`/`output_tokens`/`input_tokens` per subagent subtree. Not Phase 4 scope but the data flow enables it. diff --git a/docs/design/telemetry-resource-attributes-design.md b/docs/design/telemetry-resource-attributes-design.md new file mode 100644 index 00000000000..01ec84efa5b --- /dev/null +++ b/docs/design/telemetry-resource-attributes-design.md @@ -0,0 +1,762 @@ +# Telemetry: Custom Resource Attributes + Metric Cardinality Controls + +> 配套 issue: [#4365](https://github.com/QwenLM/qwen-code/issues/4365) +> 父 issue: [#3731](https://github.com/QwenLM/qwen-code/issues/3731) +> 基于 2026-05-21 对 qwen-code main 分支的代码复核 + +## 1. 背景 + +qwen-code 已经接入 OpenTelemetry SDK，但 Resource 构造方式让它在两个常见生产场景下不可用： + +1. **无法附加自定义维度**：运维侧想给所有 telemetry 数据打 `team` / `env` / `cost_center` / `user_id` 标签，今天没有任何机制可以做到。即使设置标准的 `OTEL_RESOURCE_ATTRIBUTES` 环境变量也**完全不生效**。 +2. **指标基数（cardinality）失控**：`session.id` 被注入到了 Resource 层，会自动附着到每条 metric 数据点。每个 CLI session 产生一个新值，指标后端（Prometheus / 阿里云 ARMS Metric / VictoriaMetrics）会被无界 time-series 撑爆。 + +这两个问题耦合在一起：解决前者会让用户**更容易**给数据加高基数的字段，所以必须配套提供后者。 + +## 2. 现状 + +### 2.1 Resource 构造 + +`packages/core/src/telemetry/sdk.ts:156-161`： + +```ts +const resource = resourceFromAttributes({ + [SemanticResourceAttributes.SERVICE_NAME]: SERVICE_NAME, + [SemanticResourceAttributes.SERVICE_VERSION]: + config.getCliVersion() || 'unknown', + 'session.id': config.getSessionId(), +}); +``` + +`sdk.ts:274-278`： + +```ts +sdk = new NodeSDK({ + resource, + // Disable async host/process/env resource detectors: they leave attributes + // pending and trigger an OTel diag.error on any resource attribute read + // before the detectors settle (e.g. during HttpInstrumentation span creation). + autoDetectResources: false, + ... +}); +``` + +`autoDetectResources: false` 关闭了标准 OTel 的 `envDetector`——也就是平时会读取 `OTEL_RESOURCE_ATTRIBUTES` 和 `OTEL_SERVICE_NAME` 的那一层。这是有原因的（detector 异步，会在 settle 前触发 `diag.error`），但副作用是这两个标准环境变量在 qwen-code 里**完全无效**。 + +### 2.2 `session.id` 实际是三重注入 + +| 位置 | 行号 | 影响 | +| --------------------------- | ------------------------ | ------------------------------------- | +| Resource | `sdk.ts:160` | 所有 signal（spans / logs / metrics） | +| Per-span | `session-tracing.ts:169` | spans | +| Per-log | `loggers.ts:128` | logs | +| **`getCommonAttributes()`** | `metrics.ts:57` | **每条 metric record 显式叠加** | + +也就是说**单独把 `session.id` 从 Resource 拿掉是不够的**——`metrics.ts:57` 的 `baseMetricDefinition.getCommonAttributes()` 会被 30+ 个 metric 调用点 `...spread` 进去，再次塞回 `session.id`。 + +```ts +// metrics.ts:55-59 +const baseMetricDefinition = { + getCommonAttributes: (config: Config): Attributes => ({ + 'session.id': config.getSessionId(), + }), +}; +``` + +好消息：所有 metric 调用点（30+ 个）都走这一个函数，是天然的 chokepoint。 + +### 2.3 config resolver 模式 + +`packages/core/src/telemetry/config.ts:resolveTelemetrySettings()` 用统一的优先级链： + +``` +argv (highest) > QWEN_* env > OTEL_* env > settings.json (lowest) +``` + +新加项照搬这个 pattern。 + +### 2.4 settings schema 现状 + +`packages/cli/src/config/settingsSchema.ts:998-1018` 定义 `telemetry` 的 JSON schema： + +```ts +telemetry: { + type: 'object', + // ... + jsonSchemaOverride: { + type: 'object', + properties: { + includeSensitiveSpanAttributes: { ... }, + }, + additionalProperties: true, // ← 今天对其他 telemetry.* key 不校验 + }, +} +``` + +`additionalProperties: true` 意味着今天 schema 对 `otlpEndpoint` / `otlpProtocol` / `resourceAttributes` 等其他字段全部放行不校验。新加 `resourceAttributes` / `metrics` 字段时，应同步在这里补 schema，方便 IDE 自动补全和 settings UI 渲染。 + +### 2.5 不在本设计范围的代码路径 + +`packages/core/src/telemetry/qwen-logger/qwen-logger.ts` 是 qwen-code 的**第一方使用上报通道**（基于阿里 RUM 内部协议 `RumResourceEvent`），与 OTel SDK 完全独立。它有自己的 endpoint、proxy 和数据模型，**不受本设计影响**。详见第 3 节。 + +### 2.6 已支持 / 未支持的 `OTEL_*` 环境变量 + +| 环境变量 | 现状 | +| --------------------------------------------------- | --------------------------------- | +| `OTEL_EXPORTER_OTLP_ENDPOINT` | ✅ 支持（`config.ts:79`） | +| `OTEL_EXPORTER_OTLP_{TRACES,LOGS,METRICS}_ENDPOINT` | ✅ 支持 | +| `OTEL_EXPORTER_OTLP_HEADERS` | ✅ 底层 exporter 直接读取 | +| `OTEL_TRACES_SAMPLER` | ✅ 支持（`tracer.ts:247`） | +| **`OTEL_RESOURCE_ATTRIBUTES`** | ❌ 完全不支持 | +| **`OTEL_SERVICE_NAME`** | ❌ 完全不支持 | +| **`OTEL_METRICS_INCLUDE_*`** | ❌ 完全不支持（claude-code 风格） | + +## 3. 目标 / 非目标 + +### 3.1 目标 + +- 让运维通过标准 `OTEL_RESOURCE_ATTRIBUTES` 和自家 `settings.json` 给所有 OTLP 导出的 span / log / metric 附加自定义 resource attributes +- 让 `OTEL_SERVICE_NAME` 按 OTel 规范工作（包括与 `OTEL_RESOURCE_ATTRIBUTES` 里的 `service.name` 的优先级） +- 默认情况下，metric 上**不**携带 `session.id`（保护后端基数） +- 提供显式开关让需要 metric-level session correlation 的用户重新打开 +- 保留 spans 和 logs 上的 `session.id`（trace correlation 必须） +- 保留 `autoDetectResources: false`，不退化 `diag.error` 那个已修的 bug +- 配套更新 `settingsSchema.ts` 让新字段对 settings UI 和 IDE 可见 + +### 3.2 非目标 + +- **`qwen-logger` 第一方上报**：完全独立的 RUM 通道，不在本设计范围。其上报字段（device id、user agent 等）由 RUM 协议决定，不应被用户 resource attribute 干扰。若未来要给 `qwen-logger` 增加自定义维度，是另一条独立的设计。 +- **Per-span 动态 attribute hook**：让用户写代码 / hook 给每个 span 计算 attribute。claude-code 也没解决这块，复杂度高、收益低。 +- **`service.version` cardinality 控制**：版本变化频率有限（月级），time series 增长可控。需要时走 v2，引入 OTel View API。 +- **Agent SDK 形态的 per-query resource attrs**：qwen-code 目前没有 SDK 调用场景。 +- **OTLP 请求头（auth headers）配置**：是另一条 issue 线（#3731 P1），与本设计独立。 +- **CLI flag 形式的 resource attribute**：env var + settings.json 已覆盖临时与基线两种场景，CLI flag 会让命令行变得啰嗦，无明显增益。 + +## 4. 设计 + +### 4.1 总体分层 + +``` +┌─ Resource（sdk.ts:156）────────────────────────────────────────┐ +│ service.name ← OTEL_SERVICE_NAME │ +│ > OTEL_RESOURCE_ATTRIBUTES.service.name│ +│ > 'qwen-code' │ +│ service.version ← config.getCliVersion() [reserved] │ +│ ...user attrs ← OTEL_RESOURCE_ATTRIBUTES │ +│ + settings.resourceAttributes │ +│ ✗ session.id 移走 │ +└────────────────────────────────────────────────────────────────┘ + │ + ├──→ Spans ＋ session.id（session-tracing.ts:169，保留） + ├──→ Logs ＋ session.id（loggers.ts:128，保留） + └──→ Metrics ＋ getCommonAttributes() — 默认 {} + toggle ON: { session.id } +``` + +### 4.2 优先级 / merge 顺序 + +#### 一般 attribute + +低 → 高： + +1. `OTEL_RESOURCE_ATTRIBUTES`（标准 OTel env var） +2. `settings.telemetry.resourceAttributes` +3. 内建保留键（覆盖以上任何同名） + +**理由**：环境变量是 ops-time 临时覆盖（CI / 单机 debug），settings.json 是 fleet-baked 基线，内建是产品契约——基线优先级应高于临时变量，内建优先级应高于一切。 + +#### `service.name` 特殊处理 + +`service.name` 必须遵守 [OTel 规范](https://opentelemetry.io/docs/specs/otel/configuration/sdk-environment-variables/)： + +> **`OTEL_SERVICE_NAME` takes precedence over `service.name` defined with the `OTEL_RESOURCE_ATTRIBUTES` variable.** + +因此对 `service.name` 单独应用这条优先级链（高 → 低）： + +1. `OTEL_SERVICE_NAME`（最高，标准 OTel 规范规定） +2. `settings.resourceAttributes.service.name`（settings 优先于 env，沿用本设计一般规则） +3. `OTEL_RESOURCE_ATTRIBUTES.service.name` +4. 内建默认 `'qwen-code'` + +`service.name` 允许通过 settings 覆盖——它是 service 身份，企业 fleet 用统一 settings.json 配置 service.name 是常见且合理的做法，禁止反而会阻断 GitOps 分发场景。`OTEL_SERVICE_NAME` 作为标准 OTel 规范规定的"最高优先级"通道，仍然可以在 CI / 单机调试时临时覆盖 settings。 + +具体规则： + +| 来源 | 写入 `service.name` 是否生效 | +| ------------------------------------------------------- | -------------------------------------- | +| `OTEL_SERVICE_NAME=foo` | ✅ 最高优先级（覆盖任何其他来源） | +| `settings.resourceAttributes={ "service.name": "foo" }` | ✅ 仅在没有 `OTEL_SERVICE_NAME` 时生效 | +| `OTEL_RESOURCE_ATTRIBUTES=service.name=foo` | ✅ 仅在以上两者都没有时生效 | + +### 4.3 保留键策略 + +| 键 | 用户能否覆盖 | 理由 | +| ----------------- | ----------------------------------------------------------------------- | ----------------------------------------------------------------------------------------------------- | +| `service.name` | ✅ env var + settings 都可（见 §4.2 优先级链） | service 身份，应允许 ops 控制 | +| `service.version` | ❌ 任何来源都丢弃 + warn | 遥测可信度——不允许用户谎报版本 | +| `session.id` | ❌ 任何来源都丢弃 + warn（在 metric 上额外有 toggle 控制 runtime 注入） | runtime-only；用户写到 Resource 会绕过 metric cardinality toggle（Resource attr 自动附到所有 signal） | +| `qwen.*` 前缀 | ⚠️ 不强制保留，但 docs 建议留给产品自用 | 避免未来内建 attr 与用户 attr 冲突 | + +**保留键以常量集中维护**： + +```ts +// telemetry/resource-attributes.ts (new file) +/** Keys that cannot be overridden from any source (env or settings). */ +export const RESERVED_RESOURCE_ATTRIBUTE_KEYS = new Set([ + 'service.version', + 'session.id', +]); +``` + +`service.name` **不**在 RESERVED 列表里——它走自己的优先级链（§4.2），不属于"全局禁止覆盖"语义。RESERVED 是"任何来源写了都警告并丢弃"，统一适用于 env 和 settings 两个入口。 + +### 4.4 `OTEL_RESOURCE_ATTRIBUTES` 解析 + +同步实现，绕开 OTel 自带的异步 envDetector： + +```ts +function parseOtelResourceAttributes( + raw: string | undefined, +): Record { + if (!raw) return {}; + const out: Record = {}; + for (const pair of raw.split(',')) { + const trimmed = pair.trim(); + if (!trimmed) continue; + const idx = trimmed.indexOf('='); + if (idx <= 0) { + diag.warn( + `Skipping malformed OTEL_RESOURCE_ATTRIBUTES entry: ${trimmed}`, + ); + continue; + } + const key = trimmed.slice(0, idx).trim(); + const valueRaw = trimmed.slice(idx + 1).trim(); + if (!key) continue; + let value: string; + try { + value = decodeURIComponent(valueRaw); + } catch { + diag.warn( + `Invalid percent-encoding in OTEL_RESOURCE_ATTRIBUTES for key "${key}", using raw value`, + ); + value = valueRaw; + } + out[key] = value; // duplicate keys: last wins (matches OTel reference impls) + } + return out; +} +``` + +格式严格按 OTel 规范：`key1=val1,key2=val2`，值 percent-encoded。 + +### 4.5 Metric attribute filter + +唯一改动点 `metrics.ts:55-59`： + +```ts +const baseMetricDefinition = { + getCommonAttributes: (config: Config): Attributes => { + const out: Attributes = {}; + if (config.getTelemetryMetricsIncludeSessionId()) { + out['session.id'] = config.getSessionId(); + } + return out; + }, +}; +``` + +调用点（30+ 个）零改动——`...spread` 一个空对象等价于不展开任何字段。 + +### 4.6 边界情况与校验 + +| 输入 | 行为 | +| ---------------------------------------------------------------- | ----------------------------------------------------------------------- | +| `OTEL_RESOURCE_ATTRIBUTES=""` (空字符串) | 返回 `{}`，正常启动 | +| `OTEL_RESOURCE_ATTRIBUTES="a"` (无 `=`) | 跳过该项 + `diag.warn`，继续解析其余 | +| `OTEL_RESOURCE_ATTRIBUTES="=val"` (空 key) | 跳过该项，继续解析其余 | +| `OTEL_RESOURCE_ATTRIBUTES="a=,b=2"` (空 value) | `a=''`, `b='2'`（OTel 规范允许空 value） | +| `OTEL_RESOURCE_ATTRIBUTES="a=val%ZZbad"` (无效 percent-encoding) | 保留原始 `val%ZZbad` + `diag.warn` | +| `OTEL_RESOURCE_ATTRIBUTES="a=1,a=2"` (duplicate key) | 后写胜出 `a=2`（与 OTel SDK 参考实现一致） | +| `OTEL_RESOURCE_ATTRIBUTES="a=1, b=2 "` (含空格) | 自动 trim | +| `OTEL_RESOURCE_ATTRIBUTES=service.version=x` | 静默丢弃 `service.version` + `diag.warn`，保留其他键 | +| `settings.resourceAttributes={ "service.name": "x" }` | 接受（settings 可设 service.name，见 §4.2） | +| `settings.resourceAttributes={ "service.version": "x" }` | 静默丢弃 + `diag.warn` | +| `settings.resourceAttributes={ "team": 123 }` (非 string) | TypeScript 类型阻挡；runtime 传入则 settings JSON schema validator 拒绝 | +| Resource 总大小 > OTel 限制 (4KB?) | 由底层 OTel SDK 处理，不在本层校验 | + +**为什么不在本层做 attribute key 命名校验**（如 OTel 推荐的 `[a-z][a-z0-9_.]*` 模式）：OTel SDK 自己会在 export 时校验，本层重复校验既慢又容易和 SDK 行为偏移。我们只做格式解析，不做语义校验。 + +**RESERVED 键的强制保护对两个入口都生效**： + +```ts +// 应用于 env-parsed attrs +for (const k of RESERVED_RESOURCE_ATTRIBUTE_KEYS) { + if (k in envAttrs) { + diag.warn(`OTEL_RESOURCE_ATTRIBUTES cannot override "${k}"; ignoring`); + delete envAttrs[k]; + } +} + +// 应用于 settings attrs +for (const k of RESERVED_RESOURCE_ATTRIBUTE_KEYS) { + if (k in settingsAttrs) { + diag.warn( + `settings.telemetry.resourceAttributes cannot override "${k}"; ignoring`, + ); + delete settingsAttrs[k]; + } +} +``` + +### 4.7 生命周期与多进程 + +- **SDK init 时机**：Resource 在 `initializeTelemetry()` 时一次性构造，**进程内不可变**。这与 OTel SDK 设计一致。 +- **Subagent fork**：qwen-code 的 subagent 是同进程内的 (`subagent-runtime.ts`)，共享 Resource。若未来引入跨进程 subagent，子进程会**重新 init SDK**，重新读 env var 和 settings——只要 env 透传过去，行为一致。 +- **Hot reload**：settings 修改后**不会重新构造 Resource**。需要操作员重启 CLI 才能生效。文档应明确说明。 +- **`refreshSessionContext()`** (`sdk.ts:306`)：仅刷新 session ALS context，**不重建 Resource**——因为 Resource 上已经没有 `session.id` 了（本设计的核心改动之一）。 + +## 5. Config schema 改动 + +### 5.1 `TelemetrySettings` 接口（`packages/core/src/config/config.ts:293`） + +```ts +export interface TelemetrySettings { + // ... existing fields + /** Static resource attributes attached to every span/log/metric. */ + resourceAttributes?: Record; + /** Per-signal cardinality controls. */ + metrics?: { + /** Include session.id on metric data points (default: false). */ + includeSessionId?: boolean; + }; +} +``` + +### 5.2 `Config` getter（同文件） + +```ts +class Config { + getTelemetryResourceAttributes(): Record { + return this.telemetrySettings.resourceAttributes ?? {}; + } + getTelemetryMetricsIncludeSessionId(): boolean { + return this.telemetrySettings.metrics?.includeSessionId ?? false; + } +} +``` + +### 5.3 `resolveTelemetrySettings()` 新增 + +```ts +const envResourceAttrs = parseOtelResourceAttributes( + env['OTEL_RESOURCE_ATTRIBUTES'], +); +const settingsResourceAttrs = { ...(settings.resourceAttributes ?? {}) }; + +// Strip RESERVED keys from both sources (warn if user tried to set them). +for (const k of RESERVED_RESOURCE_ATTRIBUTE_KEYS) { + if (k in envResourceAttrs) { + diag.warn(`OTEL_RESOURCE_ATTRIBUTES cannot override "${k}"; ignoring`); + delete envResourceAttrs[k]; + } + if (k in settingsResourceAttrs) { + diag.warn( + `settings.telemetry.resourceAttributes cannot override "${k}"; ignoring`, + ); + delete settingsResourceAttrs[k]; + } +} + +// Merge: env < settings (settings wins on conflict). +const merged: Record = { + ...envResourceAttrs, + ...settingsResourceAttrs, +}; + +// service.name precedence: OTEL_SERVICE_NAME (env-only escape) wins over +// everything else. settings already overwrote env in the spread above. +if (env['OTEL_SERVICE_NAME']) { + merged['service.name'] = env['OTEL_SERVICE_NAME']; +} + +const resourceAttributes = merged; + +const metricsIncludeSessionId = + parseBooleanEnvFlag(env['QWEN_TELEMETRY_METRICS_INCLUDE_SESSION_ID']) ?? + settings.metrics?.includeSessionId ?? + false; + +return { + // ... existing fields + resourceAttributes, + metrics: { includeSessionId: metricsIncludeSessionId }, +}; +``` + +### 5.4 `sdk.ts` Resource 构造改动 + +```ts +const userAttrs = config.getTelemetryResourceAttributes(); +// service.version is always built-in; service.name flows through userAttrs +// (it was already resolved with OTEL_SERVICE_NAME precedence in resolver). +const builtinServiceName = userAttrs['service.name'] ?? SERVICE_NAME; +const { 'service.name': _, 'service.version': __, ...nonReserved } = userAttrs; + +const resource = resourceFromAttributes({ + ...nonReserved, + [SemanticResourceAttributes.SERVICE_NAME]: builtinServiceName, + [SemanticResourceAttributes.SERVICE_VERSION]: + config.getCliVersion() || 'unknown', + // session.id deliberately NOT placed on Resource — see design doc §4.1 +}); +``` + +### 5.5 `settingsSchema.ts` 改动 + +`packages/cli/src/config/settingsSchema.ts:998-1018` 的 `telemetry.jsonSchemaOverride.properties` 加： + +```ts +{ + // ... existing includeSensitiveSpanAttributes + resourceAttributes: { + type: 'object', + additionalProperties: { type: 'string' }, + description: + 'Static resource attributes attached to all telemetry data. ' + + 'Keys must be strings; values must be strings. ' + + 'Reserved keys (service.name, service.version) are silently dropped.', + default: {}, + }, + metrics: { + type: 'object', + additionalProperties: false, + properties: { + includeSessionId: { + type: 'boolean', + default: false, + description: + 'Include session.id on every metric data point. ' + + 'WARNING: each CLI session creates a new value, causing unbounded ' + + 'metric time-series fan-out. Only enable for short-term debugging.', + }, + }, + }, +} +``` + +也要把 `additionalProperties: true` 重新评估——目前是 permissive，可以保留也可以转 strict。建议保留 permissive，避免对其他未在 schema 中声明的 `telemetry.*` 字段产生破坏性变更，但 docs 里明确"未声明字段会被忽略"。 + +## 6. 文件改动清单 + +| 文件 | 改动 | +| -------------------------------------------------------------- | -------------------------------------------------------------------------- | +| `packages/core/src/telemetry/sdk.ts` | 改 Resource 构造（合并 user attrs，删 `session.id`） | +| `packages/core/src/telemetry/resource-attributes.ts` (新文件) | `parseOtelResourceAttributes()` + `RESERVED_RESOURCE_ATTRIBUTE_KEYS` 常量 | +| `packages/core/src/telemetry/config.ts` | resolver 加 `resourceAttributes` + `metrics.includeSessionId` 解析与 merge | +| `packages/core/src/telemetry/metrics.ts` | `getCommonAttributes()` 加 toggle gate | +| `packages/core/src/config/config.ts` | `TelemetrySettings` schema + 两个 getter | +| `packages/cli/src/config/settingsSchema.ts` | `jsonSchemaOverride` 加 `resourceAttributes` + `metrics` | +| `docs/developers/development/telemetry.md` | 加 "Resource attributes" + "Cardinality controls" 两节 + 迁移说明 + 示例 | +| `packages/core/src/telemetry/resource-attributes.test.ts` (新) | 解析器单元测试（覆盖 §4.6 全部用例） | +| `packages/core/src/telemetry/sdk.test.ts` | merge 优先级 / 保留键 / `OTEL_SERVICE_NAME` | +| `packages/core/src/telemetry/metrics.test.ts` | toggle off/on 时 `session.id` 出现与否 | +| `packages/core/src/telemetry/config.test.ts` | env / settings 合并 | +| `CHANGELOG.md` 或 release notes | PR 2 的 breaking change 说明 | + +## 7. 分 PR 拆分 + +按 review 友好性与 blast radius 分三个 PR： + +### PR 1 — Custom resource attributes（additive，零破坏） + +- 新文件 `resource-attributes.ts`：`parseOtelResourceAttributes()` + `RESERVED_RESOURCE_ATTRIBUTE_KEYS` +- `TelemetrySettings.resourceAttributes` 字段 + resolver merge 逻辑 +- `OTEL_SERVICE_NAME` / `OTEL_RESOURCE_ATTRIBUTES` 接入，按 §4.2 优先级 +- 合并进 Resource（`sdk.ts`） +- `settingsSchema.ts` 加 `resourceAttributes` JSON schema +- **不动** `session.id` 在 Resource 上的位置 +- Docs 加 "Resource attributes" 一节 + +**风险**：低。完全 additive，不改任何现有行为。除非用户主动设置环境变量或 settings，否则导出的数据无变化。 + +### PR 2 — Cardinality controls（semantic break） + +- 从 Resource 删 `session.id` (`sdk.ts:160` 那一行) +- 加 `metrics.includeSessionId` toggle（settings + env）+ `getCommonAttributes()` gate +- `settingsSchema.ts` 加 `metrics` JSON schema +- CHANGELOG / 迁移说明 +- 快照测试锁定 metric attribute 集合（防回归） +- Docs 加 "Cardinality controls" 一节 + 迁移指南 + +**风险**：中等。任何依赖 metric 上 `session.id` 的 Prometheus query / Grafana dashboard / 告警规则会失效。需要显式 release note 与 1-2 个版本的迁移窗口。 + +**Opt-in 过渡方案**（候选，本期建议**不采用**）： + +> PR 2 可先以"opt-out"形式落地——默认仍把 `session.id` 注入 metric，但加 warn log "this default will flip in v0.X"。一个 release 后再翻转默认。 + +不建议采用的原因：（1）当前 qwen-code 用户群不大，破坏面有限；（2）这是 cardinality bug，越早默认安全越好；（3）双段式发布会增加文档负担。如果父 issue owner 想要保守一些，可以采纳。 + +### PR 3 — Docs polish + samples（cleanup） + +- `docs/developers/development/telemetry.md` 补示例（见 §10） +- 阿里云 ARMS / Prometheus / Grafana 接入示例 +- 把所有典型 use case 的 settings.json 片段加进去 + +## 8. 测试计划 + +### 8.1 `parseOtelResourceAttributes()` 单元测试 + +参数化覆盖 §4.6 表格全部行（建议用 vitest `it.each`）： + +```ts +it.each([ + ['', {}], + ['a=1', { a: '1' }], + ['a=1,b=2', { a: '1', b: '2' }], + ['a=hello%20world', { a: 'hello world' }], + ['a=val%ZZbad', { a: 'val%ZZbad' }], // invalid percent + ['malformed', {}], + ['=val', {}], + ['a=', { a: '' }], + ['a=1,a=2', { a: '2' }], + [' a = 1 , b = 2 ', { a: '1', b: '2' }], +])('parses %j → %j', (input, expected) => { + expect(parseOtelResourceAttributes(input)).toEqual(expected); +}); +``` + +### 8.2 Resolver merge 测试 + +| 场景 | 期望 `service.name` | 期望 user attr | +| ----------------------------------------------------------------------- | ----------------------------------------------------- | ------------------------------------ | +| 全空 | `'qwen-code'` | 不存在 | +| 仅 env `OTEL_SERVICE_NAME=A` | `'A'` | — | +| 仅 env `OTEL_RESOURCE_ATTRIBUTES=service.name=B` | `'B'` | — | +| `OTEL_SERVICE_NAME=A` + `OTEL_RESOURCE_ATTRIBUTES=service.name=B` | `'A'`（OTEL_SERVICE_NAME 优先） | — | +| `OTEL_SERVICE_NAME=A` + `settings={service.name:C}` | `'A'`（OTEL_SERVICE_NAME 优先） | — | +| `OTEL_RESOURCE_ATTRIBUTES=service.name=B` + `settings={service.name:C}` | `'C'`（settings 优先于 env，无 OTEL_SERVICE_NAME 时） | — | +| `OTEL_RESOURCE_ATTRIBUTES=team=x` + `settings={team:y}` | `'qwen-code'` | `team='y'`（settings 优先） | +| `OTEL_RESOURCE_ATTRIBUTES=service.version=fake` | `'qwen-code'` + warn | service.version 仍为真实 cli version | +| `settings={service.version:fake}` | `'qwen-code'` + warn | service.version 仍为真实 cli version | + +### 8.3 Resource 内容快照测试 + +用 `InMemorySpanExporter` 拿一个 span，断言： + +```ts +expect(span.resource.attributes['service.name']).toBe('qwen-code'); +expect(span.resource.attributes['service.version']).toBe(EXPECTED_VERSION); +expect(span.resource.attributes['session.id']).toBeUndefined(); // 关键 +expect(span.resource.attributes['team']).toBe('platform'); // 用户加的 +``` + +### 8.4 Metric attribute toggle 测试 + +```ts +it('does not emit session.id on metrics by default', async () => { + // emit one tool call counter + recordToolCallMetrics(...); + const data = await metricReader.collect(); + const dp = data.resourceMetrics.scopeMetrics[0].metrics[0].dataPoints[0]; + expect(dp.attributes['session.id']).toBeUndefined(); +}); + +it('emits session.id when toggle is true', async () => { + config.telemetrySettings.metrics = { includeSessionId: true }; + recordToolCallMetrics(...); + const data = await metricReader.collect(); + const dp = data.resourceMetrics.scopeMetrics[0].metrics[0].dataPoints[0]; + expect(dp.attributes['session.id']).toBe(KNOWN_SESSION_ID); +}); +``` + +### 8.5 Spans / Logs 行为保持测试 + +- spans 仍有 `session.id`（不受 metric toggle 影响） +- logs 仍有 `session.id`（不受 metric toggle 影响） + +### 8.6 回归保护 + +- `autoDetectResources: false` 保持不变（assertion on config） +- 启动期间不出现新增 `diag.error`（捕获 OTel diag 日志做 assertion） +- 现有所有 telemetry 测试通过（CI） + +### 8.7 Diag warn 测试 + +校验下列输入都触发 `diag.warn` 一次： + +- `settings.resourceAttributes = { 'service.version': 'x' }`（reserved） +- `OTEL_RESOURCE_ATTRIBUTES=service.version=x`（reserved，env 也要 warn） +- `OTEL_RESOURCE_ATTRIBUTES=malformed`（无 `=`） +- `OTEL_RESOURCE_ATTRIBUTES=a=val%ZZ`（无效 percent-encoding） + +校验下列输入**不**触发 warn（合法路径）： + +- `settings.resourceAttributes = { 'service.name': 'x' }`（settings 允许设 service.name） +- `OTEL_SERVICE_NAME=foo` + `settings.resourceAttributes = { 'service.name': 'bar' }`（OTEL_SERVICE_NAME 优先即可，不需要 warn） + +## 9. 迁移 / 破坏性变更 + +### 9.1 破坏性变更（PR 2） + +**指标上的 `session.id` 默认消失**。这会影响： + +- Prometheus query 中 `by (session_id)` / `group_left(session_id)` 的聚合 +- Grafana dashboard 中按 session 切片的图 +- 任何按 session.id 做告警分组的规则 + +注：spans 和 logs 上的 `session.id` **不受影响**。 + +### 9.2 迁移路径 + +文档里给两个选项： + +**选项 A**：恢复旧行为（短期 debug 推荐） + +```bash +export QWEN_TELEMETRY_METRICS_INCLUDE_SESSION_ID=true +``` + +或 `settings.json`： + +```json +{ + "telemetry": { + "metrics": { "includeSessionId": true } + } +} +``` + +⚠️ **警告**：长期开启会让 metric time-series 数量 = 历史 session 数量，撑爆后端。仅短期 debug 用。 + +**选项 B**：改用 spans / logs 做 session 切片（推荐） + +- spans / logs 上仍有 `session.id`，可在 trace backend（如 Jaeger / Aliyun ARMS Tracing）/ log backend（如 Loki / SLS）按 session 切片 +- 这两类数据本来就是 per-event 存储，cardinality 不会爆炸 +- 适合做 session-level drill-down 分析 + +### 9.3 Release note 模板 + +``` +**Breaking change (metric attribute):** + +The `session.id` attribute is no longer attached to metric data +points by default. This protects metric backends from unbounded +time-series fan-out. + +- Spans and logs are unaffected — `session.id` is still present. +- To restore the previous behavior (short-term debugging only), set + `QWEN_TELEMETRY_METRICS_INCLUDE_SESSION_ID=true` or in settings.json: + `telemetry.metrics.includeSessionId: true`. +- For long-term session correlation, query against trace / log + backends instead of metric backends. + +See docs/developers/development/telemetry.md "Migration" for details. +``` + +## 10. 示例配置（用于文档） + +### 10.1 按 team / env 切片所有 telemetry + +```bash +export OTEL_RESOURCE_ATTRIBUTES="team=platform,env=prod,cost_center=eng-123" +``` + +效果：所有 span / log / metric 都带 `team=platform` `env=prod` `cost_center=eng-123`。 + +### 10.2 用 `OTEL_SERVICE_NAME` 在共享 collector 中路由 + +```bash +export OTEL_SERVICE_NAME=qwen-code-ci +``` + +效果：`service.name=qwen-code-ci`，多租户 OTel collector 可按 service.name 路由到不同后端。 + +### 10.3 Fleet baseline + 单机 override + +公司 fleet 的 `~/.qwen/settings.json`（GitOps 分发）： + +```json +{ + "telemetry": { + "resourceAttributes": { + "deployment.environment": "production", + "service.namespace": "engineering-tooling" + } + } +} +``` + +单机 ops 临时覆盖（不修改 settings）： + +```bash +export OTEL_RESOURCE_ATTRIBUTES="debug_run=true" +# settings 里的 deployment.environment / service.namespace 仍然生效 +# 同时这次运行额外带 debug_run=true +``` + +### 10.4 短期 debug 打开 metric session.id + +```bash +# 一次性 debug run +QWEN_TELEMETRY_METRICS_INCLUDE_SESSION_ID=true qwen "投资分析" +``` + +完事即关闭，不要持久化到 settings。 + +### 10.5 阿里云 ARMS Metric 接入（推荐配置） + +```json +{ + "telemetry": { + "enabled": true, + "otlpEndpoint": "http:///api/v1/...", + "otlpProtocol": "http", + "resourceAttributes": { + "team": "platform", + "deployment.environment": "production" + }, + "metrics": { + "includeSessionId": false + } + } +} +``` + +## 11. 与 claude-code 实现的对比 + +| 维度 | claude-code | qwen-code 本设计 | 决策依据 | +| -------------------------- | ------------------------------------------------ | ------------------------------------------------ | -------------------------------------------------- | +| 标准 OTel env var | `OTEL_RESOURCE_ATTRIBUTES` / `OTEL_SERVICE_NAME` | ✅ 一致 | 标准契约 | +| `OTEL_SERVICE_NAME` 优先级 | 遵守 OTel 规范 | ✅ 遵守 | spec 明确规定 | +| Cardinality 开关命名 | `OTEL_METRICS_INCLUDE_*` | `QWEN_TELEMETRY_METRICS_INCLUDE_*` | 不污染标准 OTel 命名空间 | +| 开关作用域 | 仅 metric | ✅ 仅 metric | spans / logs 是 per-event，无 cardinality 爆炸问题 | +| 默认值 | 高基数 attribute 默认 false | ✅ 默认 false | 安全优先 | +| Per-attribute granularity | 每 attribute 一个 toggle | ✅ 一致 | 灵活，符合实际诊断需求 | +| settings.json 等价物 | ❌ 无 | ✅ 有 `telemetry.resourceAttributes` + `metrics` | 企业 fleet 部署 base config | +| Per-span 动态 hook | ❌ 无 | ❌ 无 | 复杂度高，claude-code 也没解，本期不做 | +| 多租户 `account_uuid` | 有 | ❌ 无 | qwen-code metric 里没有此 attr | +| Agent SDK `options.env` | 有 | ❌ 无 | qwen-code 没有等价模式 | +| 保留键策略 | 不允许覆盖 built-in id | ✅ 一致 | 遥测可信度 | +| 第一方上报通道 | claude-code 也有独立第一方通道（与 OTel 隔离） | ✅ qwen-logger 同样隔离 | 第一方与第三方通道职责分离 | + +**最值得借的两点**： + +1. **命名约定**：`*_INCLUDE_*` 一眼能看出语义，比反义命名（`*_EXCLUDE_*` / `*_DROP_*`）清晰 +2. **范围克制**：只 gate metric，不 gate span/log——claude-code 显然踩过这个边界，我们直接受益 + +**qwen-code 做得更好的点**： + +- settings.json 支持：claude-code 完全靠 env var，对企业 fleet 场景不友好 +- 明确的保留键策略（`service.version` 不可覆盖）：减少遥测被污染的可能 +- 第一方上报隔离：qwen-logger 走独立通道，与用户 OTLP 设置完全解耦 + +## 12. 未来工作（v2 + 候选） + +- **`service.version` cardinality 控制**：用 OTel View API 在 metric 层 drop attribute +- **更多 cardinality toggle**：未来若 metric 上引入 `user.account_uuid` / `model` 等，按需补 toggle +- **Per-span 动态 attribute hook**：可借鉴 qwen-code 自家 hooks 系统，加 `OnSpanStart(span, context) => attrs` 回调。需要独立设计。 +- **Resource attribute schema 校验**：限制 key 命名空间（如禁止覆盖 `service.*` 前缀以外的内建 attr），目前靠保留键列表硬编码够用。 +- **Hot reload Resource**：当 settings.json 在进程内被修改（设想 qwen-serve daemon 场景），目前不会重建 Resource。若 daemon 场景成熟，可以增加一条 reload 路径。 +- **跨进程 subagent context 传播**：subagent 跨进程时，把 parent 的 trace context（包括 resource）通过 OTel context propagation 标准 header 传过去。需要独立设计。 diff --git a/docs/design/worktree.md b/docs/design/worktree.md index 4de9968b7aa..8c9d4f0d56d 100644 --- a/docs/design/worktree.md +++ b/docs/design/worktree.md @@ -8,23 +8,23 @@ qwen-code 目前仅有面向 Arena 多模型对比场景的内部 worktree 实 ## 现状对比 -| 功能 | qwen-code | claude-code | -| --------------------------------- | --------------- | ----------- | -| `EnterWorktree` 工具 | ❌ | ✅ | -| `ExitWorktree` 工具 | ❌ | ✅ | -| AgentTool `isolation: 'worktree'` | ❌ | ✅ | -| worktree 会话状态持久化与恢复 | ❌ | ✅ | -| 过期 worktree 自动清理 | ❌ | ✅ | -| Post-creation setup（hooks 配置） | ❌ | ✅ | -| StatusLine worktree 状态展示 | ❌ | ✅ | -| WorktreeExitDialog（退出提示） | ❌ | ✅ | -| 符号链接目录（node_modules 等） | ❌ | ✅ | -| sparse checkout | ❌ | ✅ | -| `--worktree` CLI 启动标志 | ❌ | ✅ | -| tmux 集成 | ❌ | ✅ | -| Arena 多模型 worktree 隔离 | ✅（qwen 独有） | ❌ | -| 脏状态覆盖（stash + copy） | ✅ | ✅ | -| Baseline commit 追踪 | ✅（qwen 独有） | ❌ | +| 功能 | qwen-code | claude-code | 阶段 | +| --------------------------------- | --------------- | ----------- | ------- | +| `EnterWorktree` 工具 | ✅（Phase A） | ✅ | — | +| `ExitWorktree` 工具 | ✅（Phase A） | ✅ | — | +| AgentTool `isolation: 'worktree'` | ✅（Phase B） | ✅ | — | +| 过期 worktree 自动清理 | ✅（Phase B） | ✅ | — | +| worktree 会话状态持久化与恢复 | ❌ | ✅ | Phase C | +| Post-creation setup（hooks 配置） | ❌ | ✅ | Phase C | +| StatusLine worktree 状态展示 | ❌ | ✅ | Phase C | +| WorktreeExitDialog（退出提示） | ❌ | ✅ | Phase C | +| `--worktree` CLI 启动标志 | ❌ | ✅ | Phase D | +| 符号链接目录（node_modules 等） | ❌ | ✅ | Phase D | +| sparse checkout | ❌ | ✅ | Future | +| tmux 集成 | ❌ | ✅ | Future | +| Arena 多模型 worktree 隔离 | ✅（qwen 独有） | ❌ | — | +| 脏状态覆盖（stash + copy） | ✅ | ✅ | — | +| Baseline commit 追踪 | ✅（qwen 独有） | ❌ | — | ## 设计原则 @@ -54,14 +54,14 @@ AgentTool 的 `isolation: 'worktree'` 只走通用路径，Arena 内部不经过 Arena 的 worktree 路径由 `agents.arena.worktreeBaseDir` 控制，默认 `~/.qwen/arena`（`ArenaManager.ts:125`），与通用路径完全独立，不做任何改动。 -### 扩展配置（暂缓至 Phase C/D） +### 扩展配置 | 配置项 | 类型 | 用途 | 阶段 | | ----------------------------- | ---------- | -------------------------------------------------------------- | ------- | -| `worktree.symlinkDirectories` | `string[]` | 符号链接指定目录（如 `node_modules`）到 worktree，避免磁盘浪费 | Phase C | -| `worktree.sparsePaths` | `string[]` | git sparse-checkout cone 模式，大型 monorepo 只写入指定路径 | Phase D | +| `worktree.symlinkDirectories` | `string[]` | 符号链接指定目录（如 `node_modules`）到 worktree，避免磁盘浪费 | Phase D | +| `worktree.sparsePaths` | `string[]` | git sparse-checkout cone 模式，大型 monorepo 只写入指定路径 | Future | -Phase A / B 不新增任何配置项。 +Phase A / B / C 不新增任何配置项。 ## 工具设计 @@ -187,27 +187,88 @@ _无需改动：_ --- -### Phase C：体验优化（Post-creation setup + UI） +### Phase C：会话完整性（SessionService 持久化 + UI 安全网） -**目标：** worktree 创建后自动初始化环境，状态在界面上可见。 +**目标：** worktree 状态在会话中断后可恢复，用户在界面上始终知道自己在哪个 worktree 里，退出会话时有安全提示。 **要实现的功能：** -- Post-creation setup：配置 `core.hooksPath` 指向主仓库（qwen-code 无 `settings.local.json` 概念，不需要复制） -- StatusLine 展示当前 worktree 名称 / 分支 -- WorktreeExitDialog：会话退出时（检测到 worktree 仍活跃）提示用户选择 keep 或 remove -- 新增 `worktree.symlinkDirectories` 配置项，实现目录符号链接 +_SessionService worktree 状态持久化 + `--resume` 恢复：_ + +- `SessionService` 扩展 `WorktreeSession` 字段，记录 `{ slug, worktreePath, worktreeBranch, originalCwd, originalBranch }` +- `EnterWorktreeTool` 调用 `sessionService.setWorktreeSession()` 写入状态 +- `ExitWorktreeTool` 调用 `sessionService.clearWorktreeSession()` 清除状态 +- `--resume` 启动路径读取该字段，恢复 `targetDir` 并向模型注入上下文提示 + +_Post-creation setup：_ + +- 创建 worktree 后自动执行 `git config core.hooksPath /.git/hooks`，确保 worktree 内的提交与主仓库 hooks 行为一致 + +_StatusLine worktree 展示：_ + +- `UIStateContext` 新增 `activeWorktree` 字段（从 session 状态读取），在会话进入 / 退出 worktree 时更新 +- `StatusLineCommandInput` payload 新增 `worktree?: { slug: string; branch: string }` 字段，供用户 statusline 脚本使用 +- `Footer` 在 `activeWorktree` 非空时内置展示一行 `⎇ ()`，无需用户配置 statusline 脚本即可获得基本可见性 + +_WorktreeExitDialog：_ + +- 新增 `WorktreeExitDialog.tsx` 组件，参考现有 Dialog 写法 +- 修改退出键（Ctrl+C / Ctrl+D）处理逻辑：检测到 `activeWorktree` 非空时，拦截第二次确认，展示 Dialog 提示用户选择 keep 或 remove +- keep / remove 操作复用 `ExitWorktreeTool` 的现有路径 + +**影响文件：** + +| 文件 | 变更类型 | +| ------------------------------------------------------------- | ----------------------------------------------------------------------------- | +| `packages/core/src/services/sessionService.ts` | 新增 `WorktreeSession` 字段及读写方法 | +| `packages/core/src/tools/enter-worktree.ts` | 调用 `sessionService.setWorktreeSession()` | +| `packages/core/src/tools/exit-worktree.ts` | 调用 `sessionService.clearWorktreeSession()` | +| `packages/core/src/services/gitWorktreeService.ts` | `createUserWorktree()` / `createAgentWorktree()` 后追加 `core.hooksPath` 配置 | +| `packages/cli/src/ui/contexts/UIStateContext.tsx` | 新增 `activeWorktree` 字段及 set/clear action | +| `packages/cli/src/ui/hooks/useStatusLine.ts` | `StatusLineCommandInput` 新增 `worktree` 字段 | +| `packages/cli/src/ui/components/Footer.tsx` | 内置 worktree 行展示 | +| `packages/cli/src/ui/components/WorktreeExitDialog.tsx` | 新建 | +| `packages/cli/src/ui/components/DialogManager.tsx` | 注册 `WorktreeExitDialog` | +| `packages/cli/src/ui/components/ExitWarning.tsx` 或退出键处理 | 检测 `activeWorktree` 并拦截退出 | --- -### Phase D：高级功能 +### Phase D：启动时配置（`--worktree` CLI 标志 + 目录符号链接） -**目标：** 对齐 claude-code 的完整特性集。 +**目标：** 支持在启动时直接进入 worktree，并通过目录符号链接减少大型项目的磁盘开销。 **要实现的功能：** -- `--worktree [name]` CLI 启动标志：启动时直接创建 worktree，整个会话在隔离环境中运行 -- sparse checkout 支持：新增 `worktree.sparsePaths` 配置项 -- `.worktreeinclude` 文件：支持将 gitignore 的文件复制到 worktree -- tmux 集成：`--worktree --tmux` 在 tmux 会话中启动 -- PR 引用解析：`--worktree=#123` 自动 fetch 并基于 PR 创建 worktree +_`--worktree [name]` CLI 启动标志：_ + +- `packages/cli/src/args.ts` 新增 `--worktree [name]` 参数 +- 启动流程在进入主循环前调用 `createUserWorktree()`，将 `targetDir` 设为 worktree 路径，并写入 SessionService 状态 +- 整个会话从启动即在 worktree 环境中运行，退出时触发 WorktreeExitDialog + +_`worktree.symlinkDirectories` 配置项：_ + +- settings schema 新增 `worktree.symlinkDirectories: string[]` +- `createUserWorktree()` 后遍历配置，调用 `fs.symlink()` 将主仓库目录链接进 worktree +- 跳过目标不存在的项；目标已存在时跳过（不覆盖） + +**影响文件：** + +| 文件 | 变更类型 | +| -------------------------------------------------- | ------------------------------------------- | +| `packages/cli/src/args.ts` | 新增 `--worktree [name]` 参数 | +| `packages/cli/src/main.ts`（或启动入口） | 解析 `--worktree` 并在主循环前创建 worktree | +| `packages/core/src/services/gitWorktreeService.ts` | `createUserWorktree()` 后追加 symlink 逻辑 | +| `packages/core/src/config/`（settings schema） | 新增 `worktree.symlinkDirectories` 字段 | + +--- + +### Future：高级功能（按需实现） + +以下功能面向更特定的使用场景，当前阶段不纳入排期，待用户需求明确后再评估实现。 + +| 功能 | 说明 | +| ----------------------- | ------------------------------------------------------------------------------------------- | +| sparse checkout | `worktree.sparsePaths` 配置项，大型 monorepo 只 checkout 指定路径，缩短创建时间和磁盘占用 | +| `.worktreeinclude` 文件 | 将 gitignore 的文件（`.env`、`secrets.json` 等）自动复制进 worktree | +| tmux 集成 | `--worktree --tmux` 在新 tmux 窗口启动 worktree 会话 | +| PR 引用解析 | `--worktree=#123` 自动 fetch PR 分支并基于它创建 worktree（依赖 Phase D `--worktree` 标志） | diff --git a/docs/developers/development/telemetry.md b/docs/developers/development/telemetry.md index 1cd31a96916..a0069fe671e 100644 --- a/docs/developers/development/telemetry.md +++ b/docs/developers/development/telemetry.md @@ -66,6 +66,8 @@ These settings can be overridden by environment variables or CLI flags. | `outfile` | `QWEN_TELEMETRY_OUTFILE` | `--telemetry-outfile ` | Save telemetry to file (overrides OTLP export) | file path | - | | `logPrompts` | `QWEN_TELEMETRY_LOG_PROMPTS` | `--telemetry-log-prompts` / `--no-telemetry-log-prompts` | Include prompts in telemetry logs | `true`/`false` | `true` | | `includeSensitiveSpanAttributes` | `QWEN_TELEMETRY_INCLUDE_SENSITIVE_SPAN_ATTRIBUTES` | - | Include user prompts, system prompts, tool I/O, and model output as native span attributes (in addition to log-to-span bridge spans) | `true`/`false` | `false` | +| `resourceAttributes` | `OTEL_RESOURCE_ATTRIBUTES` (+ `OTEL_SERVICE_NAME`) | - | Static resource attributes attached to every exported span / log / metric. See [Resource attributes](#resource-attributes) below. | `key=value,…` | `{}` | +| `metrics.includeSessionId` | `QWEN_TELEMETRY_METRICS_INCLUDE_SESSION_ID` | - | Include `session.id` on metric data points. **Disabled by default** to protect metric backends from time-series fan-out. | `true`/`false` | `false` | **Note on boolean environment variables:** For the boolean settings (`enabled`, `logPrompts`, `includeSensitiveSpanAttributes`), setting the @@ -125,6 +127,141 @@ The `QWEN_TELEMETRY_OTLP_*` variants take precedence over the `OTEL_*` variants. For detailed information about all configuration options, see the [Configuration Guide](./cli/configuration.md). +### Resource attributes + +Resource attributes are static key-value pairs attached to every span, log, +and metric exported via OTLP. Use them to slice telemetry by team, environment, +deployment region, or any other dimension your backend cares about. + +Two sources, merged in priority order (lowest → highest): + +1. The standard `OTEL_RESOURCE_ATTRIBUTES` env var +2. `telemetry.resourceAttributes` in `.qwen/settings.json` (overrides env on + key conflict) + +`OTEL_SERVICE_NAME` is a separate escape hatch — when set, it overrides +`service.name` from any other source (per the OpenTelemetry spec). + +#### Examples + +**Slice all telemetry by team / environment:** + +```bash +export OTEL_RESOURCE_ATTRIBUTES="team=platform,env=prod,cost_center=eng-123" +``` + +**Route to a per-tenant collector via `service.name`:** + +```bash +export OTEL_SERVICE_NAME=qwen-code-ci +``` + +**Fleet baseline (`~/.qwen/settings.json`) + per-host override:** + +```json +{ + "telemetry": { + "resourceAttributes": { + "deployment.environment": "production", + "service.namespace": "engineering-tooling" + } + } +} +``` + +```bash +# Add a one-off tag without touching settings: +export OTEL_RESOURCE_ATTRIBUTES="debug_run=true" +``` + +#### Reserved keys + +Some keys are runtime-controlled and cannot be overridden: + +- `service.version` — always set to the running CLI version. Setting it from + any source is silently dropped with a warning. +- `session.id` — runtime-injected per session. User-provided values from + either env or settings are dropped with a warning. The reason is that + Resource attributes auto-attach to every metric data point; allowing user + override would bypass [Cardinality controls](#cardinality-controls) below. + Spans and logs always carry `session.id`. + +`service.name` is **not** reserved; it follows the precedence chain above. + +#### Format + +`OTEL_RESOURCE_ATTRIBUTES` follows the OpenTelemetry spec: +`key1=value1,key2=value2` with values percent-encoded. Spaces in values must +be encoded as `%20`, **commas as `%2C`** (unencoded commas split the value at +the wrong boundary and the second half is dropped as malformed). Malformed +pairs are skipped with a warning rather than failing telemetry startup. + +#### Troubleshooting: when a user-provided attribute appears not to take effect + +Reserved keys (`service.version`, `session.id`), malformed pairs, non-string +settings values, and invalid percent-encoding are all silently dropped with a +warning logged via the OpenTelemetry diagnostics channel. That channel routes +to the debug log file (`~/.qwen/log/otel-*.log`), **not** the console, so the +behavior can look like silent failure. + +If a custom resource attribute isn't appearing on exported telemetry: + +1. Check `~/.qwen/log/otel-*.log` for lines matching `cannot override` (reserved + key dropped), `Skipping malformed` (bad env var pair), or `must be a string` + (non-string settings value). +2. Verify the env var is set in the qwen-code process's environment (not just + your shell) and that values are percent-encoded. +3. Confirm `telemetry.enabled` is `true` — telemetry init only runs if enabled. + +### Cardinality controls + +Metrics are aggregated by attribute set at the backend — every distinct +combination of attribute values produces a new time series. Attaching a +high-cardinality field like `session.id` to a metric causes time-series fan-out +proportional to the number of sessions, which quickly exhausts metric backend +storage. + +To prevent this, Qwen Code keeps high-cardinality attributes off metric data +points by default. Spans and logs are per-event and unaffected, so they +continue to carry `session.id` for trace and log correlation. + +#### `telemetry.metrics.includeSessionId` (default: `false`) + +Setting this to `true` (via settings or +`QWEN_TELEMETRY_METRICS_INCLUDE_SESSION_ID=true`) re-attaches `session.id` to +every metric data point. + +⚠️ **Warning:** each CLI session creates a new value. Leaving this on for a +fleet will blow up metric storage. Recommended only for short-term debugging. +For long-term session correlation, query trace or log backends instead. + +#### Migration from earlier versions + +Prior to this release, `session.id` was attached to metrics by default. If +your Prometheus queries / Grafana dashboards / alert rules reference +`session_id` on a metric, you have two options: + +**Option A** — restore the previous behavior for short-term debugging: + +```bash +export QWEN_TELEMETRY_METRICS_INCLUDE_SESSION_ID=true +``` + +or: + +```json +{ + "telemetry": { + "metrics": { "includeSessionId": true } + } +} +``` + +**Option B (recommended)** — move session-level analysis off metrics. Spans +and logs still carry `session.id`, and trace / log backends (Jaeger, Tempo, +Loki, Aliyun SLS / ARMS Tracing) handle per-session slicing natively without +cardinality pressure. + ## Aliyun Telemetry ### Manual OTLP Export diff --git a/docs/developers/qwen-serve-protocol.md b/docs/developers/qwen-serve-protocol.md index 84eaddc56c7..dc5b96066d5 100644 --- a/docs/developers/qwen-serve-protocol.md +++ b/docs/developers/qwen-serve-protocol.md @@ -1129,7 +1129,7 @@ Request: { "mode": "auto-edit", "persist": false } ``` -`mode` must be one of `'plan' | 'default' | 'auto-edit' | 'yolo'` (mirror of core's `ApprovalMode` enum; the SDK exports `DAEMON_APPROVAL_MODES` for runtime validation). `persist` defaults to `false`. +`mode` must be one of `'plan' | 'default' | 'auto-edit' | 'auto' | 'yolo'` (mirror of core's `ApprovalMode` enum; the SDK exports `DAEMON_APPROVAL_MODES` for runtime validation). `persist` defaults to `false`. Response (200): diff --git a/docs/developers/sdk-java.md b/docs/developers/sdk-java.md index d3eab983c57..8e2a8dbfec2 100644 --- a/docs/developers/sdk-java.md +++ b/docs/developers/sdk-java.md @@ -144,7 +144,7 @@ The SDK supports different permission modes for controlling tool execution: - **`default`**: Write tools are denied unless approved via `canUseTool` callback or in `allowedTools`. Read-only tools execute without confirmation. - **`plan`**: Blocks all write tools, instructing AI to present a plan first. -- **`auto-edit`**: Auto-approve edit tools (edit, write_file) while other tools require confirmation. +- **`auto-edit`**: Auto-approve edit tools (`edit`, `write_file`, `notebook_edit`) while other tools require confirmation. - **`yolo`**: All tools execute automatically without confirmation. ### Session Event Consumers and Assistant Content Consumers diff --git a/docs/developers/sdk-typescript.md b/docs/developers/sdk-typescript.md index 8ba590997d6..a3de0f2e57e 100644 --- a/docs/developers/sdk-typescript.md +++ b/docs/developers/sdk-typescript.md @@ -158,7 +158,7 @@ The SDK supports different permission modes for controlling tool execution: - **`default`**: Write tools are denied unless approved via `canUseTool` callback or in `allowedTools`. Read-only tools execute without confirmation. - **`plan`**: Blocks all write tools, instructing AI to present a plan first. -- **`auto-edit`**: Auto-approve edit tools (edit, write_file) while other tools require confirmation. +- **`auto-edit`**: Auto-approve edit tools (`edit`, `write_file`, `notebook_edit`) while other tools require confirmation. - **`yolo`**: All tools execute automatically without confirmation. ### Permission Priority Chain diff --git a/docs/developers/tools/file-system.md b/docs/developers/tools/file-system.md index 118f5e0b6d8..d07fd805c6b 100644 --- a/docs/developers/tools/file-system.md +++ b/docs/developers/tools/file-system.md @@ -44,7 +44,72 @@ Qwen Code provides a comprehensive suite of tools for interacting with the local - For other binary files: A message like `Cannot display content of binary file: /path/to/data.bin`. - **Confirmation:** No. -## 3. `write_file` (WriteFile) +### Jupyter notebook reads + +For Jupyter notebooks (`.ipynb`), `read_file` parses the notebook JSON and returns a structured, model-readable notebook view instead of raw JSON. The rendered output includes the notebook language, ordered cells, cell IDs, source, and summarized outputs. + +Notebook cells can then be edited with `notebook_edit`. The model should use the cell IDs shown by `read_file` when targeting a cell. + +`offset` and `limit` are not supported for `.ipynb` files. Notebook reads are treated as structured full-file reads; if the rendered notebook output is internally truncated because it is too large, `notebook_edit` will reject cell-level edits and ask you to reduce outputs or split the notebook before editing. + +## 3. `notebook_edit` (NotebookEdit) + +`notebook_edit` edits Jupyter notebook (`.ipynb`) files safely at the cell level. Use it instead of `edit` or `write_file` when changing notebook cells. + +- **Tool name:** `notebook_edit` +- **Display name:** NotebookEdit +- **File:** `notebook-edit.ts` +- **Parameters:** + - `notebook_path` (string, required): The absolute path to the `.ipynb` file. + - `cell_id` (string, optional): The target cell ID shown by `read_file`. Required for `replace` and `delete`. For `insert`, the new cell is inserted after this cell; if omitted, the new cell is inserted at the beginning. + - `new_source` (string, optional): The new cell source for `replace` and `insert`. Not required for `delete`. + - `cell_type` (`code` or `markdown`, optional): The cell type for inserted cells, or the target type when replacing a cell. + - `edit_mode` (`replace`, `insert`, or `delete`, optional): The edit operation. Defaults to `replace`. +- **Behavior:** + - Requires the notebook to have been read first with `read_file` in the current session. + - Targets cells using the IDs rendered by `read_file`, including real notebook cell IDs and displayed `cell-N` fallback IDs. + - Rejects ambiguous rendered cell IDs instead of guessing. + - For code cells, clears stale outputs and resets `execution_count` when source changes. + - Preserves notebook JSON formatting, line endings, encoding, and BOM where possible. + - Invalidates the prior-read state after structural edits when displayed fallback IDs can shift, so the next notebook edit requires a fresh `read_file`. +- **Output (`llmContent`):** A success message describing the edited notebook cell and, for non-delete operations, the updated source. +- **Confirmation:** Yes. Shows a notebook JSON diff and asks for user approval before writing, unless the current permission mode or rules auto-approve edit tools. + +### `notebook_edit` examples + +Replace a code cell: + +``` +notebook_edit( + notebook_path="/path/to/analysis.ipynb", + cell_id="load-data", + new_source="result = 41 + 1\nprint(result)" +) +``` + +Insert a markdown cell after an existing cell: + +``` +notebook_edit( + notebook_path="/path/to/analysis.ipynb", + edit_mode="insert", + cell_id="summary", + cell_type="markdown", + new_source="## Findings\n\nThe cleaned data is ready for modeling." +) +``` + +Delete a cell: + +``` +notebook_edit( + notebook_path="/path/to/analysis.ipynb", + edit_mode="delete", + cell_id="old-experiment" +) +``` + +## 4. `write_file` (WriteFile) `write_file` writes content to a specified file. If the file exists, it will be overwritten. If the file doesn't exist, it (and any necessary parent directories) will be created. @@ -56,11 +121,12 @@ Qwen Code provides a comprehensive suite of tools for interacting with the local - `content` (string, required): The content to write into the file. - **Behavior:** - Writes the provided `content` to the `file_path`. + - Does not write raw Jupyter notebook JSON. Use `notebook_edit` for `.ipynb` cell edits. - Creates parent directories if they don't exist. - **Output (`llmContent`):** A success message, e.g., `Successfully overwrote file: /path/to/your/file.txt` or `Successfully created and wrote to new file: /path/to/new/file.txt`. - **Confirmation:** Yes. Shows a diff of changes and asks for user approval before writing. -## 4. `glob` (Glob) +## 5. `glob` (Glob) `glob` finds files matching specific glob patterns (e.g., `src/**/*.ts`, `*.md`), returning absolute paths sorted by modification time (newest first). @@ -78,7 +144,7 @@ Qwen Code provides a comprehensive suite of tools for interacting with the local - **Output (`llmContent`):** A message like: `Found 5 file(s) matching "*.ts" within /path/to/search/dir, sorted by modification time (newest first):\n---\n/path/to/file1.ts\n/path/to/subdir/file2.ts\n---\n[95 files truncated] ...` - **Confirmation:** No. -## 5. `grep_search` (Grep) +## 6. `grep_search` (Grep) `grep_search` searches for a regular expression pattern within the content of files in a specified directory. Can filter files by a glob pattern. Returns the lines containing matches, along with their file paths and line numbers. @@ -131,7 +197,7 @@ Search for a pattern with file filtering and custom result limiting: grep_search(pattern="function", glob="*.js", limit=10) ``` -## 6. `edit` (Edit) +## 7. `edit` (Edit) `edit` replaces text within a file. By default it requires `old_string` to match a single unique location; set `replace_all` to `true` when you intentionally want to change every occurrence. This tool is designed for precise, targeted changes and requires significant context around the `old_string` to ensure it modifies the correct location. @@ -148,6 +214,7 @@ grep_search(pattern="function", glob="*.js", limit=10) - `replace_all` (boolean, optional): Replace all occurrences of `old_string`. Defaults to `false`. - **Behavior:** + - Does not edit raw Jupyter notebook JSON. Use `notebook_edit` for `.ipynb` cell edits. - If `old_string` is empty and `file_path` does not exist, creates a new file with `new_string` as content. - If `old_string` is provided, it reads the `file_path` and attempts to find exactly one occurrence unless `replace_all` is true. - If the match is unique (or `replace_all` is true), it replaces the text with `new_string`. diff --git a/docs/e2e-tests/2026-05-18-qwen-memory-benchmark-report.md b/docs/e2e-tests/2026-05-18-qwen-memory-benchmark-report.md new file mode 100644 index 00000000000..1a7aaf32533 --- /dev/null +++ b/docs/e2e-tests/2026-05-18-qwen-memory-benchmark-report.md @@ -0,0 +1,286 @@ +# Qwen Code Runtime Memory Benchmark Report + +Date: 2026-05-18 + +## Summary + +This report records local memory benchmarks for Qwen Code runtime behavior. It +compares Qwen Code across models and compares Qwen Code with Claude Code on the +same task shapes where equivalent model endpoints were available. + +The headline result is consistent across the latest matrix (single run per cell, +not statistically repeated): + +- Qwen Code process-tree RSS peak: about `852-1062 MiB` (`0.83-1.04 GiB`). +- Claude Code process-tree RSS peak: about `279-366 MiB` (`0.27-0.36 GiB`). +- Qwen Code was about `2.3x-3.6x` higher in the tested + non-interactive CLI task benchmarks. + +Note: process-tree RSS includes MCP child processes (~350 MiB overhead on the +Qwen side). This inflates the absolute numbers but the relative comparison +remains informative since both CLIs were measured the same way. + +The difference reproduced in small PR review, code navigation, and synthetic +diff workloads. It is therefore unlikely to be explained only by one large PR +or by one model provider. + +This report is intended to make the current performance investigation visible: +what has been measured, what conclusion is already supported, what remains +unknown, and what diagnostics should be added next. + +## Test Environment + +| Item | Value | +| --------------------------------------------- | ------------------------------------------ | +| Date | 2026-05-18 | +| Platform | macOS local development machine | +| Qwen Code version | `0.15.11` | +| Qwen Code binary | PATH-resolved `qwen` binary | +| Claude Code version used in the latest matrix | `2.1.129` | +| Claude Code binary used in the latest matrix | PATH-resolved `claude` binary | +| Node.js version | v22.x (default system install) | +| Sampling method | External `ps` RSS sampling once per second | +| Headline metric | Process-tree RSS peak | + +Process-tree RSS is used as the headline metric because Qwen Code launches a +root wrapper and a child Node/Qwen worker. Looking only at the root process can +understate the memory footprint seen by users. + +Temporary CLI config directories were used for matrix runs so the benchmarks +did not depend on global CLI state. + +## Benchmark Artifacts + +Five local reports were produced before this consolidated report: + +1. Qwen Code PR review memory run. +2. Qwen Code model comparison run. +3. Strict Qwen Code vs Claude Code comparison with `pai/glm-5`. +4. Qwen Code vs Claude Code, two CLIs by two models. +5. Qwen Code vs Claude Code, five-case matrix. + +This consolidated report covers the conclusions and headline metrics from all +five reports. It does not embed every raw sample row, terminal transcript, or +temporary runner artifact. Those raw artifacts stayed in local `tmp/` +directories because they are experiment outputs rather than stable repository +fixtures. + +The latest matrix is the strongest evidence because it covers multiple task +shapes rather than only one PR review workload. + +## Preliminary Conclusion + +The current data is strong enough to say that Qwen Code has a higher runtime +memory footprint than Claude Code in these local non-interactive CLI task +benchmarks. It is not strong enough to name one final root cause yet. + +The leading explanation is a Qwen Code runtime/path difference rather than a +model provider difference: + +- the gap reproduces with both `pai/glm-5` and `qwen3.6-plus`; +- the gap reproduces in small PR and code-navigation tasks, not only in large + diff tasks; +- Qwen Code repeatedly sends or accounts for more tokens than Claude Code for + similar work; +- Qwen Code's largest observed component is the child Node/Qwen worker process, + which points toward task-time process footprint, module loading, context + assembly, live history, tool-result retention, or subagent/saved-output + paths. + +The most useful next measurement is therefore not another external RSS-only +run. The next measurement should split RSS into V8 heap, native memory, +session/history size, retained tool-result size, and subagent/process-tree +activity. + +## Initial Cause Analysis + +The benchmark does not yet prove one root cause, but it does narrow the likely +problem area. + +| Signal | What it suggests | What it does not prove | +| -------------------------------------------------------------------------------------------- | ------------------------------------------------------------------------------------------ | ------------------------------------------------------------------------------------------------------- | +| Qwen remains near `1 GiB` in small PR and code-navigation cases | A high non-interactive task-time runtime cost is likely involved | It does not identify whether the footprint is V8 heap, native memory, module loading, or retained state | +| Diff size from 100 KiB to 5 MiB does not scale linearly with RSS | Raw diff bytes alone are probably not the primary driver | Large outputs can still amplify memory in real PR review flows | +| Qwen uses more tokens than Claude in every matrix cell | Qwen likely constructs or retains larger prompt/context/tool-result state for similar work | Token count is not the same as process memory and may be an effect rather than the cause | +| Tool call counts are similar, and Claude sometimes uses more turns/tool calls with lower RSS | A longer tool-call chain is unlikely to be the main explanation by itself | Tool output size and retention still need to be measured | +| Earlier large PR runs showed saved-output recovery and subagent amplification | Tool-output truncation and saved-output paths are likely heavy-workload amplifiers | They do not explain the entire small-task execution footprint | + +The current best explanation is therefore: + +1. **Task-time runtime cost first**: Qwen Code likely initializes or retains + more runtime state during non-interactive CLI task execution than Claude + Code. This may include agent runtime, tool registry, provider adapters, + session services, or UI/history structures that are not strictly needed for + a short non-interactive task. +2. **Context/tool-result volume second**: Qwen Code appears to carry larger + model-facing or session-facing context for similar work. The token gap makes + context assembly, tool result normalization, and history retention important + suspects. +3. **Large-output amplification third**: Large PR review can trigger additional + saved-output and subagent paths. These are probably not the only cause, but + they can make memory and token pressure worse in realistic review tasks. + +The next diagnostic run should answer where the `~1 GiB` sits: + +- high immediately after startup: module/runtime startup cost; +- jumps after tool execution: tool-output retention or result normalization; +- jumps during request assembly: context construction or duplicated histories; +- grows after streaming/compression: response retention or compression state; +- mostly RSS outside V8 heap: native buffers, loaded modules, or external + memory. + +## Latest Matrix + +The latest benchmark ran: + +- 2 CLIs: Qwen Code and Claude Code. +- 2 model labels: `pai/glm-5` and `qwen3.6-plus`. +- 5 cases: + - small PR review: PR `#4268`, one-line change + - code navigation: `rg` plus `sed` on compression-related files + - synthetic local diff, about 100 KiB + - synthetic local diff, about 1 MiB + - synthetic local diff, about 5 MiB + +All 20 runs exited `0` with no timeout. + +## Matrix Results + +| Case | Model | Qwen tree peak | Claude tree peak | Qwen / Claude | +| ---------------- | -------------- | -------------: | ---------------: | ------------: | +| small PR `#4268` | `pai/glm-5` | 1032.7 MiB | 357.8 MiB | 2.89x | +| small PR `#4268` | `qwen3.6-plus` | 852.2 MiB | 365.5 MiB | 2.33x | +| code navigation | `pai/glm-5` | 993.1 MiB | 359.6 MiB | 2.76x | +| code navigation | `qwen3.6-plus` | 996.9 MiB | 349.0 MiB | 2.86x | +| diff 100 KiB | `pai/glm-5` | 1012.1 MiB | 350.8 MiB | 2.89x | +| diff 100 KiB | `qwen3.6-plus` | 1001.1 MiB | 336.2 MiB | 2.98x | +| diff 1 MiB | `pai/glm-5` | 1008.3 MiB | 278.8 MiB | 3.62x | +| diff 1 MiB | `qwen3.6-plus` | 1003.3 MiB | 340.5 MiB | 2.95x | +| diff 5 MiB | `pai/glm-5` | 858.8 MiB | 323.2 MiB | 2.66x | +| diff 5 MiB | `qwen3.6-plus` | 1062.0 MiB | 331.2 MiB | 3.21x | + +Average process-tree RSS peak by case: + +| Case | Avg Qwen tree peak | Avg Claude tree peak | +| ---------------- | -----------------: | -------------------: | +| small PR `#4268` | 942.5 MiB | 361.6 MiB | +| code navigation | 995.0 MiB | 354.3 MiB | +| diff 100 KiB | 1006.6 MiB | 343.5 MiB | +| diff 1 MiB | 1005.8 MiB | 309.6 MiB | +| diff 5 MiB | 960.4 MiB | 327.2 MiB | + +## Runtime And Token Signals + +The same matrix also showed Qwen Code using more model-side tokens in every +tested case. + +Selected examples: + +| Case | Model | CLI | Duration | Turns | Total tokens | Tool calls | +| --------------- | -------------- | ------ | -------: | ----: | -----------: | ---------: | +| small PR | `pai/glm-5` | Qwen | 25.2s | 2 | 32,567 | 3 | +| small PR | `pai/glm-5` | Claude | 21.1s | 4 | 7,899 | 3 | +| code navigation | `qwen3.6-plus` | Qwen | 25.2s | 2 | 38,151 | 3 | +| code navigation | `qwen3.6-plus` | Claude | 46.9s | 6 | 25,861 | 5 | +| diff 100 KiB | `qwen3.6-plus` | Qwen | 16.5s | 3 | 57,185 | 2 | +| diff 100 KiB | `qwen3.6-plus` | Claude | 17.2s | 3 | 6,377 | 2 | +| diff 5 MiB | `pai/glm-5` | Qwen | 23.2s | 2 | 38,574 | 2 | +| diff 5 MiB | `pai/glm-5` | Claude | 9.8s | 3 | 5,285 | 2 | + +This token gap does not prove that token volume is the memory root cause, but it +does suggest that context assembly, tool result retention, or response +normalization should be measured alongside RSS and V8 heap statistics. + +## Token Usage Analysis + +The token gap is one of the strongest clues, but it needs internal request +metrics before it can be treated as a root cause. + +What the data supports today: + +- Qwen Code used more total tokens than Claude Code in every matrix cell. +- The gap appears even when tool-call counts are similar. +- Claude sometimes used more turns or tool calls while still using less memory. + +What this suggests: + +- The token delta is unlikely to come only from a longer tool-call chain. +- Qwen may be carrying larger static prompt/context state, larger tool schemas, + larger serialized tool results, or more retained conversation/session content. +- Large-output flows may add another layer through truncation, saved-output + recovery, or subagent paths. + +What is still missing: + +- per-request input token breakdown; +- system prompt and tool schema token sizes; +- retained message and tool-result sizes before each model request; +- whether large outputs are retained in multiple places, such as model history, + UI history, session recording, or saved-output storage. + +Those missing metrics are why the next step should add internal diagnostics +rather than only repeat the external RSS benchmark. + +## Earlier Large PR Review Signal + +An earlier strict PR review benchmark used PR `#4186` and showed the same broad +shape: + +| Model | CLI | Process-tree RSS peak | +| -------------- | ----------- | --------------------: | +| `pai/glm-5` | Qwen Code | 1000.7 MiB | +| `pai/glm-5` | Claude Code | 349.0 MiB | +| `qwen3.6-plus` | Qwen Code | 1095.8 MiB | +| `qwen3.6-plus` | Claude Code | 341.1 MiB | + +That earlier run was not enough by itself because a large PR can trigger unusual +tool-output and saved-output paths. The latest five-case matrix makes the +finding stronger because small PR and code-navigation tasks also reproduce the +gap. + +## Working Hypothesis + +The current evidence supports these hypotheses, in priority order: + +1. Qwen Code has a higher non-interactive task-time process footprint than + Claude Code. The Qwen child Node worker was typically the largest process in + local sampling, often around `0.7-0.8 GiB`. +2. Model choice is not the main explanation. Both `pai/glm-5` and + `qwen3.6-plus` showed the same broad Qwen-vs-Claude gap. +3. Large diff size alone is not the main explanation. The synthetic diff size + did not scale linearly from 100 KiB to 5 MiB, likely because tool-output + truncation caps how much output reaches the model. +4. Context/tool-result handling is still a likely contributor. Qwen Code used + more tokens than Claude Code in every matrix cell, and earlier large-PR runs + showed saved tool-output recovery and subagent amplification paths. +5. The next diagnostic layer should separate V8 heap, native RSS, loaded + module/runtime startup cost, session history, UI history, tool-result + retention, and subagent activity. External RSS alone cannot distinguish + those causes. + +## Caveats + +- These are single runs per matrix cell, not repeated statistical samples. +- RSS is external process RSS. It cannot distinguish V8 heap, native buffers, + module loading, retained tool output, UI state, or session history. +- Claude Code and Qwen Code use different runtime implementations and protocol + adapters, even when the model labels are the same. +- The benchmark was run locally on macOS. Linux servers should be tested before + drawing deployment-specific conclusions. + +## Recommended Follow-Up Measurements + +The next local investigation branch should add or use diagnostics for: + +- `process.memoryUsage()` before and after startup, tool execution, streaming, + compression, and session finalization. +- V8 heap statistics and heap spaces. +- Active handles and requests. +- Session message count and approximate retained character/token volume. +- Tool result count, total retained tool-result size, largest tool-result size, + and whether large outputs are retained by UI history or model history. +- Subagent count and child process/process-tree RSS. +- Tool-output truncation and saved-output recovery events. + +These measurements should be collected with the same benchmark matrix so the +current RSS comparison can be connected to internal Qwen Code state. diff --git a/docs/e2e-tests/2026-05-19-oom-reproduction-report.md b/docs/e2e-tests/2026-05-19-oom-reproduction-report.md new file mode 100644 index 00000000000..8716e208f56 --- /dev/null +++ b/docs/e2e-tests/2026-05-19-oom-reproduction-report.md @@ -0,0 +1,437 @@ +# OOM 压力测试与长任务 Replay 报告 + +**日期**: 2026-05-19 +**分支**: `codex/memory-diagnostics-local-run` +**测试人**: yiliang114 +**结论**: 成功复现并定位根因。v0.15.7 (#3735) 引入的 auto-compaction 使 `structuredClone` +调用频率倍增，在高 heap 压力时形成正反馈死循环导致 OOM。真实 debug 日志完整佐证了该机制。 + +--- + +## 一、背景 + +多个 issue（#4309, #4276, #4185, #4315, #4322, #2868）报告 qwen-code 在长会话中出现 V8 heap OOM crash： + +``` +FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory +``` + +用户报告的崩溃特征： +| Issue | 崩溃时 Heap | 运行时长 | 平台 | +|-------|------------|---------|------| +| #4276 | 4014 MB | ~110 分钟 | Linux x64 | +| #4315 | 2027 MB | ~19.6 小时 | macOS (默认 2GB limit) | +| #4322 | 4023 MB | ~7 小时 | Windows | +| #2868 | 2035 MB | ~1.7 分钟 | Linux | +| #4309 | 7020 MB | 未知 | Windows (设了 8GB limit 仍崩) | + +--- + +## 二、方法论修正 + +本报告区分两类测试： + +1. **低 heap 压力测试**：通过降低 `--max-old-space-size` 放大问题，用于快速定位 + “history 很大时整段复制导致瞬时峰值”的代码路径。它是诊断工具，不等价于用户真实 + 4G/8G OOM 复现。 +2. **默认 heap 长任务 replay**：不设置 `NODE_OPTIONS`，使用真实 JSONL 历史恢复并 + 继续执行 review 任务，同时从进程外采样 process-tree RSS。这类结果才用于判断 + 用户侧实际内存量级。 + +因此，低 heap 结果不能单独作为“真实 OOM 已修复”的证明。它只能说明某条路径在 +history 足够大时会产生峰值放大，需要再用默认 heap 长任务验证。 + +## 三、低 heap 压力测试条件 + +| 参数 | 值 | +| ------------------------ | ------------------------------------------------------------ | +| CLI 版本 | 0.15.11 (从 `codex/memory-diagnostics-local-run` 分支 build) | +| Model | `qwen3.6-plus` (128K context window) | +| Heap limit | `--max-old-space-size=512` | +| Heap-pressure safety net | **禁用** (HEAP_PRESSURE_COMPRESSION_RATIO 设为 99.0) | +| 操作模式 | YOLO + 自动化多轮 Read 文件任务 | +| 工作目录 | qwen-code monorepo (3538 .ts files, 1.26M lines) | + +### 关键配置修改 + +`packages/core/src/core/geminiChat.ts` 中将 heap-pressure compaction 阈值从 0.7 改为 99.0（使其永远不触发），模拟 #4186 修复前的状态。 + +--- + +## 四、低 heap 压力测试结果 + +### 崩溃时间线 + +``` +[21:26:59] #1 RSS:193.6MB Ctx:0% → Read geminiChat.ts (1500 行) +[21:27:46] #2 RSS:270.4MB Ctx:4.2% → Read agent.ts +[21:28:32] #3 RSS:397.5MB Ctx:4.3% → grep + Read 3 个文件 +[21:29:18] #4 RSS:452.7MB Ctx:5.7% → Read slashCommandProcessor.ts +[21:30:04] #5 RSS:515.0MB Ctx:5.9% → Read chatCompressionService.ts +[21:30:50] #6 RSS:649.1MB Ctx:4.0% ← TOKEN COMPACTION 触发 (5.9%→4.0%) + RSS 反增 134MB (structuredClone 峰值) +[21:31:36] #7 RSS:666.7MB Ctx:3.2% ← 再次 compaction, RSS 继续涨 +[21:32:22] CRASH — FATAL ERROR: Ineffective mark-compacts near heap limit +``` + +**总耗时**: ~5.5 分钟，7 轮任务后崩溃。 + +这证明在受限 heap 下，长 history + compaction/history clone 可以触发 V8 heap OOM。 +但该结果不代表默认 heap 下的真实用户 OOM 已经被完整复现。 + +### 更大 heap 的 synthetic 复现 + +为避免只依赖 512 MiB 低 heap 结论，补充了更大 heap 的 synthetic runtime +pressure 测试。该测试不调用模型，而是构造类似长 review/subagent 任务的历史： + +- root review turns: 10 +- subagent calls: 30 +- subagent transcript records: 780 +- retained tool result bytes: 193,986,560 +- serialized history bytes: 195,620,061 +- pressure mode: retained `structuredClone(history)` copies + +| Heap limit | Clone pressure | 结果 | 关键 GC / stack | +| ---------- | -----------------: | ---------------------------------------- | ------------------------------------------------------------ | +| 2 GiB | 8 retained clones | 未崩溃，RSS 2.42 GiB，heap used 1.87 GiB | 接近 heap limit | +| 2 GiB | 10 retained clones | OOM | `Reached heap limit`, `ValueDeserializer`, `StructuredClone` | +| 4 GiB | 20 retained clones | OOM | `Reached heap limit`, `ValueDeserializer`, `StructuredClone` | + +2 GiB 复现的 GC 摘要： + +``` +Mark-Compact 2042.9 (2081.9) -> 2042.9 (2081.1) MB +Mark-Compact 2048.9 (2087.2) -> 2048.9 (2087.2) MB +FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory +... +node::worker::(anonymous namespace)::StructuredClone +``` + +4 GiB 复现的 GC 摘要： + +``` +Mark-Compact 4082.5 (4126.8) -> 4082.5 (4126.3) MB +Mark-Compact 4095.1 (4139.0) -> 4095.1 (4139.0) MB +FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory +... +node::worker::(anonymous namespace)::StructuredClone +``` + +这组结果比 512 MiB 压力测试更接近用户报告的 2 GiB / 4 GiB heap OOM： +只要 history 中保留足够多的大 tool result / subagent transcript，对整段 history +做 retained 或瞬时 clone 都可以在 2-4 GiB heap 下触发 V8 OOM。它仍然是 synthetic +复现，不等价于完整业务长任务 replay，但能直接证明问题不是“小 heap 人为制造”的。 + +### 崩溃时 GC 状态 + +``` +[41381:0x130008000] 342468 ms: Mark-Compact 508.6 (526.7) -> 507.0 (526.9) MB, + pooled: 1 MB, 86.42 / 0.00 ms (average mu = 0.175, current mu = 0.150) + task; scavenge might not succeed + +[41381:0x130008000] 342568 ms: Mark-Compact 509.1 (526.9) -> 507.1 (528.2) MB, + pooled: 0 MB, 93.79 / 0.12 ms (average mu = 0.121, current mu = 0.068) + allocation failure; scavenge might not succeed + +FATAL ERROR: Ineffective mark-compacts near heap limit +Allocation failed - JavaScript heap out of memory +``` + +Mark-Compact 只能回收 1-2 MB（几乎所有对象都是 reachable），证明内存确实被合法持有的对象占满。 + +--- + +## 五、默认 heap 长任务 replay + +为了避免低 heap 结论过度外推，补充了默认 heap 的真实 JSONL replay： + +- 不设置 `NODE_OPTIONS` +- 不启用内部 runtime profiler，避免采样器自身影响 heap +- 每个 CLI 从同一份 rewound JSONL 复制出 fresh session +- 使用临时 `QWEN_HOME`，禁用 MCP 和 hooks，避免本地全局配置污染 +- 只用进程外采样统计 process-tree RSS + +| CLI | 结果 | 时长 | Tree RSS 峰值 | Root RSS 峰值 | Worker RSS 峰值 | 备注 | +| -------------------- | ---- | -----: | ------------: | ------------: | --------------: | ----------------------------------------------------------- | +| installed `qwen` | 成功 | 167.3s | 838.0 MiB | 230.2 MiB | 566.3 MiB | 第一次 fresh run 遇到模型服务端错误，未纳入结论；retry 成功 | +| local rebuilt bundle | 成功 | 106.3s | 527.5 MiB | 182.1 MiB | 345.4 MiB | 包含本地 clone 热路径修复 | + +默认 heap replay 的结论： + +1. 当前这份 review JSONL 可以稳定跑出数百 MiB 到约 0.8 GiB 的 process-tree RSS， + 但没有复现 4G/8G OOM。 +2. 本地 rebuilt bundle 在同起点 replay 上的峰值低于 installed CLI，说明减少 + history clone 热路径有实际收益。 +3. 这还不能证明所有用户 OOM 都已解决。真实 4G/8G OOM 仍需要更长任务、更大 + tool-result 累积，或保留 MCP/tool schema 压力的 replay 继续验证。 + +## 六、根因分析 + +### OOM 的三层机制 + +``` +┌─────────────────────────────────────────────────────────┐ +│ Layer 3: V8 Heap Limit (512MB/2GB/4GB) │ ← 用户最终撞到这里 +├─────────────────────────────────────────────────────────┤ +│ Layer 2: structuredClone() 峰值放大 (瞬时 ~2x) │ ← 直接诱因 +├─────────────────────────────────────────────────────────┤ +│ Layer 1: History 中 tool result 累积 (线性增长) │ ← 基础增长 +├─────────────────────────────────────────────────────────┤ +│ Layer 0: Token compaction 触发时机 │ ← 控制点 +└─────────────────────────────────────────────────────────┘ +``` + +### 精确崩溃路径 + +``` +sendMessage() + → tryCompress() + → heapPressureRatio < threshold (safety net disabled) + → ChatCompressionService.compress() + → chat.getHistory(true) + → structuredClone(this._history) ← 峰值分配！ + → V8 需要额外 ~N MB 来容纳 clone + → 如果 existing heap + N > limit → OOM +``` + +### 关键证据 + +| 观察 | 含义 | +| --------------------------------------- | ---------------------------------------------- | +| Task #5→#6: Context 5.9%→4.0% (降了) | Token compaction **成功执行**了 | +| Task #5→#6: RSS 515→649 MB (涨了 134MB) | Compaction 过程的 `structuredClone` 制造了峰值 | +| GC 只能回收 1-2 MB | 所有对象都是 live（history + clone 都在） | +| #4309 设 8GB limit 仍崩 | history 足够大时，clone 峰值可超任何 limit | + +需要注意：以上证据来自低 heap 压力测试和 issue 现象的组合推断。默认 heap replay +目前支持”clone 热路径会显著影响峰值 RSS”，但尚未单独复现 4G/8G OOM。 + +### 为什么 128K context window 更容易触发 + +- 128K × 70% = ~90K tokens 触发 compaction +- 大 context window (1M) 的 70% = 700K tokens，几乎不会触发 +- **compaction 越频繁 → structuredClone 越频繁 → OOM 风险越高** +- DeepSeek 等未配置 contextWindowSize 的模型默认 128K，更易触发 + +--- + +## 六.5、真实运行日志佐证 + +以下日志提取自本地 crash session 的 debug 输出。为避免泄露本地路径和 session id， +报告只保留时间线和关键日志内容。 + +该 session 启动于 `2026-05-19T13:26:35Z` (本地 21:26:35)，crash 于 +`2026-05-19T13:32:10Z` (本地 21:32:10)。 + +### Heap Pressure 与 Auto-Compaction 事件时间线 + +``` +13:29:43 [WARN] Heap pressure at 74.9%; attempting auto-compaction before token threshold. +13:30:06 [DEBUG] [FILE_READ_CACHE] clear after auto tryCompress ← compaction #1 执行成功 +13:30:13 [WARN] Heap pressure at 70.7%; attempting auto-compaction before token threshold. + ← 刚压完 heap 从 74.9% 仅降到 70.7%，仍超阈值，立即再次尝试 +13:30:52 [DEBUG] Heap pressure at 86.0%; skipping heap-pressure auto-compaction during cooldown. + ← 30s cooldown 期间拒绝执行 +13:30:56 [WARN] Heap pressure at 85.3%; attempting auto-compaction before token threshold. + ← cooldown 过期，heap 已升至 85.3% +13:31:21 [DEBUG] [FILE_READ_CACHE] clear after auto tryCompress ← compaction #2 执行成功 +13:31:37 [WARN] Heap pressure at 88.8%; attempting auto-compaction before token threshold. + ← 压完后 heap 反弹至 88.8% +13:32:09 [DEBUG] Heap pressure at 90.2%; skipping heap-pressure auto-compaction during cooldown. + ← heap 已达 90.2%，cooldown 中无法执行 +13:32:10 ← 日志终止（进程 OOM crash） +``` + +### 日志证据解读 + +| 日志观察 | 含义 | +| ------------------------------------------------------------------------------------- | --------------------------------------------------------- | +| 2.5 分钟内触发 **4 次** heap-pressure auto-compaction 尝试（另有 2 次 cooldown 拒绝） | #3735 引入的 `tryCompress` 在高压时频繁触发 | +| 每次 compaction 执行后 heap 占比仍 >70% | `structuredClone()` 制造的临时峰值抵消了压缩收益 | +| 74.9% → 70.7% → 86% → 85.3% → 88.8% → 90.2% → crash | 正反馈循环：压缩→clone 峰值→heap 更高→再压缩→更高 | +| 日志在 90.2% 后 1 秒内断裂 | 下一次 `getHistory(true)` 的 `structuredClone()` 瞬间超限 | +| `[FILE_READ_CACHE] clear after auto tryCompress` 出现 2 次 | 证实 compaction 确实走了完整的 compress → setHistory 路径 | + +### 正反馈死循环机制 + +``` +heap 占比高 (>70%) + → 触发 heap-pressure auto-compaction + → tryCompress() 内部调用 getHistory(true) + → structuredClone(this._history) ← 瞬时 heap 峰值 +30~40% + → compaction 成功，释放旧 history + → 但 clone 峰值已经把 heap 推高到更危险的水位 + → 下一轮 send 继续累积 + → heap 占比更高 → 更频繁触发 → crash +``` + +--- + +## 六.6、版本归因：为什么 0.15.7 ~ 0.15.11 期间 OOM 报告增多 + +### 关键 commit 时间线 + +| 版本 | PR | 改动 | 对 `structuredClone` 调用频率的影响 | +| ------------ | ---------------------------------------------------- | ----------------------------------------------------------------------------------- | ----------------------------------- | +| **v0.15.6** | — | `getHistory(true)` 仅在 `sendMessage` 入口调用 1 次 | 基线：每次 send 1 次 clone | +| **v0.15.7** | **#3735** `auto-compact subagent context` | 将 `tryCompress()` 下沉到 `GeminiChat`，**每次 send 前**先执行一次 compaction 检查 | **+1 次**：send 前 compress 检查 | +| **v0.15.10** | **#3879** `reactive compression on context overflow` | 当 provider 返回 context overflow 时，再次触发 `tryCompress()` + `getHistory(true)` | **+1~2 次**：overflow retry 路径 | +| **v0.15.10** | **#3985** `harden reactive compression` | 强化 reactive compression 重试逻辑 | 同上 | + +### v0.15.6 vs v0.15.11 的 `getHistory(true)` 调用点对比 + +**v0.15.6** (2 处)： + +``` +L367: const requestContents = this.getHistory(true); ← send 构造 request +L618: const recoveryContents = self.getHistory(true); ← MAX_TOKENS escalation (极少触发) +``` + +**v0.15.11** (5 处)： + +``` +L467: ChatCompressionService.compress() 内部调用 ← #3735: 每次 send 前的 auto-compact +L574: requestContents = this.getHistory(true); ← send 构造 request +L724: reactive tryCompress() 内部调用 ← #3879: context overflow 后 retry +L739: requestContents = self.getHistory(true); ← #3879: retry 构造新 request +L943: const recoveryContents = self.getHistory(true); ← MAX_TOKENS escalation +``` + +### 最坏路径：一次 send 可触发 4 次 `structuredClone` + +``` +sendMessage() + → tryCompress() ← #3735: getHistory(true) [clone #1] + → getHistory(true) ← 构造 request [clone #2] + → API 返回 context overflow + → reactive tryCompress() ← #3879: getHistory(true) [clone #3] + → getHistory(true) ← retry request [clone #4] +``` + +### 结论 + +**#3735 (v0.15.7)** 是 OOM 频率显著上升的最可能触发因素（非唯一根因）——它使每次 +`sendMessage` 都会先跑一次 `tryCompress()`，而 `tryCompress` 内部通过 +`ChatCompressionService.compress()` → `chat.getHistory(true)` 做全量 `structuredClone`。 +在 history 较大时，这个 “先 clone 再判断是否需要压缩” 的设计让内存峰值从 ~1.3x 升至 ~2x+。 +注：issue history 显示 OOM 报告在 #3735 之前就已存在，但 #3735 大幅增加了 structuredClone +的调用频率，从而显著提高了 OOM 的触发概率。 + +**#3879 (v0.15.10)** 进一步恶化了问题——在已经处于 heap 边界时 (provider 返回 context overflow) +再触发一次全量 clone，使原本就危险的 session 更容易 crash。 + +--- + +## 七、#4186 修复效果验证（对比测试） + +启用 heap-pressure safety net (HEAP_PRESSURE_COMPRESSION_RATIO = 0.7) 后的对比测试： + +| 指标 | 禁用 safety net | 启用 safety net | +| --------------- | ------------------ | ------------------------- | +| OOM 发生 | 是（7 轮后 crash） | 否（持续运行 >10 分钟） | +| RSS 峰值 | 666 MB → crash | 555 MB → GC 回收到 280 MB | +| Compaction 触发 | 仅 token threshold | heap 70% 时提前触发 | +| Context 行为 | 5.9%→4.0%→crash | 22.7%→17.0%（安全回落） | + +**结论**: #4186 的 heap-pressure safety net 有效防止了 OOM，但它是一个**缓解**而非根治： + +- 如果 history 本身已经占了 heap 的 60%+，即使提前 compact，clone 的峰值仍然可能超限 +- 这解释了为什么 #4309 用户设了 8GB limit 后仍然 crash + +--- + +## 八、内存占用分布 + +基于测试中的 RSS 增长模式估算： + +| 内存位置 | 占比 | 增长特征 | +| -------------------------------- | ------ | --------------------------- | +| `this._history[]` (tool results) | 40-50% | 线性累积，每轮 +30-100MB | +| `structuredClone()` 临时拷贝 | 30-40% | 瞬时峰值，compaction 时出现 | +| V8 runtime (GC metadata, code) | ~15% | 基本恒定 | +| UI/logging/stream buffers | ~5% | 缓慢增长 | + +--- + +## 九、复现脚本与环境 + +### 自动化驱动脚本 + +```bash +#!/bin/bash +# /tmp/oom-simple-driver.sh +SESSION="$1" + +TASKS=( + "用 Read 工具完整读取 packages/core/src/core/geminiChat.ts" + "用 Read 工具完整读取 packages/core/src/tools/agent/agent.ts" + "用 grep -rn structuredClone packages/core/src 然后 Read 前 3 个文件" + "用 Read 完整读取 packages/cli/src/ui/hooks/slashCommandProcessor.ts" + "用 Read 完整读取 packages/core/src/services/chatCompressionService.ts" + "用 find packages/cli/src/ui/commands -name '*.ts' 然后逐一 Read" + "用 Read 完整读取 packages/core/src/core/turn.ts" + # ... 更多任务 +) + +i=0 +while true; do + TASK="${TASKS[$((i % ${#TASKS[@]}))]}" + i=$((i + 1)) + + QWEN_PID=$(ps aux | grep "dist/index.js" | grep -v grep | awk '{print $2}' | sort -rn | head -1) + RSS=$(ps -o rss= -p $QWEN_PID 2>/dev/null) + [ -z "$RSS" ] && { echo "CRASH after $((i-1)) tasks!"; exit 0; } + + RSS_MB=$(echo "scale=1; $RSS/1024" | bc) + CTX=$(tmux capture-pane -t "$SESSION:1" -p 2>/dev/null | grep -oE "[0-9]+\.[0-9]+% 已用" | tail -1) + echo "[$(date +%H:%M:%S)] #$i RSS:${RSS_MB}MB Ctx:$CTX | ${TASK:0:55}" + + tmux send-keys -t "$SESSION:1" C-u + sleep 0.2 + tmux send-keys -t "$SESSION:1" "$TASK" Enter + sleep 0.5 + tmux send-keys -t "$SESSION:1" Enter + sleep 45 +done +``` + +### 启动命令 + +```bash +# 1. 禁用 heap-pressure safety net +# geminiChat.ts: HEAP_PRESSURE_COMPRESSION_RATIO = 99.0 + +# 2. Build +npm run build --workspace=packages/core && npm run build --workspace=packages/cli + +# 3. 启动 qwen (128K context model, 512MB heap) +SESSION="oom-test" +tmux new-session -d -s "$SESSION" -c "$REPO_DIR" +tmux send-keys -t "$SESSION" \ + "NODE_OPTIONS='--max-old-space-size=512' node packages/cli/dist/index.js --model 'qwen3.6-plus'" Enter + +# 4. 等待启动后运行驱动 +sleep 10 +bash /tmp/oom-simple-driver.sh "$SESSION" +``` + +--- + +## 十、后续建议 + +### 短期缓解（已有） + +- [x] #4186: heap-pressure auto-compaction safety net (0.7 threshold) +- [x] #4188: fileReadCache / crawlCache 上限 + +### 中期修复（建议） + +- [ ] 减少 `structuredClone()` 调用 — `nextSpeakerChecker` 只需最后一条消息，不需 clone 全量 +- [ ] Compaction 使用 slice + 引用替代全量 deep clone +- [ ] 大 tool result (>100KB) 写入临时文件，history 中只保留摘要引用 + +### 长期方向 + +- [ ] Tool result offload 到磁盘 + lazy load (#4184) +- [ ] 基于 RSS 的分级压缩策略（不仅是 token count） +- [ ] History 分段存储，避免单次全量操作 diff --git a/docs/e2e-tests/2026-05-19-qwen-runtime-diagnostics-benchmark-report.md b/docs/e2e-tests/2026-05-19-qwen-runtime-diagnostics-benchmark-report.md new file mode 100644 index 00000000000..e482f0f94c3 --- /dev/null +++ b/docs/e2e-tests/2026-05-19-qwen-runtime-diagnostics-benchmark-report.md @@ -0,0 +1,904 @@ +# Qwen Code Runtime Diagnostics Benchmark Report + +Date: 2026-05-19 + +## Scope + +This run repeats the previous Qwen Code benchmark shapes with the new opt-in +runtime diagnostics enabled. It only tests Qwen Code, not Claude Code. + +Initial model matrix: + +- `pai/glm-5` +- `qwen3.6-plus` + +Additional PR-size follow-up: + +- `DeepSeek/deepseek-v4-pro` through Anthropic-compatible protocol + +Cases: + +- small GitHub PR review: PR `#4268` +- code navigation: compression / compaction related code search and reads +- synthetic local diff: about 94.6 KiB +- synthetic local diff: about 968.5 KiB +- synthetic local diff: about 4.84 MiB + +The run used the local bundled CLI from the diagnostics branch, with +`QWEN_CODE_PROFILE_RUNTIME=1` and a temporary CLI home. Global MCP servers and +hooks were not loaded for this benchmark. + +Important caveat: these absolute RSS numbers are lower than the previous +PATH-resolved `qwen` runs because this run used `node dist/cli.js` from the +local branch plus a stripped temporary config. Treat this report as an internal +diagnostics distribution run, not a direct replacement for the earlier installed +CLI RSS comparison. + +## Installed CLI vs Local Bundle Sanity Check + +A follow-up sanity check used the same minimal prompt, model, and non-interactive +mode across the installed CLI and the local diagnostics bundle. The only +intentional variable was whether Qwen Code loaded a stripped temporary CLI home +or the normal user config. + +| CLI | Config mode | Total tokens | Tree RSS peak | Root RSS peak | Process count peak | Runtime diagnostics | +| ------------------- | --------------- | -----------: | ------------: | ------------: | -----------------: | ------------------- | +| PATH `qwen` | stripped config | 33,965 | 542.4 MiB | 249.9 MiB | 3 | no | +| local `dist/cli.js` | stripped config | 47,281 | 455.2 MiB | 214.2 MiB | 4 | yes | +| PATH `qwen` | normal config | 97,615 | 1,099.9 MiB | 250.1 MiB | 6 | no | +| local `dist/cli.js` | normal config | 97,954 | 1,105.4 MiB | 212.7 MiB | 8 | yes | + +This check changes the attribution: the earlier 1 GiB user-visible peak is +reproducible with the normal config even on the local diagnostics bundle. It is +therefore not primarily explained by the local branch including PR `#4186`. + +At the normal-config peak, the local process-tree sample was dominated by +multiple Node/MCP processes rather than the Qwen root process alone: + +| Role | Command shape | RSS at tree peak | +| ----- | ------------------------- | ---------------: | +| child | Node process | 252.9 MiB | +| child | Chrome DevTools MCP | 219.7 MiB | +| child | Node process | 219.2 MiB | +| root | Qwen Node process | 215.1 MiB | +| child | Chrome DevTools MCP setup | 175.2 MiB | + +PR `#4186` is present in the local diagnostics branch, but it is a V8 heap +pressure auto-compaction safety net. It triggers at about 70% V8 heap pressure; +on this environment the Node heap limit is about 4.1 GiB, while the stripped +benchmark end heap was about 99-143 MiB. Based on these numbers, the lower +stripped-config RSS is not caused by `#4186` actively compressing context during +these benchmark runs. + +### Bare Mode Config Attribution Check + +A second follow-up used `qwen3.6-plus` with the same PR-review prompt shape on +both the installed CLI and the local bundle. This is not a normal end-to-end +business benchmark. It is a controlled attribution check for startup/config +memory only. + +`--bare` changes the runtime inputs: it skips normal global settings discovery, +MCP startup, hooks, implicit context, skills, and other startup integrations. It +can therefore fail or behave differently when a model provider is configured +only in global settings. For this run, model credentials were supplied only +through the child-process environment because bare mode intentionally does not +load the normal provider settings. Nothing was written back to the user's global +config. + +This run did not produce useful token/tool-call statistics: the model completed +in one turn and did not call the requested shell command. Do not use these rows +as normal task benchmark results, and do not compare their token/tool-call +behavior with the matrix above. They are only useful for estimating how much +process-tree RSS comes from normal config and configured child processes. + +| CLI | Mode | Wall | Turns | Tool uses | Tree RSS peak | Root RSS peak | Process count peak | +| ------------------- | -------- | ---: | ----: | --------: | ------------: | ------------: | -----------------: | +| PATH `qwen` | normal | 5.5s | 1 | 0 | 1,021.3 MiB | 251.5 MiB | 5 | +| PATH `qwen` | `--bare` | 2.4s | 1 | 0 | 525.7 MiB | 246.4 MiB | 2 | +| local `dist/cli.js` | normal | 4.9s | 1 | 0 | 1,046.2 MiB | 213.3 MiB | 5 | +| local `dist/cli.js` | `--bare` | 2.3s | 1 | 0 | 454.3 MiB | 216.5 MiB | 3 | + +The result confirms the process-tree hypothesis for startup/config attribution. +On this machine, normal config adds roughly 0.50-0.59 GiB of user-visible +process-tree RSS over `--bare`, while root RSS stays in the same 0.21-0.25 GiB +band. At the normal-config peak, the extra RSS again came from additional +Node/MCP child processes, including a Chrome DevTools MCP process and its setup +wrapper. `--bare` removes those startup/config children and brings +installed/local runs back into the 0.45-0.53 GiB tree-RSS range. + +### Temporary Settings MCP / Hooks Isolation + +Because `--bare` changes too many runtime inputs to be treated as a normal +benchmark, a follow-up used temporary `QWEN_HOME` directories with generated +settings files derived from the normal settings. The run stayed on the normal +settings-loading path, but toggled only two config dimensions: + +- MCP disabled: `mcpServers` cleared and MCP allow/exclude lists emptied. +- Hooks disabled: `disableAllHooks` set to true. + +No global settings were modified. The case used `qwen3.6-plus` and a minimal +startup prompt, so it measures startup/config process-tree cost, not task +reasoning quality. + +| CLI | Temporary config | MCP servers | Tools | Tree RSS peak | Root RSS peak | Process count peak | +| ------------------- | -------------------- | ----------: | ----: | ------------: | ------------: | -----------------: | +| PATH `qwen` | full | 4 | 46 | 1,017.4 MiB | 249.8 MiB | 5 | +| PATH `qwen` | MCP disabled | 0 | 17 | 548.7 MiB | 252.4 MiB | 2 | +| PATH `qwen` | hooks disabled | 4 | 46 | 1,003.8 MiB | 246.4 MiB | 5 | +| PATH `qwen` | MCP + hooks disabled | 0 | 17 | 542.5 MiB | 248.0 MiB | 2 | +| local `dist/cli.js` | full | 4 | 48 | 865.9 MiB | 220.4 MiB | 6 | +| local `dist/cli.js` | MCP disabled | 0 | 19 | 442.9 MiB | 209.6 MiB | 2 | +| local `dist/cli.js` | hooks disabled | 4 | 48 | 848.3 MiB | 212.6 MiB | 5 | +| local `dist/cli.js` | MCP + hooks disabled | 0 | 19 | 447.2 MiB | 217.8 MiB | 2 | + +Interpretation: + +1. Disabling MCP is the dominant change. It removes 4 MCP servers, reduces the + advertised tool count by about 29 tools, and lowers process-tree RSS by about + 0.42-0.47 GiB in this startup/config case. +2. Disabling hooks alone barely changes RSS in this case. That is expected + because the prompt did not produce tool calls, so `PreToolUse` / + `PostToolUse` hooks were not executed. +3. The root process stays around 0.21-0.25 GiB across all rows. The large + difference is again process-tree composition, not root Qwen RSS. + +Two attempted code-navigation follow-ups with `qwen3.6-plus` and `pai/glm-5` +also reproduced the same MCP-vs-no-MCP memory split, but neither model produced +tool calls in those runs. Those rows are therefore not used as hooks execution +evidence. A valid hooks benchmark still needs a task/model combination that +reliably emits tool calls. + +### Per-MCP Isolation + +The previous row showed MCP as a group is the dominant startup/config memory +factor. A follow-up isolated each configured MCP server while keeping hooks +disabled for all rows. This keeps the test on the normal settings-loading path +but changes only the MCP server subset. + +Configured MCP server names: + +- `approval-bridge` +- `env-center` +- `chrome-devtools` +- `code` + +Single-pass isolation: + +| Variant | Enabled MCPs | Tools | MCP servers | Tree RSS peak | Root RSS peak | Interpretation | +| ------------------------- | -------------------------------------------------- | ----: | ----------: | ------------: | ------------: | ------------------------------------ | +| none | none | 19 | 0 | 444.4 MiB | 211.7 MiB | baseline without MCP | +| full | all 4 | 48 | 4 | 857.3 MiB | 215.9 MiB | full MCP startup shape | +| only `approval-bridge` | `approval-bridge` | 19 | 1 | 455.5 MiB | 214.0 MiB | near baseline | +| only `env-center` | `env-center` | 19 | 1 | 452.3 MiB | 214.4 MiB | near baseline | +| only `chrome-devtools` | `chrome-devtools` | 48 | 1 | 824.4 MiB | 209.5 MiB | large RSS increase and tool increase | +| only `code` | `code` | 19 | 1 | 452.1 MiB | 216.6 MiB | near baseline | +| without `approval-bridge` | `env-center`, `chrome-devtools`, `code` | 48 | 3 | 997.1 MiB | 215.4 MiB | still high; run showed variance | +| without `env-center` | `approval-bridge`, `chrome-devtools`, `code` | 48 | 3 | 863.8 MiB | 220.9 MiB | still high | +| without `chrome-devtools` | `approval-bridge`, `env-center`, `code` | 19 | 3 | 463.4 MiB | 221.6 MiB | returns near baseline | +| without `code` | `approval-bridge`, `env-center`, `chrome-devtools` | 48 | 3 | 858.1 MiB | 219.5 MiB | still high | + +Because startup RSS has some variance, the key variants were repeated twice: + +| Variant | Samples | Tree RSS range | Avg tree RSS | Result | +| ------------------------- | ------: | ------------------- | -----------: | ------------------------------ | +| none | 2 | 443.3-451.9 MiB | 447.6 MiB | stable no-MCP baseline | +| full | 2 | 856.1-922.8 MiB | 889.5 MiB | stable high-MCP range | +| only `chrome-devtools` | 2 | 1,007.1-1,021.2 MiB | 1,014.2 MiB | enough alone to reproduce high | +| without `chrome-devtools` | 2 | 461.1-461.6 MiB | 461.4 MiB | removes the high RSS | +| only `approval-bridge` | 2 | 449.1-449.9 MiB | 449.5 MiB | near baseline | +| only `env-center` | 2 | 438.7-449.5 MiB | 444.1 MiB | near baseline | +| only `code` | 2 | 450.6-451.3 MiB | 451.0 MiB | near baseline | + +Interpretation: + +1. `chrome-devtools` is the dominant MCP contributor in this environment. It is + sufficient by itself to reproduce the high process-tree RSS. +2. Removing `chrome-devtools` from the full MCP set returns RSS to the no-MCP + band. Removing other MCPs while keeping `chrome-devtools` does not. +3. The advertised tool count follows the same pattern: baseline is 19 tools, + while `chrome-devtools` raises the tool count to 48. That means this MCP is + also likely to increase request tool schema size and token pressure, not just + process-tree RSS. +4. `approval-bridge`, `env-center`, and `code` individually stay near the + no-MCP baseline in these startup/config runs. They emitted startup warnings + in this environment, so this result should be interpreted as "no persistent + startup RSS owner observed" rather than proof that they have zero cost in all + workflows. + +## Runtime Summary + +| Case | Model | Wall | Turns | Total tokens | Tree RSS peak | Root RSS peak | End heap | End RSS | +| ---------------- | -------------- | ----: | ----: | -----------: | ------------: | ------------: | --------: | --------: | +| small PR `#4268` | `pai/glm-5` | 20.1s | 7 | 173,216 | 362.1 MiB | 359.8 MiB | 103.1 MiB | 216.5 MiB | +| code navigation | `pai/glm-5` | 18.4s | 2 | 49,127 | 378.0 MiB | 376.0 MiB | 102.4 MiB | 313.4 MiB | +| diff 94.6 KiB | `pai/glm-5` | 16.6s | 6 | 135,716 | 367.9 MiB | 366.0 MiB | 99.1 MiB | 295.0 MiB | +| diff 968.5 KiB | `pai/glm-5` | 11.4s | 2 | 42,590 | 373.2 MiB | 362.5 MiB | 106.4 MiB | 345.6 MiB | +| diff 4.84 MiB | `pai/glm-5` | 12.0s | 4 | 95,119 | 414.2 MiB | 412.0 MiB | 123.6 MiB | 410.7 MiB | +| small PR `#4268` | `qwen3.6-plus` | 35.0s | 6 | 156,556 | 358.9 MiB | 356.9 MiB | 102.6 MiB | 293.1 MiB | +| code navigation | `qwen3.6-plus` | 28.9s | 4 | 99,800 | 370.3 MiB | 368.3 MiB | 105.8 MiB | 298.2 MiB | +| diff 94.6 KiB | `qwen3.6-plus` | 28.3s | 4 | 90,808 | 358.8 MiB | 356.9 MiB | 105.9 MiB | 307.0 MiB | +| diff 968.5 KiB | `qwen3.6-plus` | 30.9s | 6 | 151,782 | 366.1 MiB | 364.1 MiB | 101.0 MiB | 316.9 MiB | +| diff 4.84 MiB | `qwen3.6-plus` | 24.1s | 4 | 93,271 | 372.8 MiB | 366.0 MiB | 142.8 MiB | 366.0 MiB | + +Average by model: + +| Model | Avg tree RSS peak | Avg root RSS peak | Avg turns | Avg total tokens | Avg max wire body | Avg total tool result | +| -------------- | ----------------: | ----------------: | --------: | ---------------: | ----------------: | --------------------: | +| `pai/glm-5` | 379.1 MiB | 375.3 MiB | 4.2 | 99,154 | 111.8 KiB | 335.1 KiB | +| `qwen3.6-plus` | 365.4 MiB | 362.4 MiB | 4.8 | 118,443 | 119.3 KiB | 344.3 KiB | + +Overlapping small PR `#4268` model snapshot: + +| Model | Protocol | Wall | Turns | Total tokens | Tree RSS peak | Root RSS peak | Max wire body | +| -------------------------- | --------- | ----: | ----: | -----------: | ------------: | ------------: | ------------: | +| `pai/glm-5` | OpenAI | 20.1s | 7 | 173,216 | 362.1 MiB | 359.8 MiB | 113.8 KiB | +| `qwen3.6-plus` | OpenAI | 35.0s | 6 | 156,556 | 358.9 MiB | 356.9 MiB | 134.1 KiB | +| `DeepSeek/deepseek-v4-pro` | Anthropic | 39.7s | 2 | 43,362 | 346.9 MiB | 344.8 MiB | 103.0 KiB | + +## Request And Tool Diagnostics + +| Case | Model | Requests | Max wire body | Max system prompt | Max tool schema | Tool calls | Total tool result | Max tool result | Max function response in request | +| ---------------- | -------------- | -------: | ------------: | ----------------: | --------------: | ---------: | ----------------: | --------------: | -------------------------------: | +| small PR `#4268` | `pai/glm-5` | 7 | 113.8 KiB | 51.4 KiB | 40.2 KiB | 9 | 4.7 KiB | 3.9 KiB | 15.3 KiB | +| code navigation | `pai/glm-5` | 2 | 114.6 KiB | 51.5 KiB | 40.2 KiB | 3 | 17.5 KiB | 6.2 KiB | 18.4 KiB | +| diff 94.6 KiB | `pai/glm-5` | 6 | 111.2 KiB | 39.1 KiB | 37.2 KiB | 9 | 94.9 KiB | 92.6 KiB | 29.2 KiB | +| diff 968.5 KiB | `pai/glm-5` | 2 | 104.8 KiB | 39.1 KiB | 37.2 KiB | 2 | 772.1 KiB | 771.9 KiB | 25.6 KiB | +| diff 4.84 MiB | `pai/glm-5` | 4 | 114.7 KiB | 39.1 KiB | 37.2 KiB | 4 | 786.3 KiB | 783.2 KiB | 34.7 KiB | +| small PR `#4268` | `qwen3.6-plus` | 6 | 134.1 KiB | 51.4 KiB | 40.2 KiB | 5 | 34.6 KiB | 15.6 KiB | 36.6 KiB | +| code navigation | `qwen3.6-plus` | 4 | 114.9 KiB | 51.5 KiB | 40.2 KiB | 3 | 17.5 KiB | 6.2 KiB | 18.4 KiB | +| diff 94.6 KiB | `qwen3.6-plus` | 4 | 112.8 KiB | 39.1 KiB | 37.2 KiB | 3 | 92.9 KiB | 92.6 KiB | 33.0 KiB | +| diff 968.5 KiB | `qwen3.6-plus` | 6 | 113.1 KiB | 39.1 KiB | 37.2 KiB | 5 | 778.0 KiB | 771.9 KiB | 32.1 KiB | +| diff 4.84 MiB | `qwen3.6-plus` | 4 | 121.5 KiB | 39.1 KiB | 37.2 KiB | 4 | 798.5 KiB | 783.2 KiB | 41.3 KiB | + +## Observations + +1. Process-tree RSS is almost the same as root RSS in this local bundle run. + The root/tree gap is usually below 10 MiB. That means these runs did not + show a persistent child-process memory owner. The dominant process is the + main Node process. +2. The local bundle run peaks around 0.36-0.41 GiB, not the earlier + 0.83-1.04 GiB, because the matrix used a stripped temporary config. A + follow-up normal-config sanity check reproduced about 1.1 GiB tree RSS on + both PATH `qwen` and local `dist/cli.js`, with the extra memory coming from + child MCP/Node processes in the process tree. +3. V8 heap is much smaller than RSS. End heap is about 99-143 MiB while end RSS + is about 216-411 MiB. The remaining footprint is likely loaded modules, + native allocations, external buffers, or runtime overhead outside live JS + heap. +4. Static request overhead is large and repeated. The system prompt is about + 39-51 KiB per request, and tool schema is about 37-40 KiB per request. This + explains why even small tasks can produce high accumulated token counts when + the model takes several turns. +5. Large diff output is capped before it reaches the model request. The 968 KiB + and 4.84 MiB diff cases produced around 772-799 KiB of captured tool result, + but the largest model-facing function response in a request stayed around + 25-41 KiB, and max wire body stayed around 105-122 KiB. This points to + truncation / saved-output handling working on the model-facing path. +6. Memory still increases on large-output cases even though wire body remains + bounded. For example, the 4.84 MiB GLM run reached 414.2 MiB tree RSS and + 410.7 MiB end RSS, and the 4.84 MiB qwen3.6-plus run ended with 142.8 MiB + heap. That suggests large tool output can still affect local capture, + normalization, or retained runtime state even when the final request payload + is capped. +7. Model choice changed turns and token totals more than RSS in this run. + `qwen3.6-plus` averaged more tokens and turns than `pai/glm-5`, but its + average tree RSS peak was slightly lower. This supports the earlier + conclusion that model choice is not the main explanation for process memory. + +## Updated Working Inference + +The new diagnostics make the earlier hypothesis more precise: + +- The installed-CLI user-visible 1 GiB peak is now reproducible with the normal + config on the local diagnostics bundle. The stripped run should be used for + internal Qwen runtime attribution; the normal-config run should be used for + user-visible process-tree attribution. +- The largest observed difference between stripped and normal config is + process-tree shape: normal config starts additional MCP/Node child processes. + Those children explain most of the absolute jump from about 0.35-0.55 GiB to + about 1.1 GiB in the minimal prompt sanity check. +- The `--bare` follow-up confirms the same direction on `qwen3.6-plus`: normal + config costs about 0.50-0.59 GiB more process-tree RSS than bare mode for the + same prompt shape, while root RSS changes only slightly. +- The temporary-settings isolation is a better attribution test than `--bare`: + disabling MCP alone reduces process-tree RSS by about 0.42-0.47 GiB while + keeping the normal settings-loading path. Disabling hooks alone does not show + a meaningful RSS change in no-tool-call cases. +- Per-MCP isolation points to `chrome-devtools` as the dominant MCP contributor: + it is enough by itself to reproduce the high RSS band, and removing it returns + the run near the no-MCP baseline. +- Within the local Qwen runtime, the most suspicious areas are no longer "raw + diff bytes sent to the model". The model-facing request body is bounded. +- The stronger suspects are static per-request context cost, repeated request + rounds, tool schema size, and local retention/capture of large tool outputs + before or outside model-facing truncation. +- Because RSS remains much higher than V8 heap, the next profiling layer should + include module/startup accounting, external memory, and heap snapshots around + tool execution and final response emission. + +## RSS Attribution From Current Diagnostics + +The current counters do not identify an exact retained object or source file, +but they do narrow what is and is not driving RSS in these local runs: + +| Signal | Current evidence | RSS implication | +| ---------------------------- | --------------------------------------------------------------------------------------------------------------------------- | ----------------------------------------------------------------------------------------------------------------------------------------- | +| Root RSS vs process-tree RSS | Root and tree peaks are usually within about 2-10 MiB; DeepSeek large PR is the widest gap at about 23.6 MiB | No persistent child process explains the RSS in this local bundle run; the main Node process dominates | +| Normal config process tree | Minimal-prompt normal-config runs reach about 1.1 GiB tree RSS while root RSS stays about 213-250 MiB | User-visible 1 GiB peaks can be dominated by MCP/Node child processes rather than Qwen root RSS alone | +| `--bare` comparison | `qwen3.6-plus` normal runs peak around 1.02-1.05 GiB tree RSS; bare runs peak around 0.45-0.53 GiB | Loading normal config adds about 0.50-0.59 GiB process-tree RSS in this environment | +| Temporary MCP isolation | Clearing MCP servers drops startup/config tree RSS from 865-1,017 MiB to 443-549 MiB | MCP startup and MCP child processes explain about 0.42-0.47 GiB of process-tree RSS in the controlled config check | +| Per-MCP isolation | `chrome-devtools` alone reaches about 1.0 GiB in repeated samples; without it the run stays around 461 MiB | `chrome-devtools` is the dominant MCP process-tree RSS contributor in this environment | +| Temporary hooks isolation | `disableAllHooks=true` with MCP still enabled changes tree RSS by only about 13-18 MiB in no-tool-call cases | Hook config alone is not a visible startup RSS driver here; hook execution still needs a tool-call benchmark | +| V8 heap vs RSS | End heap is about 99-143 MiB while end RSS is about 216-411 MiB | Live JS heap is not the whole footprint; loaded modules, native allocations, external buffers, or runtime overhead are likely significant | +| PR/diff size vs RSS | DeepSeek small/medium/large PRs scale from 1 to 4,750 changed lines, but tree RSS stays in a narrow 340.7-360.0 MiB band | Raw PR size is not linearly driving RSS once tool output is bounded | +| Tool output size | Large diff runs capture about 772-799 KiB tool results and show some higher end RSS / heap, but RSS does not scale linearly | Tool result capture/normalization contributes pressure, especially large-output cases, but is unlikely to be the only RSS driver | +| Request body size | Max model-facing body ranges from about 103-289 KiB while RSS stays near the same band | Request serialization size affects tokens and latency more clearly than RSS peak | +| Static per-request context | System prompt is about 39-51 KiB and tool schema about 37-48 KiB per request | Repeated rounds are a token/cost amplifier; this alone does not explain RSS but is a likely optimization target for token pressure | + +Working attribution: in the stripped local bundle benchmark, the RSS floor looks +mostly like task-time runtime/module/native footprint, with large tool output +adding incremental pressure. In the normal-config run, the user-visible 1 GiB +tree peak is mostly process-tree composition: Qwen root plus MCP/Node child +processes. The next targeted measurement should split Qwen root diagnostics +from configured MCP server diagnostics, then add startup/module/external-memory +checkpoints inside the Qwen root process. + +## Progress Snapshot + +Current confirmed signals: + +1. The user-visible 1 GiB startup/config peak is reproducible with both the + installed CLI and the local diagnostics bundle when the normal config is + loaded. It is not primarily explained by the diagnostics branch or PR `#4186`. +2. In this environment, that 1 GiB peak is mostly process-tree composition: + Qwen root process plus relaunch child process plus MCP child processes. +3. `chrome-devtools` is the dominant configured MCP contributor in the current + config. It is enough by itself to reproduce the high process-tree RSS band, + even when the prompt does not explicitly use that MCP. +4. The no-MCP normal relaunch shape still sits around 0.45 GiB process-tree RSS. + A single Qwen runtime process without the relaunch parent is closer to + 0.22-0.24 GiB in the startup attribution check. This means the 0.45 GiB + baseline is not a single-process root RSS number. +5. In stripped non-interactive task runs, model choice changes turns, token + totals, latency, and request sizes more clearly than RSS. RSS stayed in a + relatively narrow range across `pai/glm-5`, `qwen3.6-plus`, and + `DeepSeek/deepseek-v4-pro`. +6. Current short-task diagnostics show model-facing tool/function responses are + bounded, but local tool-result capture and runtime state can still increase + heap/RSS on large-output cases. This keeps large-output retention on the + investigation path. + +Current gaps: + +1. The short-task benchmark matrix is still short-lived. A later interactive + long-review run did reproduce a 41.9 min failure, but it is still one sample + and needs repeat runs plus heap/object attribution. +2. The current counters are enough to attribute process-tree RSS and request + size, but not enough to name the retained JS object graph during long + sessions. +3. Startup/config RSS and long-session OOM must remain separate tracks. MCP and + relaunch explain a large idle/startup RSS band; they do not by themselves + explain V8 heap OOM after long tasks. +4. Interactive TUI memory still needs a separate run from non-interactive mode, + because UI history and Ink static output are not exercised the same way. + +## Long-Task OOM Evidence From Issues And PRs + +Issue/PR evidence points to several different OOM shapes, not one single +failure mode: + +| Source | Evidence summary | Hypothesis to test | +| ---------------------------------------------------------------------------------------------------------------------- | ----------------------------------------------------------------------------------------------------------------------------------------------------- | -------------------------------------------------------------------------------------------------------------------------------- | +| [`#4309`](https://github.com/QwenLM/qwen-code/issues/4309) | User reports 5.84 GiB memory usage / 7.02 GiB warning with YOLO mode and DeepSeek backend; increasing Node memory to 8 GiB did not remove the symptom | Long autonomous tool loops can retain enough state that simply raising old-space limit is not a root fix | +| [`#4149`](https://github.com/QwenLM/qwen-code/issues/4149) | Multiple reports show `Ineffective mark-compacts near heap limit`, including 4 GiB and much larger heap-limit cases | A large fraction of heap is reachable application state, not immediately collectible garbage | +| [`#4116`](https://github.com/QwenLM/qwen-code/issues/4116) | OOM occurred while context display was around 9.5%; analysis points to `structuredClone`, UI history, Ink static tree, and large context windows | Token usage can be low while JS heap pressure is high; token threshold alone is not a reliable memory guard | +| [`#4167`](https://github.com/QwenLM/qwen-code/issues/4167) | User says the crash happened while compressing; analysis identifies compression peak memory as a distinct shape | Compression can itself create a peak when heap is already high, especially if history is cloned/stringified around the same time | +| [`#2128`](https://github.com/QwenLM/qwen-code/issues/2128) | Report identifies unbounded UI history, retained file diffs / terminal output, string-width caches, and checkpoint serialization | Interactive TUI long sessions may retain memory outside model history and outside non-interactive benchmarks | +| [`#2562`](https://github.com/QwenLM/qwen-code/issues/2562) | Report focuses on `GeminiChat.getHistory()` deep-cloning full history in long sessions | Full-history cloning can amplify memory peaks and should be measured separately from retained steady-state size | +| [`#4185`](https://github.com/QwenLM/qwen-code/issues/4185) | Tracks V8 heap pressure exceeding limit before token-based compaction runs | Heap-pressure guard is necessary, but it only mitigates symptoms if retained data remains large | +| [`#4184`](https://github.com/QwenLM/qwen-code/issues/4184) | Proposes diagnostics and offload/preview for large retained tool results | Large tool output may be bounded for model requests while still retained in local hot memory | +| [`#4186`](https://github.com/QwenLM/qwen-code/pull/4186) | Merged heap-pressure auto-compaction safety net and O(1) last-history access for `nextSpeakerChecker` | Covers part of heap-pressure and clone amplification, but does not claim to solve all OOM classes | +| [`#4127`](https://github.com/QwenLM/qwen-code/pull/4127), [`#4168`](https://github.com/QwenLM/qwen-code/pull/4168) | Open compaction-threshold PRs; one uses fixed heap thresholds, the other redesigns token thresholds and compression behavior | Useful related work, but long-task testing must verify whether heap, token, and compression signals line up in real runs | +| [`#3000`](https://github.com/QwenLM/qwen-code/issues/3000), [`#4183`](https://github.com/QwenLM/qwen-code/issues/4183) | Diagnostic roadmap calls out `/doctor memory`, heap snapshot, and bounded memory timeline | Snapshot/timeline support is needed to move from RSS attribution to retained-object attribution | + +Initial interpretation: + +- Unused configured MCP can consume memory because normal startup connects to + configured MCP servers and advertises their tools before the task needs them. + In the measured config, `chrome-devtools` starts extra Node/npm MCP processes + and also increases the tool schema count from 19 to 48. This explains a large + startup/config RSS band and can also increase repeated request overhead. +- The long-session OOM reports are a different layer. GC logs where + Mark-Compact frees very little memory suggest the heap is full of reachable + state. The strongest candidates are retained history/tool/UI objects, + full-history clones, compression intermediates, and streaming/logging + accumulators. +- PR `#4186` is a useful mitigation because it can compact based on heap + pressure before token thresholds trigger, and it removes one unnecessary + full-history clone. It should not be treated as proof that large tool-output + retention, UI history retention, or compression peak memory is already solved. + +## Long-Task Validation Plan + +The next benchmark should keep two tracks separate: + +1. Startup/config attribution: normal config vs MCP-disabled vs + `chrome-devtools`-only vs no-relaunch attribution. This explains what users + see before meaningful work begins. +2. Long-task runtime growth: repeated tool calls, large outputs, compression, + resume, and interactive UI history. This explains OOM after real work. + +Recommended long-task cases: + +| Case | Shape | Why it matters | +| ----------------------------- | ---------------------------------------------------------------------------------------------------- | ------------------------------------------------------------------------------------------------- | +| Long PR review loop | Repeat medium/large PR review prompts for 30, 60, and 120 minutes, with fixed model and fixed config | Closest to reported agent workflows; captures turns, tool calls, token growth, and RSS/heap trend | +| Large tool-output retention | Repeatedly produce bounded 1 MiB / 5 MiB / 20 MiB command outputs, then ask follow-up questions | Tests whether raw output is retained locally after model-facing truncation | +| Compression pressure | Use a lower controlled old-space limit and large-context prompts to trigger heap-pressure compaction | Verifies PR `#4186` triggers before OOM and whether compression itself creates a new peak | +| Interactive TUI history | Run the same long loop in tmux TUI mode and compare with non-interactive mode | Isolates UI history, Ink static output, rendered diffs, and terminal-output display retention | +| Resume stress | Resume a large saved session and immediately continue work | Targets `/resume` OOM reports and session reconstruction cost | +| Streaming/logging accumulator | Force long streamed responses with telemetry/logging enabled vs disabled | Tests the suspected `collected responses` / logging-retention path from issue analysis | +| MCP idle vs MCP active | Run no-MCP, `chrome-devtools` configured-but-unused, and `chrome-devtools` actively used variants | Separates idle MCP child RSS from actual MCP tool execution and tool schema/token overhead | + +Metrics that should be recorded per turn or per sampling interval: + +- Root RSS current/peak and process-tree RSS current/peak. +- Child process count and top child command shapes. +- V8 `heapUsed`, `heapTotal`, `heap_size_limit`, `external`, and + `arrayBuffers`. +- Turn count, request count, tool-call count, and tool-call rounds. +- Input/output/cache/total tokens by request and by whole task. +- Request body bytes, system prompt bytes, tool schema bytes, and function + response bytes. +- Tool-result count, total captured tool-result bytes, max tool-result bytes, + and retained tool-result bytes if available. +- Conversation history message count and approximate history byte size. +- Interactive-only UI history item count and approximate retained display size. +- Compression attempts, compression trigger reason, tokens before/after, heap + pressure before/after, and compression failure status. +- Heap snapshot or bounded memory timeline artifacts when heap pressure crosses + a configured threshold. + +Validation criteria: + +1. Repeat at least the key long-task cases twice. Startup RSS has visible + variance, so single-run conclusions should be avoided. +2. Report root RSS and process-tree RSS separately. User-facing memory pressure + can come from child processes, while V8 OOM comes from the Qwen root heap. +3. Treat a flat RSS line as important evidence. If tokens and tool calls grow + but heap/RSS stays flat, the issue is likely elsewhere. +4. When RSS or heap grows, correlate the growth with a specific signal: + tool-result bytes, history bytes, UI history count, compression event, + streaming accumulator size, or MCP process start. +5. If a heap snapshot is taken, write a structured diagnostics JSON first, then + the snapshot. Heap snapshots may be large and can contain sensitive strings, + so they should remain opt-in and local. + +## Interactive Long-Review Reproduction + +After the short non-interactive prompts kept finishing before the target window, +an interactive TUI benchmark was run with remote input. The CLI process stayed +alive in one session while a controller submitted one real PR-review turn at a +time. The next turn was only submitted after the assistant emitted that turn's +completion marker. This avoids treating a short one-shot prompt as a long-task +reproduction. + +Setup: + +- Installed Qwen Code `0.15.11`, model `qwen-latest-series-invite-beta-v28`. +- Temporary CLI home derived from the normal settings, with MCP and hook config + removed. No global config was modified. +- Interactive TUI mode with dual JSON event output and remote JSONL input. +- Static PR review only. The prompt disallowed dependency install, build, test, + Playwright, Docker, and other long external build commands. +- External RSS samplers recorded both process-tree RSS and the Qwen Node root + RSS every 5 seconds. + +Outcome: + +| Signal | Value | +| ----------------------------- | ----------: | +| Wall time before exit | 41.9 min | +| Exit status | 1 | +| Completed PR-review turns | 6 | +| Main chat records | 1,076 | +| API response telemetry | 335 | +| Tool-call telemetry | 607 | +| MCP tool-call telemetry | 0 | +| Main/root API responses | 36 | +| Subagent API responses | 299 | +| Root total tokens | 2.08M | +| Subagent total tokens | 17.24M | +| Total API telemetry tokens | 19.32M | +| Max root input tokens | 85,655 | +| Max subagent input tokens | 215,207 | +| `/usr/bin/time -l` max RSS | 1,072.4 MiB | +| Sampled Qwen root RSS peak | 1,028.2 MiB | +| Sampled process-tree RSS peak | 1,038.1 MiB | + +The process exited with: + +```text +libc++abi: terminating due to uncaught exception of type std::__1::system_error: thread constructor failed: Resource temporarily unavailable +``` + +This is a **thread exhaustion** error, not a V8 heap OOM. The failure mechanism +is distinct: the OS refused to create a new thread, likely due to per-process +resource limits (`RLIMIT_NPROC`) or memory fragmentation preventing stack +allocation. It is still relevant because it occurred in a disabled-MCP, +no-build/test, interactive long-session review where the Qwen Node process +itself crossed about 1 GiB RSS. +The failure happened during the final summary phase, after the controller had +already completed six review turns. + +Turn timeline and sampled Qwen root RSS: + +| Window | Turn state | Qwen root RSS max | Qwen root RSS at window end | +| ------------- | -------------------- | ----------------: | --------------------------: | +| 0.0-9.0 min | turn 1 completed | 701.2 MiB | 255.3 MiB | +| 9.0-15.1 min | turn 2 completed | 503.2 MiB | 494.4 MiB | +| 15.1-24.1 min | turn 3 completed | 468.7 MiB | 457.5 MiB | +| 24.1-31.9 min | turn 4 completed | 619.3 MiB | 602.3 MiB | +| 31.9-40.3 min | turn 5 completed | 955.5 MiB | 955.5 MiB | +| 40.3-40.4 min | turn 6 completed | 988.6 MiB | 988.6 MiB | +| 40.4-41.9 min | final summary / exit | 1,028.2 MiB | 1,028.2 MiB | + +Token and tool distribution: + +| Owner | API responses | Input tokens | Output tokens | Total tokens | Max input | +| ------------ | ------------: | -----------: | ------------: | -----------: | --------: | +| Root session | 36 | 2.06M | 22.2K | 2.08M | 85,655 | +| Subagents | 299 | 17.08M | 154.6K | 17.24M | 215,207 | + +Tool-call telemetry by function: + +| Tool | Calls | Captured content length | +| ------------------- | ----: | ----------------------: | +| `read_file` | 271 | 1.46 MB | +| `run_shell_command` | 181 | 164.4 KB | +| `web_fetch` | 80 | 846.3 KB | +| `grep_search` | 25 | 15.0 KB | +| `glob` | 15 | 27.8 KB | +| `todo_write` | 16 | 16.1 KB | +| `list_directory` | 8 | 6.2 KB | +| `agent` | 10 | 0 | +| `tool_search` | 1 | 2.1 KB | + +The top visible TUI token counter for a single agent reached about 3.83M +tokens. Telemetry also shows the heaviest subagent at about 4.05M total tokens +with a 215K-token max input request. That makes subagent amplification the +dominant signal in this reproduction. + +Interpretation: + +1. This run separates long-session growth from MCP startup/config memory. MCP + was disabled and there were no MCP tool calls, yet the Qwen root process + still reached about 1 GiB RSS. +2. The late memory peak aligns with subagent-heavy review turns and final + summary/merge-back, not with external build/test child processes. +3. The RSS curve is not a simple linear leak. It falls after early turns, then + rises sharply after later subagent turns and remains high near exit. +4. The failure mode is native resource exhaustion rather than a V8 heap-limit + stack, so the next run should add heap/external/arrayBuffer/thread-count + sampling. RSS alone cannot distinguish JS heap from native allocations or + thread-resource pressure. +5. The strongest code paths to inspect remain subagent transcript retention, + agent-result merge-back, full-history cloning, checkpoint/session recording, + and final summary/history assembly. + +## Deterministic Huge-Task Clone-Pressure Reproduction + +A deterministic stress harness was added as +`scripts/memory-pressure-repro.mjs`. It does not call a model. Instead, it +constructs a Qwen-like long-session object graph with root review turns, +subagent transcripts, large tool results, checkpoint JSON, and retained +`structuredClone()` copies. This gives a repeatable reproduction for the clone +and checkpoint peak suspected from the user-provided OOM stack. + +The harness has a lightweight script test: + +```bash +npx vitest run --config ./scripts/tests/vitest.config.ts \ + scripts/tests/memory-pressure-repro.test.js +``` + +Result: passed, 1 test. + +Controlled runs used `node --max-old-space-size=256` unless otherwise noted. + +| Case | History shape | Clone/checkpoint pressure | Result | Max RSS | +| ------------------------------------------------- | ----------------------------------------------------------------------- | -------------------------------------------------- | --------------------------------- | --------: | +| Small sanity | 2 turns, 2 KiB tool result, 1 subagent | 1 clone + 1 checkpoint | passed; 2.6 MiB history JSON | 89.7 MiB | +| Huge build only | 12 turns, 256 KiB tool result, 2 subagents x 12 subagent turns | no retained clone/checkpoint | passed; 76.2 MiB history JSON | 491.5 MiB | +| Huge + 1 clone | same as above | 1 retained `structuredClone()` | passed | 569.6 MiB | +| Huge + 2 clones | same as above | 2 retained `structuredClone()` copies | OOM, exit 134 | 496.5 MiB | +| Huge + 1 checkpoint | same as above | one checkpoint with original + cloned history JSON | passed; 152.5 MiB checkpoint JSON | 926.9 MiB | +| Huge + 2 checkpoints | same as above | two checkpoint copies | OOM, exit 134 | 920.1 MiB | +| Huge + 2 clones, no retained subagent transcripts | same generated subagent output, but parent history keeps only summaries | passed; parent history JSON drops to 3.8 MiB | 136.8 MiB | + +The failing huge-clone run produced: + +```text +FATAL ERROR: Reached heap limit Allocation failed - JavaScript heap out of memory +``` + +The native stack included: + +- `v8::internal::ValueDeserializer::ReadObjectInternal` +- `v8::internal::ValueDeserializer::ReadDenseJSArray` +- `node::worker::Message::Deserialize` +- `node::worker::StructuredClone` + +This matches the same stack family as the user-provided OOM log. The controlled +reproduction also shows why 4 GiB / 8 GiB user reports are plausible: the +failure is not caused by a single large object, but by large retained +history/tool-result/subagent state plus one or more full-history clone or +checkpoint copies. Raising `--max-old-space-size` can delay the crash while +preserving the same amplification pattern. + +Important attribution from this deterministic run: + +1. Building a 76.2 MiB parent history JSON can succeed under the reduced heap. + The OOM appears when additional full-history clone/checkpoint copies are + retained. +2. A single checkpoint copy can push RSS close to 1 GiB even before OOM. +3. Removing retained subagent transcripts from the parent hot history changes + the same generated workload from OOM to a small 136.8 MiB RSS run. That is + the clearest mitigation signal so far. +4. This reproducer is synthetic and intentionally adversarial, but it exercises + the same object-graph shape as the long interactive review: parent session, + subagents, large tool outputs, transcript merge-back, and full-history clone + pressure. + +## DeepSeek PR-Size Follow-Up + +After the initial model matrix, an additional Qwen Code-only run tested +`DeepSeek/deepseek-v4-pro` across three real PR sizes. This model is configured +through the Anthropic-compatible protocol; OpenAI-compatible execution returned +404 in a smoke check, so the successful benchmark uses `--auth-type anthropic`. + +The diagnostics branch was extended to record Anthropic wire request summaries +with the same privacy rule as the OpenAI path: aggregate counts and byte sizes +only, no prompt text, diff content, tool arguments, headers, base URL, or API +key. + +PR sizes: + +| Size | PR | State | Files | Changed lines | Title | +| ------ | ------- | ------ | ----: | ------------: | ----------------------------------------------------------------------- | +| small | `#4268` | merged | 1 | 1 | fix(serve): add mcp_guardrails to E2E capabilities expectation | +| medium | `#4186` | merged | 6 | 494 | fix(core): add heap-pressure auto-compaction safety net | +| large | `#4168` | open | 25 | 4,750 | feat(core)!: redesign auto-compaction thresholds with three-tier ladder | + +Runtime: + +| Size | PR | Wall | Turns | Total tokens | Cache-read tokens | Tree RSS peak | Root RSS peak | End heap | End RSS | +| ------ | ------- | -----: | ----: | -----------: | ----------------: | ------------: | ------------: | --------: | --------: | +| small | `#4268` | 39.7s | 2 | 43,362 | 28,672 | 346.9 MiB | 344.8 MiB | 115.2 MiB | 304.3 MiB | +| medium | `#4186` | 142.6s | 4 | 135,120 | 115,840 | 340.7 MiB | 337.3 MiB | 103.5 MiB | 285.6 MiB | +| large | `#4168` | 191.1s | 8 | 386,891 | 332,928 | 360.0 MiB | 336.3 MiB | 119.3 MiB | 237.9 MiB | + +Request and tool diagnostics: + +| Size | PR | Requests | Anthropic wire requests | Max Anthropic body | Max system | Max tool schema | Tool calls | Total tool result | Max tool result | Max function response in request | +| ------ | ------- | -------: | ----------------------: | -----------------: | ---------: | --------------: | ---------: | ----------------: | --------------: | -------------------------------: | +| small | `#4268` | 2 | 2 | 103.0 KiB | 50.8 KiB | 47.6 KiB | 3 | 0.6 KiB | 0.5 KiB | 1.1 KiB | +| medium | `#4186` | 4 | 4 | 159.8 KiB | 50.8 KiB | 47.6 KiB | 5 | 30.2 KiB | 29.3 KiB | 56.7 KiB | +| large | `#4168` | 8 | 8 | 289.5 KiB | 50.8 KiB | 47.6 KiB | 11 | 235.0 KiB | 232.1 KiB | 182.4 KiB | + +DeepSeek observations: + +1. PR size scaled turns, tokens, Anthropic wire body size, and tool result size + clearly, but did not scale RSS proportionally. The small/medium/large tree + RSS peaks stayed in a narrow `340.7-360.0 MiB` band. +2. The large PR was expensive mostly in model rounds and token volume: + 8 requests and 386,891 total tokens. Its max Anthropic body was 289.5 KiB, + much larger than the OpenAI-compatible runs, but RSS still stayed near the + same local-bundle band. +3. The static Anthropic request cost is also visible: system prompt is about + 50.8 KiB and tool schema about 47.6 KiB per request. Repeated rounds are + therefore a major token amplifier. +4. The large PR produced 235.0 KiB of captured tool results and 182.4 KiB max + function response in a request. This is higher than the earlier small PR / + code-navigation cases and shows large PRs still put pressure on local + tool-result handling and request assembly, even when RSS does not spike. +5. The DeepSeek run reinforces the model-choice conclusion: provider/model + choice strongly changes turns, latency, token volume, and wire payload shape, + but the local bundle RSS peak remains dominated by Qwen Code runtime shape + rather than scaling linearly with PR size. + +## Long-Review JSONL Replay: History Clone Pressure + +A recent long PR-review chat record was analyzed as a post-mortem shape for +the reported OOM class. The raw JSONL is not included here because it contains +prompt and tool output text. The aggregate shape is: + +| Signal | Value | +| ----------------------- | ----------------------------- | +| Duration | 87.0 min | +| Qwen Code version | 0.15.10 | +| Model | qwen-latest-series beta model | +| API responses | 380 | +| Tool-call telemetry | 507 events | +| MCP tool-call telemetry | 4 events | +| Subagent API responses | 313 | +| Root API responses | 67 | +| Root prompt growth | 38,622 -> 168,555 tokens | +| Max prompt tokens | 168,555 | +| Total response tokens | 31.28M | + +This shape does not support MCP as the primary OOM cause for this case. Only +4 of 507 tool-call telemetry events were MCP, and all four recorded +`content_length=0`. The dominant shape is long-session/subagent amplification: +15 `agent` calls produced 313 subagent API responses and 403 subagent tool-call +events. + +The replay then rebuilt the chat `Content[]` message shape from the JSONL and +ran controlled clone/stringify pressure tests. The base retained message payload +is small, so it is not itself enough to OOM: + +| Replay scale | Retained clones | History JSON | Checkpoint JSON | End heap | End RSS | +| ------------ | --------------: | -----------: | --------------: | -------: | -------: | +| 1x | 8 | 0.54 MB | 1.08 MB | 18.0 MB | 88.8 MB | +| 30x | 8 | 14.46 MB | 28.92 MB | 260.0 MB | 577.8 MB | +| 60x | 8 | 28.86 MB | 57.71 MB | 510.3 MB | 960.8 MB | + +The scaled replay is not a user-data claim; it is a controlled amplification of +the observed JSONL shape to test whether full-history clone and checkpoint +serialization can create the same failure mode as the reports. + +A low-heap reproduction with `--max-old-space-size=256` confirms the mechanism: + +| Case | History JSON | Result | +| ------------------------- | -----------: | ----------------------------------------------------- | +| Build history only | 38.4 MB | Succeeded; heap 131.6 MB, RSS 378.2 MB | +| Build + one clone | 38.4 MB | Succeeded; heap 183.3 MB, RSS 463.4 MB | +| Build + repeated clones | 38.4 MB | OOM after several retained `structuredClone()` copies | +| Checkpoint double-history | 38.4 MB | OOM while holding history plus cloned client history | + +The repeated-clone OOM stack contains `ValueDeserializer::ReadObjectInternal`, +`ValueDeserializer::ReadDenseJSArray`, +`node::worker::Message::Deserialize`, and +`node::worker::StructuredClone`, matching the same stack family seen in the +user-provided OOM log. This proves that full-history `structuredClone()` can be +the immediate OOM trigger without any MCP server involvement. + +Current working hypothesis for this JSONL class: + +1. MCP can explain normal-config startup RSS in separate benchmarks, but it is + not the likely trigger for this long-review OOM shape. +2. Long task growth comes from retained chat history, large tool outputs, + subagent histories, observable agent messages, and UI/tool-result state. +3. The immediate OOM trigger can be a full-history clone or checkpoint-style + double serialization after the heap is already high. +4. Compression can mitigate retained history, but compression itself may create + a temporary peak if it first clones or serializes large history. + +### Local Mitigation Validation: Disabled-MCP PR Review Case + +Two targeted mitigations were applied locally and validated before rerunning a +disabled-MCP PR review case: + +1. `checkNextSpeaker()` now reads only the last curated message with + `getHistoryTail(1, true)` and sends only that message to the next-speaker + side query. The next-speaker prompt only asks about the immediately previous + model response, so sending full history was unnecessary clone and token + pressure. +2. `AgentToolInvocation` no longer retains full `responseParts` arrays inside + the live `task_execution.toolCalls` display. The real response parts still + flow through transcript/history paths, but the parent UI display now keeps + only a bounded text summary for nested tool-result streaming instead of + holding another full copy of large subagent tool outputs during long runs. +3. `GeminiChat.sendMessageStream()` now builds model request contents through + an internal curated-history view instead of calling public + `getHistory(true)`. Public `getHistory()` still returns a defensive + `structuredClone()` for external callers, but the request hot path no longer + deep-clones the whole retained chat history before every model call. + +TDD checks added for these mitigations: + +| Test | Expected protection | +| -------------------------------------------------------------------------------------------------------------- | ---------------------------------------------------------------------------------------- | +| `checkNextSpeaker > should send only the last curated model message to the side query` | Prevents full-history clone/send in next-speaker checks | +| `AgentTool > should not retain responseParts in live tool call display after TOOL_RESULT` | Prevents live subagent display from retaining large tool responses | +| `AgentTool > should keep only a bounded result summary in live tool call display` | Preserves nested result readability without retaining the full response body | +| `GeminiChat > sendMessageStream > does not deep-clone the full curated history when building request contents` | Prevents request setup from hitting the `ValueDeserializer` / `StructuredClone` OOM path | + +Additional reproduction and fix validation: + +| Step | Command shape | Result | +| ------------------------------------ | -------------------------------------------------------------------------------------------------------------------------------------------- | ------------------------------------------------------------------------------------------------------------------------------------- | +| Pre-fix deterministic clone pressure | `node --max-old-space-size=256 scripts/memory-pressure-repro.mjs ... --clone-count=2 --mode=clone` | OOM, exit 134; stderr contained `Reached heap limit` and `ValueDeserializer` / `StructuredClone`; max RSS 528.1 MiB in the repeat run | +| Red test | targeted `GeminiChat` test with `structuredClone` forced to throw during request setup | failed at `GeminiChat.getHistory()` before the mitigation | +| Green test | same targeted `GeminiChat` test after the mitigation | passed | +| Built-code smoke | `node --max-old-space-size=256` against the built core package, with a 96-entry / about 48 MiB history and `structuredClone` forced to throw | passed; request had 97 contents; process RSS 161.4 MiB, `/usr/bin/time -l` max RSS 161.6 MiB | + +This narrows the earlier "same stack family" statement: the deterministic +synthetic OOM still proves retained full-history clones can fail in the same V8 +stack family as the user log, while the new `GeminiChat` red/green test proves +one real production request-setup path no longer reaches that clone point. +Checkpoint/resume and compression internals still need separate long-run +validation because they can legitimately need durable copied history. + +Verification commands: + +| Command | Result | +| ------------------------------------------------------------------------------------------------------ | ------------------------------------------------------------------------------------------------------------------------------------------- | +| `npx vitest run src/core/geminiChat.test.ts` | passed, 89 tests | +| `npx vitest run src/utils/nextSpeakerChecker.test.ts --coverage=false` | passed, 13 tests | +| `npx vitest run src/tools/agent/agent.test.ts --coverage=false` | passed, 77 tests | +| `npx vitest run --config ./scripts/tests/vitest.config.ts scripts/tests/memory-pressure-repro.test.js` | passed, 1 test | +| `npm run build --workspace=packages/core` | passed | +| `npm run build --workspace=packages/cli` | passed | +| `npm run typecheck --workspace=packages/core` | passed | +| `npm run typecheck --workspace=packages/cli` | passed | +| `npm run bundle` | passed | +| `npm run build` | failed in `packages/vscode-ide-companion` lint on existing internal-module import rules; core, CLI, bundle, and targeted tests above passed | + +The full root `npm run build` was not clean in this worktree because the +`vscode-ide-companion` package hit pre-existing `import/no-internal-modules` +lint errors. The core/CLI build and bundle needed for the local runtime test +completed successfully. + +The same PR review prompt was then run with a temporary config where MCP and +hooks were disabled. Both rows were interrupted after a bounded long-run window +instead of waiting for a full review to finish. **Caveat**: the two runs are +confounded by workload size (79K vs 390K tokens) and cannot be compared as a +controlled experiment. The comparison only shows directional evidence. + +| Variant | Runtime | MCP servers | Tools | Assistant messages | Tool use/result blocks | Parent tool ids | Total tokens | Max input tokens | Root max RSS | +| ----------------- | ------: | ----------: | ----: | -----------------: | ---------------------: | --------------: | -----------: | ---------------: | -----------: | +| before mitigation | 365.08s | 0 | 19 | 42 | 42 / 42 | 3 | 79,439 | 26,807 | 357.7 MiB | +| after mitigation | 404.52s | 0 | 19 | 58 | 52 / 42 | 2 | 390,339 | 54,000 | 310.5 MiB | + +This is not a deterministic apples-to-apples model benchmark: the patched run +did more work and consumed substantially more total tokens before the manual +cutoff. The useful signal is narrower: under a disabled-MCP review case with +more observed work, root max RSS did not increase and was about 47.2 MiB lower. +That supports the mitigation direction, but it does not prove the whole +long-task OOM class is fixed. + +Remaining high-risk clone/retention paths to inspect next: + +1. Compression still calls full `getHistory(true)` before summarization. If the + heap is already high, the compression attempt can create the peak that trips + OOM. +2. Checkpoint creation can hold original history, cloned client history, and a + serialized checkpoint payload at the same time. +3. Fork subagents still seed from parent history with `getHistory(true)`. +4. ACP/history export/summary/copy paths still call full `getHistory()` and + should be audited separately from the normal review loop. + +Version timing: + +| Issue | Created | Reported version | Signal | +| ----- | ---------- | ------------------------ | ---------------------------------------- | +| #2128 | 2026-03-05 | not specified | Long-session UI memory growth | +| #2562 | 2026-03-21 | not specified | `structuredClone` OOM in long sessions | +| #2868 | 2026-04-03 | 0.13.2 | Heap OOM | +| #2945 | 2026-04-07 | 0.14.0 | V8 heap OOM | +| #4116 | 2026-05-13 | 0.15.11 | OOM with structured-clone-style analysis | +| #4134 | 2026-05-14 | 0.15.11 | OOM | +| #4149 | 2026-05-14 | 0.15.10-nightly.20260513 | V8 heap OOM | +| #4167 | 2026-05-15 | 0.15.11 | Crash near compression | +| #4185 | 2026-05-15 | 0.15.11 | Heap pressure before token compaction | +| #4254 | 2026-05-17 | not specified | Memory keeps rising | +| #4276 | 2026-05-18 | 0.15.11 | V8 heap OOM | +| #4309 | 2026-05-19 | 0.15.11 | High memory warning around 7 GiB | + +The issue history does not prove that 0.15.10 introduced the OOM class; similar +reports existed in March and April. It does support a recent cluster beginning +around 2026-05-13, overlapping `v0.15.10`/`v0.15.11` releases. The relevant +diff between `v0.15.9` and `v0.15.10` touched subagent runtime, +non-interactive execution, `GeminiChat`, and compression code heavily, so this +range is a reasonable first bisect window. + +## Notes + +- The first code-navigation prompt allowed open-ended exploration and hit + `maxSessionTurns`; the successful rows above use a constrained command list. +- The first synthetic-diff attempt used a relative bundle path from inside the + temporary repositories; those failed immediately and are excluded from the + tables. The successful rows use the absolute local bundle path. +- Raw JSONL streams are not committed because they contain prompts, tool + commands, and tool output. The report only includes aggregate diagnostics. diff --git a/docs/e2e-tests/2026-05-21-qwen-0.15.11-default-heap-oom-stress-report.md b/docs/e2e-tests/2026-05-21-qwen-0.15.11-default-heap-oom-stress-report.md new file mode 100644 index 00000000000..e9579dee1b8 --- /dev/null +++ b/docs/e2e-tests/2026-05-21-qwen-0.15.11-default-heap-oom-stress-report.md @@ -0,0 +1,338 @@ +# Qwen Code 0.15.11 默认 Heap OOM 压测报告 + +日期：2026-05-21 + +## 测试范围 + +本报告记录了针对 Qwen Code `0.15.11` 最新本地构建的一轮默认 heap 压测。 +这轮测试的目标是验证：在不人为降低内存上限的情况下，当前代码是否还能复现 +issue 中提到的长会话 OOM，以及在更极端的大输出场景下还有没有新的风险。 + +本轮覆盖三个模型： + +- `pai/glm-5` +- `qwen3.6-plus` +- `DeepSeek/deepseek-v4-pro` + +测试分为两部分： + +1. 真实长任务、多 agent 并发 review 循环。 +2. amplified foreground stdout 压测，即用大规模前台 shell stdout 放大 + tool-output 路径压力。 + +## 测试环境 + +| 项目 | 值 | +| --------------------------- | --------------------------------------------- | +| 分支 | `codex/memory-investigation-draft-pr` | +| Commit | `c161e0aa4` | +| CLI | 本地 `dist/cli.js` | +| CLI 版本 | `0.15.11` | +| Node 默认 heap limit | `4144 MiB` | +| `NODE_OPTIONS` | 未设置 | +| 显式 `--max-old-space-size` | 未设置 | +| runner `ulimit` | runner 未设置 | +| 配置模式 | 临时复制 `~/.qwen`，并隔离 `QWEN_RUNTIME_DIR` | +| MCP / 正常配置 | 尽量按复制后的正常配置加载 | + +注意：这里的 CLI 版本显示为 `0.15.11`，是因为 package version 尚未 bump。 +实际测试对象是 commit `c161e0aa4` 下本地编译出的 `dist/cli.js`，不是 PATH +里的全局 `qwen` 可执行文件。 + +本轮没有修改全局 Qwen 配置。原始 runtime artifacts 在： + +- `.qwen/runtime-bench/2026-05-20T13-51-58-731Z-oom-stress` +- `.qwen/runtime-bench/2026-05-20T15-20-37-790Z-oom-amplified` + +注意：本轮里 `env-center` MCP server 启动失败，但其他内置工具和部分 +MCP/child process 仍然加载。因此这些结果代表当前本地环境，不是完全 stripped +的 `--bare` 环境。 + +## 核心结论 + +最新本地构建在 issue 最关心的“长会话 V8 heap OOM”路径上表现明显更好。 +基于这轮默认 heap、多模型、多 agent、长任务压测，可以认为本 PR 对此前遇到的 +long-session heap OOM 问题已经基本解决，至少在当前复现维度下已经不能再复现 +原始 heap OOM。 + +真实长任务、多 agent 并发测试一共执行了： + +- 23 个 worker turn +- 约 `719,094,118` reported total tokens +- 77 次 agent tool call +- 856 次总 tool call + +这部分没有复现任何传统 V8 heap OOM 特征： + +- `JavaScript heap out of memory` +- `Reached heap limit` +- `Ineffective mark-compacts near heap limit` +- `Allocation failed` + +真实长任务阶段最高 process-tree RSS 为 `874.7 MiB`，最高 root-process RSS 为 +`219.1 MiB`。这说明在默认 heap 下，当前代码没有轻易复现原 issue 中那种长任务 +跑挂的 heap OOM。 + +第二阶段 amplified stdout 压测更激进。它一共执行了 18 个 payload attempt， +覆盖三个模型和 `128 MiB` 到 `2048 MiB` 的 foreground stdout payload。 + +结果是： + +- 三个模型都成功跑过 `1536 MiB` payload。 +- 最高成功 process-tree RSS 是 `5964.7 MiB`，出现在 `qwen3.6-plus` + 的 `1536 MiB` payload。 +- 到 `2048 MiB` payload 时，出现了一个新的 extreme large-output failure。 + +`2048 MiB` 的结果： + +- `pai/glm-5`：`exit=1`，stdout 为空，没有标准 OOM 文本。 +- `qwen3.6-plus`：`exit=1`，stdout 为空，没有标准 OOM 文本。 +- `DeepSeek/deepseek-v4-pro`：出现 V8 fatal： + `Check failed: i::kMaxInt >= len`，栈在 + `v8::String::NewFromOneByte` / `node::StringBytes::Encode` / + `DecodeUTF8`。 + +这个新问题不是原 issue 中的传统 long-session heap OOM。它更像是 +multi-GiB foreground stdout 被解码/构造成 JS string 时触发的 V8 字符串长度 +限制或大输出处理问题。建议作为 large-output follow-up 跟踪，而不是把它当作 +当前长会话 heap-pressure 修复失败。 + +## Phase 1：真实长任务、多 Agent 并发压测 + +### 测试形态 + +每个模型 worker 都复用同一个 session，不断 `--resume`。每一轮要求 Qwen Code： + +- 进行只读代码审查和代码搜索； +- 在同一轮中并发启动至少 4 个 `agent` tool call； +- 重点检查 chat history、compaction、subagent runtime、non-interactive + streaming、provider adapters 等 memory 相关区域； +- 保留足够详细的最终回答，让 session history 自然增长。 + +runner 每秒采样 process-tree RSS，没有设置任何额外 heap cap。 + +这部分在观察到内存比较稳定后用 `SIGTERM` 主动停止，以便切换到第二阶段的 +amplified stdout 压测。因此表里的 `SIGTERM` 不是 OOM。 + +### 汇总结果 + +| Model | Worker turns | Total tokens | Agent calls | Tool calls | Peak tree RSS | Peak root RSS | Last exit | OOM | +| -------------------------- | -----------: | --------------: | ----------: | ---------: | ------------: | ------------: | --------- | ------ | +| `pai/glm-5` | 9 | 444,614,704 | 36 | 362 | 874.7 MiB | 217.4 MiB | `SIGTERM` | no | +| `qwen3.6-plus` | 7 | 101,425,927 | 17 | 346 | 862.7 MiB | 219.1 MiB | `SIGTERM` | no | +| `DeepSeek/deepseek-v4-pro` | 7 | 173,053,487 | 24 | 148 | 864.5 MiB | 213.8 MiB | `SIGTERM` | no | +| **Total / max** | **23** | **719,094,118** | **77** | **856** | **874.7 MiB** | **219.1 MiB** | - | **no** | + +### 分轮结果 + +| Model | Turn | Exit | Timed out | OOM | Peak tree RSS | Peak root RSS | Total tokens | Agent calls | Tool calls | +| -------------------------- | ---: | --------- | --------- | --- | ------------: | ------------: | -----------: | ----------: | ---------: | +| `DeepSeek/deepseek-v4-pro` | 1 | `0` | no | no | 709.1 MiB | 167.3 MiB | 5,565,147 | 4 | 37 | +| `DeepSeek/deepseek-v4-pro` | 2 | `0` | no | no | 674.5 MiB | 118.8 MiB | 13,989,721 | 4 | 29 | +| `DeepSeek/deepseek-v4-pro` | 3 | `0` | no | no | 734.1 MiB | 148.0 MiB | 22,621,542 | 4 | 24 | +| `DeepSeek/deepseek-v4-pro` | 4 | `0` | no | no | 771.1 MiB | 107.5 MiB | 33,470,249 | 4 | 22 | +| `DeepSeek/deepseek-v4-pro` | 5 | `0` | no | no | 864.5 MiB | 212.9 MiB | 43,540,313 | 4 | 19 | +| `DeepSeek/deepseek-v4-pro` | 6 | `0` | no | no | 807.6 MiB | 167.9 MiB | 53,866,515 | 4 | 17 | +| `DeepSeek/deepseek-v4-pro` | 7 | `SIGTERM` | no | no | 785.1 MiB | 213.8 MiB | n/a | n/a | n/a | +| `pai/glm-5` | 1 | `SIGTERM` | yes | no | 742.8 MiB | 170.5 MiB | 17,071,519 | 4 | 142 | +| `pai/glm-5` | 2 | `0` | no | no | 874.7 MiB | 217.4 MiB | 27,438,727 | 4 | 60 | +| `pai/glm-5` | 3 | `0` | no | no | 699.7 MiB | 102.1 MiB | 35,627,222 | 4 | 38 | +| `pai/glm-5` | 4 | `0` | no | no | 796.0 MiB | 194.0 MiB | 44,130,101 | 4 | 23 | +| `pai/glm-5` | 5 | `0` | no | no | 743.4 MiB | 152.1 MiB | 50,465,979 | 4 | 26 | +| `pai/glm-5` | 6 | `0` | no | no | 714.9 MiB | 125.2 MiB | 56,357,372 | 4 | 18 | +| `pai/glm-5` | 7 | `0` | no | no | 694.5 MiB | 96.6 MiB | 64,047,037 | 4 | 20 | +| `pai/glm-5` | 8 | `0` | no | no | 756.0 MiB | 136.8 MiB | 71,891,505 | 4 | 15 | +| `pai/glm-5` | 9 | `SIGTERM` | no | no | 755.7 MiB | 157.3 MiB | 77,585,242 | 4 | 20 | +| `qwen3.6-plus` | 1 | `0` | no | no | 735.1 MiB | 153.1 MiB | 3,890,508 | 4 | 83 | +| `qwen3.6-plus` | 2 | `0` | no | no | 702.4 MiB | 142.5 MiB | 4,300,186 | 1 | 9 | +| `qwen3.6-plus` | 3 | `0` | no | no | 862.7 MiB | 219.1 MiB | 8,635,953 | 4 | 88 | +| `qwen3.6-plus` | 4 | `SIGTERM` | yes | no | 685.8 MiB | 106.5 MiB | n/a | n/a | n/a | +| `qwen3.6-plus` | 5 | `0` | no | no | 610.5 MiB | 93.1 MiB | 40,191,337 | 4 | 87 | +| `qwen3.6-plus` | 6 | `0` | no | no | 723.6 MiB | 121.9 MiB | 44,407,943 | 4 | 79 | +| `qwen3.6-plus` | 7 | `SIGTERM` | no | no | 810.4 MiB | 116.0 MiB | n/a | n/a | n/a | + +### Phase 1 解读 + +这是本轮里最能说明原始 long-session OOM 已明显改善的数据。 + +这组测试比 5 月 18 日的小 PR review / code navigation 更重：它包含更多 +`--resume`、更多 subagent activity、更大的 reported token 量和更多 tool call。 +但 process-tree RSS 始终低于 `0.9 GiB`，也没有出现传统 V8 heap OOM。 + +这不能证明所有用户 OOM 都不可能再发生，但至少说明当前构建在默认 heap 下， +已经无法轻易复现 issue 中那类长会话 heap-pressure OOM。 + +## Phase 2：Amplified Foreground Stdout 压测 + +### 测试形态 + +第二阶段故意放大 shell-output 路径压力。每个模型、每个 payload size 都要求 +parent session 和并发 agents 运行前台 shell 命令，输出大量 `x` 到 stdout： + +```bash +node -e "const chunk='x'.repeat(1024*1024); for (let i=0; i= len. +... +v8::String::NewFromOneByte +node::StringBytes::Encode +node::encoding_binding::BindingData::DecodeUTF8 +``` + +触发条件： + +- Model：`DeepSeek/deepseek-v4-pro` +- Payload：`2048 MiB` +- Peak tree RSS：`4660.4 MiB` +- Largest process RSS：`4527.6 MiB` +- runner 记录 exit：`SIGTERM`，因为 fatal 输出已经捕获后，剩余子进程仍在高 CPU + 空转，被手动终止。 + +`pai/glm-5` 和 `qwen3.6-plus` 在 `2048 MiB` 也失败，表现为 stdout 为空、 +exit code `1`，但 stderr 没有捕获到 V8 fatal stack。 + +### 严重程度 + +这是一个真实的 robustness 问题，但触发条件是 multi-GiB foreground stdout， +不是正常代码审查任务。它也不能证明当前 long-session heap-pressure 修复失败。 + +### 是否是本 PR 引入？ + +本轮没有证据表明 `2048 MiB` stdout failure 是当前 memory PR 引入的回归。 + +原因： + +- 失败路径是 foreground shell stdout decode / string construction。 +- 原 issue 路径是 long-session history、compaction、clone pressure。 +- 本轮没有做同 payload 的 pre-PR baseline，因此不能归因成 regression。 +- 该 failure 只在刻意极端的 `2048 MiB` payload 出现；`128 MiB` 到 + `1536 MiB` 都能完成。 + +建议把它作为 dedicated large-output follow-up：更早 stream / spool / hard-cap +foreground shell output，避免在内存里构造 multi-GiB JS string。除非当前 PR 的目标 +明确包含“任意 multi-GiB 前台 stdout 都必须可处理”，否则不建议把它作为当前 PR 的 +blocker。 + +## 结论 + +1. 最新本地 `0.15.11` 构建在 issue 报告的 long-session heap OOM 方向上明显更好。 + 基于当前默认 heap 压测结果，可以认为本 PR 已经基本解决此前遇到的 + long-session heap OOM 复现路径。 + +2. 在默认 Node heap 下，真实长任务 + 多 agent review loop 没有在 + `pai/glm-5`、`qwen3.6-plus`、`DeepSeek/deepseek-v4-pro` 三个模型上复现传统 + V8 heap OOM。 + +3. synthetic foreground stdout 压测仍能把 process-tree RSS 推得很高。当前构建在 + 三模型上都撑过了 `1536 MiB` payload，最高成功 tree RSS 是 `5964.7 MiB`。 + +4. 仍然存在一个独立的极端 large-output 问题：`2048 MiB` stdout 附近，Qwen Code + 可能在输出 JSON 结果前失败；DeepSeek case 捕获到了 V8 string-length fatal。 + +5. 这个新发现重要，但更像是后续 large-output robustness 问题，不应直接作为 + long-session heap-pressure mitigation 的 blocker。 + +## 建议发到 PR 的评论摘要 + +建议 PR 评论里只放精简摘要，完整数据放本文档： + +```markdown +I reran default-heap stress tests on the latest local build with +`pai/glm-5`, `qwen3.6-plus`, and `DeepSeek/deepseek-v4-pro`. + +No `NODE_OPTIONS`, `--max-old-space-size`, or runner `ulimit` was used. The +local Node heap limit was about 4144 MiB. + +Results: + +- Realistic long-session + multi-agent review loop: 23 worker turns, + ~719M reported total tokens, 77 agent calls, 856 total tool calls. + No traditional V8 heap OOM was reproduced. Peak process-tree RSS was + 874.7 MiB; peak root RSS was 219.1 MiB. +- Amplified stdout stress: 18 payload attempts across 128 MiB -> 2048 MiB. + All three models completed through 1536 MiB payloads without traditional + heap OOM. Highest successful process-tree RSS was 5964.7 MiB. +- At 2048 MiB foreground stdout, an extreme large-output failure remains. + DeepSeek captured a V8 fatal `Check failed: i::kMaxInt >= len` stack in + `String::NewFromOneByte` / `StringBytes::Encode` / `DecodeUTF8`. + +Conclusion: this PR appears to have effectively addressed the previously +observed long-session heap OOM reproduction path under default heap. The +2048 MiB stdout failure is a separate large-output/string-limit robustness issue +and should be tracked as a follow-up rather than treated as the same +long-session heap OOM regression. +``` diff --git a/docs/e2e-tests/worktree-phase-c.md b/docs/e2e-tests/worktree-phase-c.md new file mode 100644 index 00000000000..8f7ae8d6c80 --- /dev/null +++ b/docs/e2e-tests/worktree-phase-c.md @@ -0,0 +1,594 @@ +# Worktree Phase C E2E Test Plan + +## Scope + +End-to-end verification of Phase C features against the local build at +`/Users/mochi/code/qwen-code/.claude/worktrees/romantic-burnell-b6e48c/dist/cli.js`. + +Phase C delivers: + +- **Task 1, 3, 4** — `WorktreeSession` sidecar JSON file at + `~/.qwen/tmp//chats/.worktree.json` +- **Task 2** — `core.hooksPath` configured inside new worktrees +- **Task 5–6** — `useWorktreeSession` hook, `UIState.activeWorktree`, Footer + worktree indicator, `StatusLineCommandInput.worktree` field +- **Task 7** — `--resume` injects an INFO history item when active worktree + still exists; cleans up stale sidecar otherwise +- **Task 8** — `WorktreeExitDialog` with dirty-state inspection, intercepts + second Ctrl+C in active worktree + +## Binaries + +- **Local build**: `node /Users/mochi/code/qwen-code/.claude/worktrees/romantic-burnell-b6e48c/dist/cli.js` +- **Baseline (for pre-impl comparison if needed)**: globally installed `qwen` + +## Test environment template + +Each group runs in its own temp git repo and tmux session: + +```bash +TEST_DIR=$(mktemp -d -t qwen-wt-phc-XXXXXX) +TEST_DIR=$(cd "$TEST_DIR" && pwd -P) # resolve symlinks (macOS /var → /private/var) +cd "$TEST_DIR" +git init -q -b main +git config user.email t@e.com +git config user.name t +git config commit.gpgsign false +echo "hello" > README.md +git add README.md +git commit -q -m "initial" --no-verify +``` + +`QWEN=/Users/mochi/code/qwen-code/.claude/worktrees/romantic-burnell-b6e48c/dist/cli.js` + +--- + +## Group A: WorktreeSession sidecar (headless) + +**Mode:** headless, `--approval-mode yolo`, `--output-format json` + +### A1: enter_worktree writes sidecar with all fields + +**Steps:** + +```bash +SESSION=$(node $QWEN "use the enter_worktree tool with name='a1-test' to create a worktree" \ + --approval-mode yolo --output-format json 2>/dev/null \ + | jq -r '.[] | select(.type=="system") | .session_id' | head -1) + +PROJECT_ID=$(node -e "console.log(process.argv[1].replace(/[^a-zA-Z0-9]/g,'-'))" "$TEST_DIR") +SIDECAR=~/.qwen/projects/$PROJECT_ID/chats/$SESSION.worktree.json + +# Verify all fields present +cat "$SIDECAR" | jq '.slug, .worktreePath, .worktreeBranch, .originalCwd, .originalBranch, .originalHeadCommit' +``` + +**Expected:** + +- `slug` = "a1-test" +- `worktreePath` ends with `.qwen/worktrees/a1-test` +- `worktreeBranch` = "worktree-a1-test" +- `originalCwd` = `$TEST_DIR` (resolved) +- `originalBranch` = "main" +- `originalHeadCommit` matches `[0-9a-f]{40}` + +### A2: exit_worktree (keep) clears sidecar + +**Steps:** + +```bash +SESSION=$(node $QWEN "create a worktree named 'a2-test' using enter_worktree, then immediately exit it with action='keep' using exit_worktree" \ + --approval-mode yolo --output-format json 2>/dev/null \ + | jq -r '.[] | select(.type=="system") | .session_id' | head -1) + +SIDECAR=~/.qwen/projects/$PROJECT_ID/chats/$SESSION.worktree.json +test ! -f "$SIDECAR" && echo "PASS: sidecar removed" || echo "FAIL: sidecar still exists" +``` + +**Expected:** sidecar file does not exist after the exit_worktree call. + +### A3: exit_worktree (remove) clears sidecar + +**Steps:** + +```bash +SESSION=$(node $QWEN "create a worktree named 'a3-test' using enter_worktree, then immediately exit it with action='remove' and discard_changes=true using exit_worktree" \ + --approval-mode yolo --output-format json 2>/dev/null \ + | jq -r '.[] | select(.type=="system") | .session_id' | head -1) + +SIDECAR=~/.qwen/projects/$PROJECT_ID/chats/$SESSION.worktree.json +test ! -f "$SIDECAR" && echo "PASS: sidecar removed" || echo "FAIL: sidecar still exists" +# Also verify the worktree dir is gone +test ! -d "$TEST_DIR/.qwen/worktrees/a3-test" && echo "PASS: worktree dir removed" +``` + +**Expected:** both the sidecar AND the worktree directory are gone. + +--- + +## Group B: hooksPath configuration (headless) + +### B1: Without `.husky/`, hooksPath = `/.git/hooks` + +**Steps:** + +```bash +node $QWEN "use enter_worktree with name='b1-test' to create a worktree" \ + --approval-mode yolo --output-format json 2>/dev/null > /dev/null + +HOOKS_PATH=$(git -C "$TEST_DIR/.qwen/worktrees/b1-test" config --local core.hooksPath) +echo "Got hooksPath: $HOOKS_PATH" +test "$HOOKS_PATH" = "$TEST_DIR/.git/hooks" && echo "PASS" || echo "FAIL" +``` + +**Expected:** `$TEST_DIR/.git/hooks` + +### B2: With `.husky/`, hooksPath = `/.husky` + +**Steps:** + +```bash +mkdir -p "$TEST_DIR/.husky" +echo '#!/bin/sh' > "$TEST_DIR/.husky/pre-commit" +chmod +x "$TEST_DIR/.husky/pre-commit" + +node $QWEN "use enter_worktree with name='b2-test' to create a worktree" \ + --approval-mode yolo --output-format json 2>/dev/null > /dev/null + +HOOKS_PATH=$(git -C "$TEST_DIR/.qwen/worktrees/b2-test" config --local core.hooksPath) +test "$HOOKS_PATH" = "$TEST_DIR/.husky" && echo "PASS" || echo "FAIL got=$HOOKS_PATH" +``` + +**Expected:** `$TEST_DIR/.husky` + +### B3: Hooks in main repo actually fire from inside worktree + +**Steps:** + +```bash +# Set up a hook that writes a marker file +mkdir -p "$TEST_DIR/.git/hooks" +cat > "$TEST_DIR/.git/hooks/pre-commit" <<'EOF' +#!/bin/sh +echo "hook-fired" > /tmp/qwen-wt-hook-marker +EOF +chmod +x "$TEST_DIR/.git/hooks/pre-commit" + +node $QWEN "use enter_worktree with name='b3-test' to create a worktree" \ + --approval-mode yolo --output-format json 2>/dev/null > /dev/null + +# Commit something inside the worktree +WT="$TEST_DIR/.qwen/worktrees/b3-test" +echo "x" > "$WT/file.txt" +git -C "$WT" add file.txt +rm -f /tmp/qwen-wt-hook-marker +git -C "$WT" commit -m "trigger hook" 2>&1 +test -f /tmp/qwen-wt-hook-marker && echo "PASS: hook fired" || echo "FAIL: hook did not fire" +rm -f /tmp/qwen-wt-hook-marker +``` + +**Expected:** `/tmp/qwen-wt-hook-marker` exists after the commit. + +--- + +## Group C: --resume worktree restoration (headless) + +### C1: --resume injects worktree context when sidecar present and dir alive + +**Steps:** + +```bash +# Create initial session with worktree +INIT_OUT=$(node $QWEN "use enter_worktree with name='c1-test' to create a worktree" \ + --approval-mode yolo --output-format json 2>/dev/null) +SESSION=$(echo "$INIT_OUT" | jq -r '.[] | select(.type=="system") | .session_id' | head -1) + +# Resume the session and ask "what's my context?" +RESUMED=$(node $QWEN --resume "$SESSION" "say SIDECAR-CONFIRM" \ + --approval-mode yolo --output-format json 2>/dev/null) + +# Look for the injected INFO message text in the conversation +echo "$RESUMED" | grep -q "Resumed.*Active worktree.*c1-test" && echo "PASS" || echo "FAIL: no context injection" +``` + +**Expected:** the JSON stream contains an INFO message referencing `c1-test`. + +### C2: --resume cleans up stale sidecar when worktree dir is gone + +**Steps:** + +```bash +INIT_OUT=$(node $QWEN "use enter_worktree with name='c2-test' to create a worktree" \ + --approval-mode yolo --output-format json 2>/dev/null) +SESSION=$(echo "$INIT_OUT" | jq -r '.[] | select(.type=="system") | .session_id' | head -1) +SIDECAR=~/.qwen/projects/$PROJECT_ID/chats/$SESSION.worktree.json + +# Delete the worktree directory out-of-band +rm -rf "$TEST_DIR/.qwen/worktrees/c2-test" +test -f "$SIDECAR" || { echo "SKIP: sidecar was already gone"; exit 0; } + +# Resume — should clean up the stale sidecar +node $QWEN --resume "$SESSION" "hello" --approval-mode yolo --output-format json 2>/dev/null > /dev/null +test ! -f "$SIDECAR" && echo "PASS: stale sidecar cleaned" || echo "FAIL: stale sidecar still present" +``` + +**Expected:** sidecar file is removed. + +--- + +## Group D: Footer worktree indicator (interactive tmux) + +### D1: Footer shows worktree indicator after enter_worktree + +**Steps:** + +```bash +tmux new-session -d -s wt-d1 -x 200 -y 50 \ + "cd $TEST_DIR && node $QWEN --approval-mode yolo" +sleep 3 + +tmux send-keys -t wt-d1 "use enter_worktree with name='d1-test'" +sleep 0.5 +tmux send-keys -t wt-d1 Enter + +for i in $(seq 1 30); do + sleep 2 + tmux capture-pane -t wt-d1 -p | grep -q "Type your message" && break +done + +# Capture and look for the worktree indicator line in Footer area +tmux capture-pane -t wt-d1 -p -S -100 > /tmp/wt-d1.out +grep -E "⎇.*worktree-d1-test.*\(d1-test\)" /tmp/wt-d1.out && echo "PASS" || \ + { echo "FAIL — captured output:"; cat /tmp/wt-d1.out; } +tmux kill-session -t wt-d1 +``` + +**Expected:** Footer contains a line like `⎇ worktree-d1-test (d1-test)`. + +### D2: Footer indicator disappears after exit_worktree (keep) + +**Steps:** + +```bash +tmux new-session -d -s wt-d2 -x 200 -y 50 \ + "cd $TEST_DIR && node $QWEN --approval-mode yolo" +sleep 3 + +tmux send-keys -t wt-d2 "use enter_worktree with name='d2-test'" +sleep 0.5 +tmux send-keys -t wt-d2 Enter +for i in $(seq 1 30); do sleep 2; tmux capture-pane -t wt-d2 -p | grep -q "Type your message" && break; done + +# Verify indicator showed +tmux capture-pane -t wt-d2 -p -S -100 | grep -q "⎇.*d2-test" || { echo "FAIL: indicator missing before exit"; tmux kill-session -t wt-d2; exit 1; } + +# Exit the worktree (keep) +tmux send-keys -t wt-d2 "use exit_worktree with name='d2-test' action='keep'" +sleep 0.5 +tmux send-keys -t wt-d2 Enter +for i in $(seq 1 30); do sleep 2; tmux capture-pane -t wt-d2 -p | grep -q "Kept worktree" && break; done + +sleep 2 # give Footer a tick to refresh after sidecar removal +tmux capture-pane -t wt-d2 -p -S -100 > /tmp/wt-d2-after.out +# After exit, the indicator should be gone from the bottom panel area +tail -5 /tmp/wt-d2-after.out | grep -q "⎇.*d2-test" && \ + echo "FAIL: indicator still showing" || echo "PASS" +tmux kill-session -t wt-d2 +``` + +**Expected:** worktree indicator disappears from Footer within ~2s of `exit_worktree`. + +--- + +## Group E: WorktreeExitDialog (interactive tmux) + +### E1: Second Ctrl+C in worktree shows dialog instead of quitting + +**Steps:** + +```bash +tmux new-session -d -s wt-e1 -x 200 -y 50 \ + "cd $TEST_DIR && node $QWEN --approval-mode yolo" +sleep 3 + +tmux send-keys -t wt-e1 "use enter_worktree with name='e1-test'" +sleep 0.5 +tmux send-keys -t wt-e1 Enter +for i in $(seq 1 30); do sleep 2; tmux capture-pane -t wt-e1 -p | grep -q "Type your message" && break; done + +# First Ctrl+C (cleanup; should show "Press Ctrl+C again to exit") +tmux send-keys -t wt-e1 C-c +sleep 0.3 +tmux capture-pane -t wt-e1 -p | grep -q "Press Ctrl+C again" || \ + { echo "FAIL: first Ctrl+C didn't show warning"; tmux kill-session -t wt-e1; exit 1; } + +# Second Ctrl+C — should show the WorktreeExitDialog, NOT quit +tmux send-keys -t wt-e1 C-c +sleep 2 + +# Verify the dialog rendered +tmux capture-pane -t wt-e1 -p -S -50 > /tmp/wt-e1.out +grep -q "Active worktree.*e1-test" /tmp/wt-e1.out && \ + grep -q "Keep worktree" /tmp/wt-e1.out && \ + grep -q "Remove worktree" /tmp/wt-e1.out && \ + echo "PASS" || { echo "FAIL — captured:"; cat /tmp/wt-e1.out; } +tmux kill-session -t wt-e1 +``` + +**Expected:** dialog shows three options (Keep / Remove / Cancel) and process is still alive. + +### E2: Dialog shows dirty-state counts (commits + files) + +**Steps:** + +```bash +tmux new-session -d -s wt-e2 -x 200 -y 50 \ + "cd $TEST_DIR && node $QWEN --approval-mode yolo" +sleep 3 + +tmux send-keys -t wt-e2 "use enter_worktree with name='e2-test'" +sleep 0.5 +tmux send-keys -t wt-e2 Enter +for i in $(seq 1 30); do sleep 2; tmux capture-pane -t wt-e2 -p | grep -q "Type your message" && break; done + +# Make the worktree dirty: 1 new commit + 1 uncommitted file +WT="$TEST_DIR/.qwen/worktrees/e2-test" +echo "new" > "$WT/new.txt" +git -C "$WT" add new.txt +git -C "$WT" commit -q -m "test commit" --no-verify +echo "dirty" > "$WT/uncommitted.txt" + +# Trigger exit dialog via Ctrl+C double-press +tmux send-keys -t wt-e2 C-c +sleep 0.3 +tmux send-keys -t wt-e2 C-c +sleep 3 # allow time for git status / rev-list + +tmux capture-pane -t wt-e2 -p -S -50 > /tmp/wt-e2.out +grep -qE "new commit|uncommitted file" /tmp/wt-e2.out && echo "PASS" || \ + { echo "FAIL — captured:"; cat /tmp/wt-e2.out; } +tmux kill-session -t wt-e2 +``` + +**Expected:** dialog body contains both "X new commit(s)" and "Y uncommitted file(s)". + +### E3: Cancel option dismisses dialog without exiting + +**Steps:** + +```bash +tmux new-session -d -s wt-e3 -x 200 -y 50 \ + "cd $TEST_DIR && node $QWEN --approval-mode yolo" +sleep 3 + +tmux send-keys -t wt-e3 "use enter_worktree with name='e3-test'" +sleep 0.5 +tmux send-keys -t wt-e3 Enter +for i in $(seq 1 30); do sleep 2; tmux capture-pane -t wt-e3 -p | grep -q "Type your message" && break; done + +# Trigger dialog +tmux send-keys -t wt-e3 C-c +sleep 0.3 +tmux send-keys -t wt-e3 C-c +sleep 3 + +# Navigate to Cancel (DOWN DOWN) and press Enter +tmux send-keys -t wt-e3 Down +sleep 0.2 +tmux send-keys -t wt-e3 Down +sleep 0.2 +tmux send-keys -t wt-e3 Enter +sleep 2 + +# Dialog should be gone; input prompt should be back +tmux capture-pane -t wt-e3 -p | grep -q "Type your message" && echo "PASS" || \ + { echo "FAIL — captured:"; tmux capture-pane -t wt-e3 -p; } + +# Verify the worktree was NOT removed +test -d "$TEST_DIR/.qwen/worktrees/e3-test" && echo "worktree intact" || echo "FAIL: worktree gone" +tmux kill-session -t wt-e3 +``` + +**Expected:** dialog closes, input prompt returns, worktree directory still exists. + +### E4: Keep option exits session but preserves worktree + +**Steps:** + +```bash +tmux new-session -d -s wt-e4 -x 200 -y 50 \ + "cd $TEST_DIR && node $QWEN --approval-mode yolo" +sleep 3 + +tmux send-keys -t wt-e4 "use enter_worktree with name='e4-test'" +sleep 0.5 +tmux send-keys -t wt-e4 Enter +for i in $(seq 1 30); do sleep 2; tmux capture-pane -t wt-e4 -p | grep -q "Type your message" && break; done + +# Trigger dialog and pick Keep (first option, already selected) +tmux send-keys -t wt-e4 C-c +sleep 0.3 +tmux send-keys -t wt-e4 C-c +sleep 3 +tmux send-keys -t wt-e4 Enter + +# Wait for process to exit +for i in $(seq 1 20); do + sleep 1 + tmux has-session -t wt-e4 2>/dev/null || break + tmux capture-pane -t wt-e4 -p | grep -q "\$ " && break # shell prompt back +done + +# Worktree directory should still exist +test -d "$TEST_DIR/.qwen/worktrees/e4-test" && echo "PASS: worktree preserved" || \ + echo "FAIL: worktree was removed" +tmux kill-session -t wt-e4 2>/dev/null || true +``` + +**Expected:** process exits, worktree directory remains on disk. + +### E5: Remove option exits session and deletes worktree + +**Steps:** + +```bash +tmux new-session -d -s wt-e5 -x 200 -y 50 \ + "cd $TEST_DIR && node $QWEN --approval-mode yolo" +sleep 3 + +tmux send-keys -t wt-e5 "use enter_worktree with name='e5-test'" +sleep 0.5 +tmux send-keys -t wt-e5 Enter +for i in $(seq 1 30); do sleep 2; tmux capture-pane -t wt-e5 -p | grep -q "Type your message" && break; done + +# Trigger dialog and pick Remove (DOWN, Enter) +tmux send-keys -t wt-e5 C-c +sleep 0.3 +tmux send-keys -t wt-e5 C-c +sleep 3 +tmux send-keys -t wt-e5 Down +sleep 0.2 +tmux send-keys -t wt-e5 Enter + +# Wait for exit +for i in $(seq 1 20); do + sleep 1 + tmux has-session -t wt-e5 2>/dev/null || break + tmux capture-pane -t wt-e5 -p | grep -q "\$ " && break +done + +# Worktree directory should be GONE +test ! -d "$TEST_DIR/.qwen/worktrees/e5-test" && echo "PASS: worktree removed" || \ + echo "FAIL: worktree still on disk" +# Branch should also be deleted +git -C "$TEST_DIR" branch --list | grep -q "worktree-e5-test" && \ + echo "FAIL: branch still present" || echo "PASS: branch removed" +tmux kill-session -t wt-e5 2>/dev/null || true +``` + +**Expected:** process exits, worktree directory deleted, branch `worktree-e5-test` deleted. + +--- + +## Group F: Real-user workflow simulation (interactive tmux) + +### F1: Full enter → edit → commit → resume → exit (keep) flow + +**Steps:** + +```bash +tmux new-session -d -s wt-f1 -x 200 -y 50 \ + "cd $TEST_DIR && node $QWEN --approval-mode yolo" +sleep 3 + +# Step 1: enter worktree +tmux send-keys -t wt-f1 "use enter_worktree with name='f1-feature' to create a worktree" +sleep 0.5 +tmux send-keys -t wt-f1 Enter +for i in $(seq 1 30); do sleep 2; tmux capture-pane -t wt-f1 -p | grep -q "Type your message" && break; done + +# Step 2: read the absolute worktree path so the model knows where to write +WT="$TEST_DIR/.qwen/worktrees/f1-feature" +tmux send-keys -t wt-f1 "write the file $WT/hello.txt with content 'hi from worktree'" +sleep 0.5 +tmux send-keys -t wt-f1 Enter +for i in $(seq 1 60); do sleep 2; tmux capture-pane -t wt-f1 -p | grep -q "Type your message" && break; done + +# Verify the file was actually written INSIDE the worktree +test -f "$WT/hello.txt" && grep -q "hi from worktree" "$WT/hello.txt" && \ + echo "PASS: file written inside worktree" || echo "FAIL: file not in worktree" + +# Step 3: Exit with keep via the tool +tmux send-keys -t wt-f1 "use exit_worktree with name='f1-feature' action='keep'" +sleep 0.5 +tmux send-keys -t wt-f1 Enter +for i in $(seq 1 30); do sleep 2; tmux capture-pane -t wt-f1 -p | grep -q "Kept worktree" && break; done + +# Step 4: Verify worktree still on disk after exit +test -d "$WT" && echo "PASS: worktree kept" || echo "FAIL: worktree removed" +test -f "$WT/hello.txt" && echo "PASS: file persists" || echo "FAIL" + +tmux kill-session -t wt-f1 +``` + +**Expected:** + +- File written to worktree directory (not main repo) +- After exit `keep`, both the worktree directory and the file remain + +### F2: Custom statusline receives `worktree` payload + +**Steps:** + +```bash +# Create a statusline script that prints the JSON it receives via stdin +SETTINGS_DIR=~/.qwen +SETTINGS_FILE=$SETTINGS_DIR/settings.json +cp -f "$SETTINGS_FILE" /tmp/qwen-settings-backup.json 2>/dev/null || true +mkdir -p "$SETTINGS_DIR" +SL_SCRIPT=/tmp/qwen-wt-statusline.sh +cat > $SL_SCRIPT <<'EOF' +#!/bin/sh +INPUT=$(cat) +echo "$INPUT" > /tmp/qwen-wt-statusline-input.json +WT_NAME=$(echo "$INPUT" | jq -r '.worktree.name // "no-worktree"') +echo "WT=$WT_NAME" +EOF +chmod +x $SL_SCRIPT + +cat > "$SETTINGS_FILE" <