stripRawStage rescans all history text every turn — a fourth O(history) sync path beyond #4528/#5744

环境


billion-context	`package.json` 写 `0.1.208`，dist 来自 `0.0.8277-pr.5755.01abae9` 构建（`dist/index.js` = 6,004,361 字节）
Node	v24.21.0
OS	Windows 11（本机 CPU 会在「安静模式 / 野兽模式」间切换 = 有降频）
库	`index.db` = 464 MiB，sessions 目录 971 MiB
会话	12,898 条消息，`inbound=24.9MiB` / 轮

症状

每轮本地耗时（request: … local= 与分段日志），连续十二轮，17:01–17:06：

local          中位 1454ms   区间 1177–2471
读 body+预处理  中位  866ms   区间  692–1110   ← 60%
processTurn    中位  438ms   区间  370–1493   ← 30%
收尾            中位  117ms   区间  113–156    ← 8%

其中一段日志：

17:09:17  host-json-parse=43ms consumers=2 inbound=19617485B (#5792)
17:09:17  request: 12898 msgs, inbound=24.9MiB, outbound=653.9KiB, local=1236ms
17:09:17  [storage] slow-ingest: path=delta took=588ms, 46.2 MiB WAL (#5744)

**关键观察：JSON.parse 24.9 MiB 只要 43ms。**那 866ms 里 43ms 是解析，其余基本都花在「对全部消息逐个 part 扫一遍」上。

根因

dist/index.js 偏移 3,940,789：

function stripRawStage(parsed, wire){
  const counts = emptyCounts();
  if(!isPlainRecord2(parsed)) return counts;
  counts.carriers = stripEmbeddedChainCarriers(parsed, wire);
  if(wire==="google"){ stripGoogleContents(parsed, counts) }
  else if(wire==="responses"){ stripResponsesInput(parsed.input, counts) }
  else { stripMessagesArray(parsed.messages, counts) }   // ← 全部 messages
  return counts
}

stripMessagesArray / stripResponsesInput 对每一条消息的每一个文本 slot 调一次 stripTextSlot()：

if(typeof rec.content==="string"){
  rec.content = stripTextSlot(rec.content, counts, {noStatusBody});
}

12,898 条消息 × 每条的 part 数 = 每轮 ~1.3–2 万个 stripTextSlot 调用。

这条路径本身是必要的——它剥掉的是「只给界面看」的东西：ACP 面板消息（#359）、状态行（#1029）、nudge 回声、内嵌链 carriers。不剥就会污染上游报文和 prefix cache。

问题在访问模式：上一轮已经剥干净的历史，这一轮不会再变，但每一轮都从头重扫。

调用点 6 处（全部是「拿到完整 parsed 报文之后、转 core 之前」）：

incomingCoreMessages()：anthropic / openai / google / responses 各一处
OpenAI 分片快速路径：headFragment + windowFragment 两处

与既有 issue 的关系（去重）

这条不是 #5744 的重复——#5744 修的是存储侧（refs / ccr_entries / blocks 三张表的 diff 写入），stripRawStage 是请求侧，两者互不覆盖。

也不是 #4528 / #5869（那两条讲的是整个 per-turn 同步工作 starving event loop 的总体现象，作者采样把根因钉在存储侧 StatementSync.run）。

这条是请求侧的另一条腿：#5744 的采样（CDP，96.5% 自耗时在 StatementSync.run，栈恒为 ingestSession→ingestDelta→record→build→writeInner）覆盖的是写库，从头到尾没有出现 stripRawStage / stripTextSlot。所以在 #5755 修完三张表的 diff 写入之后，这一条仍然每轮全量跑。

建议

不需要改语义，只需要让它变成增量：

按 message id 记「已剥过」——同一 message.id 只扫一次；新消息才进 stripRawStage。状态可以挂在 session 上（和已有的 coveredMessageIds 同源）。
或退一步：只扫未进块的部分（prepared.processedMessages 的尾部 + 新增），历史部分跳过。
保留一个 forceFullStrip 逃生门，在报文形状变了（tail shape changed）时回退全量——这与 0.1.212: per-turn ingest is still O(history) — 96.5% of proxy CPU in StatementSync.run, event loop starves with 8 concurrent sessions (#4528 / #5469 follow-up) #5744 的 path=full 兜底同构。

附：可以在本地验证的脚本

# 从日志算每轮「读 body+预处理」占比
import re, statistics
lines = open("bili.log", encoding="utf-8", errors="replace").read().splitlines()
local = [int(m.group(1)) for l in lines for m in [re.search(r"local=(\d+)ms", l)] if m]
print(len(local), "轮, 中位", statistics.median(local), "ms")

日志里同时有 host-json-parse=XXms 与 slow-ingest: path=… took=XXms，把这两个减掉剩下的就是 stripRawStage 那一档。

一句话：报文解析 43 毫秒，剥标记几百毫秒——剥标记这一步每轮都在从头扫 12,898 条再也不会变的历史。

Correction to the environment table — the installed build is not a PR build.

dist/build-info.json  ->  { "commit": "133f3525c" }
npm billion-context@0.1.213  ->  gitHead "133f3525c628c4b959bb79ece82af6df82e131a3"

Identical, so this is 0.1.213 正式版, not pr.5755.

One thing worth fixing on your side: the package's package.json still says version: "0.1.208". That stale value is what the proxy logs ([v=0.1.208]) and what anyone reads first — which is exactly how I got the version wrong in the table above. build-info.json is the accurate source; consider bumping version at build time so the two agree.

🤖 Powered by ework · qwen3.8-27b

(ai: vllm-qwen/qwen3.8-27b)

查重结论：不重复。 与 #5744（存储侧 refs/ccr_entries/blocks 三表 diff 写入，已由 #5755 修复）不同——本条是请求侧 stripRawStage 的 O(history) 重扫；与 #4528/#5869（per-turn 同步工作饿死 event loop 的总体现象，采样根因在存储侧 StatementSync.run）不同——#5755 修完后这条路径仍每轮全量跑；与水位快车道（#5403/#5418，需 x-bili-pf 头 + 灰度命中才生效，legacy 路径不受影响）也不同。你 issue 里的去重分析本身是准确的。

标签： bug · dsh · scope/wiring · p3 —— 机制真实存在但实测量级小（见下），属性能瑕疵级；日志特征（host-json-parse 行来自 dsh-native 车道）判定客户端为 dsh。

审核结论：机制成立，量级被高估

三步审核都做了：

复现/查证：代码路径属实——stripRawStage（src/marker/engine.ts）每轮对重发报文的每个文本 slot 走一遍剥离，四条 wire 车道 + OpenAI 分片快路径共 6 个调用点，与你的清点一致。
测量：按你 issue 的会话形状（12,898 条消息、~23 MiB anthropic 报文）构造了同规模语料实测。当前 master（与你装的 v0.1.213 此文件逐字节相同——engine.ts 在两版本间无改动）：
- JSON.parse 23.3 MiB ≈ 17–75ms（与你测的 43ms 一致）
- stripRawStage 整趟中位 ≈ 10ms（区间 9–17），不是 ~800ms
- 其中大头是 MARKER_LINE 全局正则对全部 12,846 个 slot 的扫描：ungated ≈ 6.5ms → 加字面量门后 ≈ 1.5ms
- 同一语料上 kernel 的 ToCore 转换中位 ≈ 45ms——同窗口里比 strip 更大的 O(history) 切片
归因核对：你日志里 866ms「读 body+预处理」段减去 43ms 解析后的残差，不能直接记到 stripRawStage 头上——代码里并不存在这三个分段日志（读 body+预处理 / processTurn / 收尾是按时间戳自己重建的）。同一份日志里有更硬的候选：slow-ingest: path=delta took=588ms（会话保存发生在流结束之后，位于 local= 窗口之外）、processTurn=438ms（Long sessions starve the event loop: a 4,600-message session blocks the proxy and the web UI for 7–50 s per turn #4528 家族领域）、以及宿主侧 body 读取节奏（[perf][dsh] 25.8-32.7 s of each step elapses before bili sees the body (bili itself: 5.5-7.2 s) | TTFT 归因：每步 25.8-32.7 s 发生在 bili 收到请求体之前 #5792 那条 host-json-parse 行本身就说明解析前还有等待）。你的机器在安静/野兽模式间降频，各切片的真实占比只有在你机器上才能定论——这正是本次修复加诊断行的原因。

另外一点值得你在 #5744 线程跟进：v0.1.213 已经包含 #5755 的存储 diff 写入修复（该修复首发于 v0.1.213，已用 merge-base 验证），而你的日志在该版本上仍有 slow-ingest: path=delta took=588ms / 46.2 MiB WAL——存储侧还有别的事在发生，建议回到 #5744 线程带这份日志继续查。

修复（PR 已开）

#6023 （Closes #6018，标签 bug/perf/p3/scope/wiring/dsh）

没有采用 memoization（你的选项 1/2）：按 message id 记「已剥过」需要失效规则（压缩边界、消息改写、tail shape 变化）和每会话状态保留，而实测收益在加了下面的门之后只剩个位数毫秒。改为根因对齐的微修 + 可观测性：

门：MARKER_LINE 的每个匹配都必然含字面量 [ACP]，所以不含该字面量的 slot 不可能匹配——全局正则只在 slot 含 [ACP] 时才跑。干净历史（长会话的常态）从此几乎零成本。剥离输出逐字节不变（sha256 快照对比 + 全套 marker-lane-coverage 测试绿），且新测试按双向纪律钉住边界（near-miss 文本原样通过 / 真字面量行照剥）。
诊断：RawStripCounts.strippedMs 记录整趟墙钟，≥10ms 时打独立 info 行 raw-strip: Xms …(issue #6018)——与产物计数解耦，因为超大干净历史什么都不剥但仍然耗时。模式同 [perf][dsh] 25.8-32.7 s of each step elapses before bili sees the body (bili itself: 5.5-7.2 s) | TTFT 归因：每步 25.8-32.7 s 发生在 bili 收到请求体之前 #5792 的 host-json-parse 行：以后这类报告直接从日志读归属，不用再减残差猜。水位命中轮报 0（该轮没跑 walk）。

行为变更披露：新增一条可选 info 日志行（仅 ≥10ms 时出现，正常会话 <1ms 静默；水位命中轮静默）。无线协议变更、无配置面、无持久化变更、剥离语义逐字节不变。

Response to your version correction (English, since you wrote in English)

Thanks — confirmed on our side: npm billion-context@0.1.213 has gitHead 133f3525c…, matching your dist/build-info.json, so you are on the official release, not a PR build. Agreed, that's what it is.

On the stale package.json (0.1.208) beside the 0.1.213 dist: the published npm artifact is self-consistent by construction — the release branch bumps package.json before publish, and npm rejects version mismatches between the manifest and the tag. So a copy where dist/ is newer than package.json is install-lane drift on your machine, not a repo defect: something updated the dist without moving the manifest of that particular copy (this is the ledger-drift class tracked under the install-lane contract, #3496/#3224). Suggested check on your side: run bili doctor and look at how that copy updates (which channel owns it — global self-update vs host-managed profile bundle); if it reports drift, bili doctor --fix converges the ledgers.

Your suggestion to bump version at build time I have to decline: project discipline pins version to release branches only (§4/§5 — one version, one commit, one branch), and making build-time stamping authoritative would silently break that invariant for every consumer reading the manifest. The accurate source today is build-info.json; if the skew keeps biting people, the right fix is a doctor warning when manifest and build-info disagree — say the word and I'll take that on separately.

结构化八问

是什么问题：每轮请求都对全部重发历史逐 slot 重跑标记剥离（O(history) 同步扫描），即使历史早已干净。
什么原因导致的：stripTextSlot 对每个 slot 无条件执行 MARKER_LINE 全局正则；正则匹配必含字面量 [ACP]，但代码没有利用这一点做前置过滤，导致干净文本也付全价正则扫描。
影响范围与严重程度：所有走 legacy 全量路径的长会话（四车道通用）；本机实测 ~10ms/23MiB，属体验瑕疵（p3）——在你这种降频机器上占比可能更高，具体值等新的 raw-strip 日志行上线后从字段数据确认。
怎么修复的：字面量前置门（不含 [ACP] 的 slot 跳过正则）+ 整趟墙钟计时与阈值日志行；不做 memoization（收益小、失效规则复杂、引入新状态风险）。
是否有回归问题：剥离语义逐字节不变（sha256 快照前后一致）；既有行为逐项过——面板/状态体/nudge/carrier/标记行五类产物计数不变、markerArtifactCount 不读新字段、水位快路径命中的缓存计数语义保持（命中轮计时报 0，产物计数沿用原语义）、fastpath 分片求和正确累加两片段真实耗时。未破坏 fail-fast/默认值/时序/输出格式。
是否破坏缓存：不涉及——prefix cache、重试、增量游标、去重键均不受影响（出站字节不变）。
是否改了设计方向：否。仍是同一引擎同一语义，只改访问模式并加观测。
是否引入了新的配置：无新 env/config/CLI。仅一条 ≥10ms 触发的 info 日志行（无开关——它是诊断不是行为）。

收工判定：修复已完成并开 PR（#6023），定向测试 71/71 绿、typecheck 干净，CI 在推送头全量把关（刚开 PR，check 尚未入缓存）；等你或 reviewer 验收合并。量级问题（你这台机器上 strip 到底占多少）等新日志行随下个版本进字段后再下结论。

🤖 Powered by ework · qwen3.8-27b

(ai: vllm-qwen/qwen3.8-27b)

状态更新：PR #6023 的 CI 已全绿（推送头 dd40138 上 37 个 check 成功、31 个按门跳过、0 失败；另有 32 个 cancelled 是并发组去重的重复触发，对应工作流运行全部 success）。无红项需要处理。等 review / owner 合并即可。

Merge pull request #6023 from ranxianglei/2026-11-09_raw-strip-gate-t…

fix(ranxianglei#6018): gate the per-slot MARKER_LINE regex behind a l…

Merge origin/ci-fixes (= master tip 58a8796) into reland-v6 lane

fix(fastpath-v6): carry #6018 strippedMs field in strip-count literals

Navigation Menu

Repository navigation

stripRawStage rescans all history text every turn — a fourth O(history) sync path beyond #4528/#5744 #6018

环境

症状

根因

与既有 issue 的关系（去重）

建议

附：可以在本地验证的脚本

审核结论：机制成立，量级被高估

修复（PR 已开）

Response to your version correction (English, since you wrote in English)

结构化八问

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

stripRawStage rescans all history text every turn — a fourth O(history) sync path beyond #4528/#5744 #6018

Description

环境

症状

根因

与既有 issue 的关系（去重）

建议

附：可以在本地验证的脚本

Activity

mengnianqaq commented on Nov 9, 2026

ranxianglei commented on Nov 9, 2026

审核结论：机制成立，量级被高估

修复（PR 已开）

Response to your version correction (English, since you wrote in English)

结构化八问

ranxianglei commented on Nov 9, 2026

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions