Repository navigation
[Bug][dsh] 0.1.209: estimator under-counts the real payload by 18-26% -> permanent 400 loop after resume-miss; upstream-stated counts are never re-learned #5370
Description
Description *
DSH long-running session (processTurn: 4901 msgs, inbound 5.8 MiB, local-est 1,369,938 tok) hit a
resume-inheritance miss at 21:41:48 (+08:00). From then on, every turn had to rebuild the compression view
from raw messages. When the proxy own estimate reached 785,823 tok it forwarded the request; upstream
rejected at 991,404 tok (available input budget = window 1,048,576 - DSH-declared 256,000 max_tokens
reservation = 792,576). A refold to est 731,613 was rejected again at 922,782 tok; the 400 is passed through
(#1195). Three forwards were observed: est 785,823 / 731,613 / 782,170 -> upstream stated 991,404 / 922,782 /
922,919 (ratio 1.26x / 1.26x / 1.18x). Each attempt is preceded by a 141-350 s O(messages) scan (slow-session,
#4528), so the client just shows a spinner.
Expected: the proxy should recalibrate from the real counts the upstream 400 already states
(rejected payload ~991404 tokens stated, 922782 in the messages) - re-target the next preflight, or learn
k = stated/est for the route. Actual: every preflight re-decides from the local estimate and fails forever.
The estimator is CJK 1 char = 1 token plus 4 chars/token otherwise (defaultCountTokens in dist/index.js),
while the real tokenizer bills more; the docs themselves say local estimates run well below what upstream
actually bills for CJK-heavy content.
Repro:
- DSH lane session with >= ~1.3M tok of raw history (~4,901 rendered msgs, 5.8 MiB inbound).
- Client declares max_tokens = 256,000 (DSH default) -> available input budget 792,576.
- Force a resume-miss (goal-round injection, host-side prune, or any prefix rewrite).
- Every subsequent turn: 141-350 s local scan -> preflight folds up to 16 ranges on a 28-round budget ->
forwards at est 785,823 -> upstream 400 (stated 991,404) -> one refold (est 731,613) -> 400 -> error
forwarded to the client.
Additional observations (all from the same incidents log):
- folding can fail to shrink:
preflight compressed 4 range(s), ~0 tokens saved (958873 -> 981259). - the proxy post-fold estimate disagrees with the next round: postCtx/Vp = 632,513 vs payload ~928,964.
usage=oscillates on the same lane and the same 792,576 window: 537% (4256378/792576), 120%, 100%, 92%.- two preflights were aborted by client disconnect after folding 11 and 4 ranges (
not forwarding).
bili version *
0.1.209 (release 2026-10-28; also the latest release at report time)
Usage mode *
Plugin native (bili plugin install …, runs inside the host process)
Client and version *
DSH desktop 0.2.1-rc.5 (DeepSeek Harness, Electron)
Operating system *
Windows 11 (native, not WSL2)
Upstream and model *
https://api.deepseek.com/anthropic/v1/messages · deepseek-flash · stated window 1,048,576 · DSH-declared completion reservation 256,000 (max_tokens) · proxy estimator = CJK 1 char/token + 4 chars/token otherwise · upstream stated / proxy estimate in [1.18, 1.26]
Compression-related config (optional)
# ~/.config/billion-context/billion-context.json
providers: {}
compress:
modelContextLimit: "82%" # added after the incident to test the hard wall; it never loaded because the
# detached proxy from the previous host instance kept its old configLog excerpt (strongly recommended)
billion-context bili.log excerpt - incident 2026-10-31 21:40-21:59 (+08:00)
bili 0.1.209 | DSH desktop 0.2.1-rc.5 | Windows 11
session: session-7cbb9708-db37-49e9-a099-750e661e32b8 (DSH long-running session, 4901 msgs / 5.8 MiB)
upstream: https://api.deepseek.com/anthropic/v1/messages | model=deepseek-flash | stated window=1048576 | completion reservation=256000
filtered: resume-inheritance / preflight rounds / preflight aborted / shrink / compress / forward / overflow / refold / slow-session / usage
format: chronological, deduplicated (identical lines after the timestamp dropped), no head/tail truncation
redaction: no API keys and no message content; session ids kept.
--------------------------------------------------------------------------
2026-10-31T21:40:05.273 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] nudge idle: usage=46% (365190/792576), growth=58239/22500 (ref=306951, interval=50000), pendingT1=32259/50000 model=deepseek-flash, reason="max compressible 54834, growth 58239"
2026-10-31T21:40:05.332 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] slow-session: 2890 msgs / inbound=5.8MiB took local=586ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:40:05.332 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] forward POST → https://api.deepseek.com/anthropic/v1/messages
2026-10-31T21:40:12.371 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] nudge idle: usage=46% (366025/792576), growth=59074/22500 (ref=306951, interval=50000), pendingT1=32259/50000 model=deepseek-flash, reason="max compressible 54834, growth 59074"
2026-10-31T21:40:12.430 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] slow-session: 2892 msgs / inbound=5.8MiB took local=601ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:40:17.692 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] nudge idle: usage=46% (366349/792576), growth=59398/22500 (ref=306951, interval=50000), pendingT1=32259/50000 model=deepseek-flash, reason="max compressible 54834, growth 59398"
2026-10-31T21:40:17.755 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] slow-session: 2894 msgs / inbound=5.8MiB took local=608ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:40:38.779 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] nudge idle: usage=46% (366749/792576), growth=59798/22500 (ref=306951, interval=50000), pendingT1=32907/50000 model=deepseek-flash, reason="max compressible 54834, growth 59798"
2026-10-31T21:40:38.846 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] slow-session: 2896 msgs / inbound=5.8MiB took local=612ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:40:43.439 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] nudge idle: usage=46% (367117/792576), growth=60166/22500 (ref=306951, interval=50000), pendingT1=32907/50000 model=deepseek-flash, reason="max compressible 54834, growth 60166"
2026-10-31T21:40:43.503 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] slow-session: 2898 msgs / inbound=5.8MiB took local=576ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:40:51.690 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] nudge idle: usage=46% (367618/792576), growth=60667/22500 (ref=306951, interval=50000), pendingT1=33443/50000 model=deepseek-flash, reason="max compressible 54834, growth 60667"
2026-10-31T21:40:51.759 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] slow-session: 2900 msgs / inbound=5.8MiB took local=626ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:40:59.406 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] nudge idle: usage=47% (369003/792576), growth=62052/22500 (ref=306951, interval=50000), pendingT1=33443/50000 model=deepseek-flash, reason="max compressible 54834, growth 62052"
2026-10-31T21:40:59.464 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] slow-session: 2902 msgs / inbound=5.8MiB took local=586ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:41:08.271 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] nudge idle: usage=47% (369392/792576), growth=62441/22500 (ref=306951, interval=50000), pendingT1=35654/50000 model=deepseek-flash, reason="max compressible 54834, growth 62441"
2026-10-31T21:41:08.332 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] slow-session: 2904 msgs / inbound=5.8MiB took local=598ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:41:08.332 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] forward POST → https://api.deepseek.com/anthropic/v1/messages
2026-10-31T21:41:16.575 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] nudge idle: usage=47% (371005/792576), growth=64054/22500 (ref=306951, interval=50000), pendingT1=36600/50000 model=deepseek-flash, reason="max compressible 54834, growth 64054"
2026-10-31T21:41:16.638 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] slow-session: 2906 msgs / inbound=5.8MiB took local=617ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:41:21.524 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] nudge idle: usage=47% (371794/792576), growth=64843/22500 (ref=306951, interval=50000), pendingT1=36600/50000 model=deepseek-flash, reason="max compressible 54834, growth 64843"
2026-10-31T21:41:21.619 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] slow-session: 2908 msgs / inbound=5.8MiB took local=873ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:41:29.539 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] nudge idle: usage=47% (372229/792576), growth=65278/22500 (ref=306951, interval=50000), pendingT1=37526/50000 model=deepseek-flash, reason="max compressible 54834, growth 65278"
2026-10-31T21:41:29.596 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] slow-session: 2910 msgs / inbound=5.8MiB took local=649ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:41:34.437 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] nudge idle: usage=47% (372996/792576), growth=66045/22500 (ref=306951, interval=50000), pendingT1=38051/50000 model=deepseek-flash, reason="max compressible 54834, growth 66045"
2026-10-31T21:41:34.532 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] slow-session: 2912 msgs / inbound=5.8MiB took local=870ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:41:40.480 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] nudge idle: usage=47% (373458/792576), growth=66507/22500 (ref=306951, interval=50000), pendingT1=38416/50000 model=deepseek-flash, reason="max compressible 54834, growth 66507"
2026-10-31T21:41:40.580 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:c37b54e467bd6dea] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:c37b54e467bd6dea] slow-session: 2914 msgs / inbound=5.8MiB took local=889ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:41:48.861 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] [resume-inheritance] miss: no byte-exact resume among 26 eligible chain(s); closest session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:9149a98a8075fa0f (chain 2197, incoming 3167): first divergence found at cell 2069 (stored ab5d8308 vs incoming fe798d61; cells 0..2068 uninspectable — chain deeper than the 128-cell window) (#4264)
2026-10-31T21:41:51.329 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] processTurn: 4901 msgs, renderTags=text-only, 274 text tagged, 0 tool tagged (should be 0 with text-only)
2026-10-31T21:41:51.329 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] nudge idle: usage=0% (0/792576), growth=0/22500 (ref=0, interval=50000), pendingT1=1185307/50000 model=deepseek-flash, reason="growth 0 < floor 22500, ready: T1 1185307"
2026-10-31T21:41:51.465 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] context 1369938 tokens reached preflight target 792576 (model window 792576, model=deepseek-flash; usage-baseline=none local-est=1367638); preflight compressing before forward
2026-10-31T21:41:51.480 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] payload ~1367056 tok vs window 792576 (~1.7x) — raising summarization budget 16 -> 28, rounds 16 -> 28
2026-10-31T21:41:53.612 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 1/28: payload ~1369938 tok vs window 792576 (deficit 577362), 131 viable range(s)
2026-10-31T21:42:00.206 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00372–m00455]
2026-10-31T21:42:00.261 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 3% this-fold (~42337/1332856 tok) · cumulative 3% (~42337/1332856 tok) foldPoint=m00372 blocks=1 anchor≈496 tok (1 active blocks, sys excluded) postCtx≈1290519 → next-request cache ceiling ≥0%
2026-10-31T21:42:02.408 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 2/28: payload ~1328469 tok vs window 792576 (deficit 535893), 130 viable range(s)
2026-10-31T21:42:18.160 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m03639–m03865]
2026-10-31T21:42:18.270 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 3% this-fold (~39079/1332856 tok) · cumulative 6% (~81416/1332856 tok) foldPoint=m03639 blocks=1 anchor≈2573 tok (2 active blocks, sys excluded) postCtx≈1251440 → next-request cache ceiling ≥0%
2026-10-31T21:42:20.372 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 3/28: payload ~1292215 tok vs window 792576 (deficit 499639), 129 viable range(s)
2026-10-31T21:42:21.469 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] preflight still running after 30000ms grace — committed early SSE headers + keep-alive to hold the client (#568)
2026-10-31T21:42:22.291 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m01678–m01831]
2026-10-31T21:42:22.361 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 3% this-fold (~38857/1332856 tok) · cumulative 9% (~120273/1332856 tok) foldPoint=m01678 blocks=1 anchor≈2657 tok (3 active blocks, sys excluded) postCtx≈1212583 → next-request cache ceiling ≥0%
2026-10-31T21:42:24.416 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 4/28: payload ~1253458 tok vs window 792576 (deficit 460882), 128 viable range(s)
2026-10-31T21:42:29.371 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00981–m01050]
2026-10-31T21:42:29.427 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 3% this-fold (~33648/1332856 tok) · cumulative 12% (~153921/1332856 tok) foldPoint=m00981 blocks=1 anchor≈2904 tok (4 active blocks, sys excluded) postCtx≈1178935 → next-request cache ceiling ≥0%
2026-10-31T21:42:31.468 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 5/28: payload ~1220063 tok vs window 792576 (deficit 427487), 127 viable range(s)
2026-10-31T21:42:46.276 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00809–m00881]
2026-10-31T21:42:46.334 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 3% this-fold (~33500/1332856 tok) · cumulative 14% (~187421/1332856 tok) foldPoint=m00809 blocks=1 anchor≈4978 tok (5 active blocks, sys excluded) postCtx≈1145435 → next-request cache ceiling ≥0%
2026-10-31T21:42:48.357 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 6/28: payload ~1188947 tok vs window 792576 (deficit 396371), 126 viable range(s)
2026-10-31T21:42:54.194 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00493–m00564]
2026-10-31T21:42:54.248 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 2% this-fold (~31440/1332856 tok) · cumulative 16% (~218861/1332856 tok) foldPoint=m00493 blocks=1 anchor≈5919 tok (6 active blocks, sys excluded) postCtx≈1113995 → next-request cache ceiling ≥0%
2026-10-31T21:42:56.258 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 7/28: payload ~1158470 tok vs window 792576 (deficit 365894), 125 viable range(s)
2026-10-31T21:43:24.191 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m03466–m03607]
2026-10-31T21:43:24.277 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 2% this-fold (~30579/1332856 tok) · cumulative 19% (~249440/1332856 tok) foldPoint=m03466 blocks=1 anchor≈8633 tok (7 active blocks, sys excluded) postCtx≈1083416 → next-request cache ceiling ≥0%
2026-10-31T21:43:26.432 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 8/28: payload ~1130727 tok vs window 792576 (deficit 338151), 124 viable range(s)
2026-10-31T21:43:50.119 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m02065–m02142]
2026-10-31T21:43:50.183 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 2% this-fold (~24262/1332856 tok) · cumulative 21% (~273702/1332856 tok) foldPoint=m02065 blocks=1 anchor≈10807 tok (8 active blocks, sys excluded) postCtx≈1059154 → next-request cache ceiling ≥1%
2026-10-31T21:43:52.171 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 9/28: payload ~1108661 tok vs window 792576 (deficit 316085), 123 viable range(s)
2026-10-31T21:44:15.488 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00196–m00322]
2026-10-31T21:44:15.546 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 2% this-fold (~22064/1332856 tok) · cumulative 22% (~295766/1332856 tok) foldPoint=m00196 blocks=1 anchor≈15113 tok (9 active blocks, sys excluded) postCtx≈1037090 → next-request cache ceiling ≥1%
2026-10-31T21:44:17.516 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 10/28: payload ~1091055 tok vs window 792576 (deficit 298479), 122 viable range(s)
2026-10-31T21:44:19.020 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00631–m00711]
2026-10-31T21:44:19.076 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 2% this-fold (~22036/1332856 tok) · cumulative 24% (~317802/1332856 tok) foldPoint=m00631 blocks=1 anchor≈15145 tok (10 active blocks, sys excluded) postCtx≈1015054 → next-request cache ceiling ≥1%
2026-10-31T21:44:21.025 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 11/28: payload ~1069078 tok vs window 792576 (deficit 276502), 121 viable range(s)
2026-10-31T21:44:23.625 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m01052–m01114]
2026-10-31T21:44:23.681 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 2% this-fold (~21922/1332856 tok) · cumulative 25% (~339724/1332856 tok) foldPoint=m01052 blocks=1 anchor≈15451 tok (11 active blocks, sys excluded) postCtx≈993132 → next-request cache ceiling ≥1%
2026-10-31T21:44:25.608 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 12/28: payload ~1047478 tok vs window 792576 (deficit 254902), 120 viable range(s)
2026-10-31T21:44:49.517 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] nudge INJECT T1: usage=537% (4256378/792576), growth=3208916/22500 (ref=1047462, interval=50000), pendingT1=845583/50000 model=deepseek-flash, reason="EMERGENCY T1: max effective pending 845583, usage 537%"
2026-10-31T21:44:49.553 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] preflight compressed 11 range(s), ~322460 tokens saved (1369938 → 949521) in 178088ms
2026-10-31T21:44:49.553 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] preflight aborted (the client disconnected during preflight compression); not forwarding
2026-10-31T21:44:49.553 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] slow-session: 2907 msgs / inbound=5.9MiB took local=181172ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:44:51.984 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] nudge INJECT T1: usage=120% (949521/792576), growth=-3306857/22500 (ref=4256378, interval=50000), pendingT1=845583/50000 model=deepseek-flash, reason="EMERGENCY T1: max effective pending 845583, usage 120%"
2026-10-31T21:44:52.109 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] slow-session: 2907 msgs / inbound=5.8MiB took local=2545ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:44:52.110 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] forward POST → https://api.deepseek.com/anthropic/v1/messages
2026-10-31T21:44:53.379 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] upstream context overflow (model=deepseek-flash) — window 1048576 stated upstream, rejected payload ~1174837 tokens stated, completion reservation 256000 tokens; armed emergency shrink at 792576 (clamped to the judging limit 792576, #3738), declared window unchanged (#987)
2026-10-31T21:44:55.521 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] nudge INJECT T1: usage=100% (792576/792576), growth=-156945/22500 (ref=949521, interval=50000), pendingT1=845583/50000 model=deepseek-flash, reason="EMERGENCY T1: max effective pending 845583, usage 100%"
2026-10-31T21:44:55.618 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] context 958873 tokens reached preflight target 792576 (window 792576 minus proven completion reservation 256000) (model window 792576, model=deepseek-flash; usage-baseline=792576 local-est=956573); preflight compressing before forward
2026-10-31T21:44:55.655 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] payload ~1367515 tok vs window 792576 (~1.7x) — raising summarization budget 16 -> 28, rounds 16 -> 28
2026-10-31T21:44:57.600 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 1/28: payload ~958873 tok vs window 792576 (deficit 166297), 120 viable range(s)
2026-10-31T21:45:21.613 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m01164–m01222]
2026-10-31T21:45:21.670 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 2% this-fold (~20071/1333315 tok) · cumulative 27% (~359795/1333315 tok) foldPoint=m01164 blocks=1 anchor≈16824 tok (12 active blocks, sys excluded) postCtx≈973520 → next-request cache ceiling ≥1%
2026-10-31T21:45:23.578 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 2/28: payload ~1029881 tok vs window 792576 (deficit 237305), 119 viable range(s)
2026-10-31T21:45:25.645 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] preflight still running after 30000ms grace — committed early SSE headers + keep-alive to hold the client (#568)
2026-10-31T21:46:16.794 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m04259–m04282]
2026-10-31T21:46:16.855 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~19973/1333315 tok) · cumulative 28% (~379768/1333315 tok) foldPoint=m04259 blocks=1 anchor≈21798 tok (13 active blocks, sys excluded) postCtx≈953547 → next-request cache ceiling ≥2%
2026-10-31T21:46:18.814 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 3/28: payload ~1015178 tok vs window 792576 (deficit 222602), 118 viable range(s)
2026-10-31T21:46:41.908 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m01451–m01530]
2026-10-31T21:46:41.974 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~19466/1333315 tok) · cumulative 30% (~399234/1333315 tok) foldPoint=m01451 blocks=1 anchor≈23903 tok (14 active blocks, sys excluded) postCtx≈934081 → next-request cache ceiling ≥2%
2026-10-31T21:46:43.939 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 4/28: payload ~998578 tok vs window 792576 (deficit 206002), 117 viable range(s)
2026-10-31T21:46:54.538 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00931–m00980]
2026-10-31T21:46:54.595 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~19035/1333315 tok) · cumulative 31% (~418269/1333315 tok) foldPoint=m00931 blocks=1 anchor≈25110 tok (15 active blocks, sys excluded) postCtx≈915046 → next-request cache ceiling ≥2%
2026-10-31T21:46:56.475 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 5/28: payload ~981259 tok vs window 792576 (deficit 188683), 116 viable range(s)
2026-10-31T21:47:11.116 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] nudge INJECT T1: usage=92% (725876/792576), growth=-255420/22500 (ref=981296, interval=50000), pendingT1=767038/50000 model=deepseek-flash, reason="OVER-LIMIT T1: max effective pending 767038, usage 92%"
2026-10-31T21:47:11.154 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] preflight compressed 4 range(s), ~0 tokens saved (958873 → 981259) in 135513ms
2026-10-31T21:47:11.154 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] preflight aborted (the client disconnected during preflight compression); not forwarding
2026-10-31T21:47:11.154 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] slow-session: 2907 msgs / inbound=5.8MiB took local=141595ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:47:57.195 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] nudge INJECT T1: usage=92% (725876/792576), growth=0/22500 (ref=725876, interval=50000), pendingT1=767038/50000 model=deepseek-flash, reason="OVER-LIMIT T1: max effective pending 767038, usage 92%"
2026-10-31T21:47:57.313 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] context 981355 tokens reached preflight target 792576 (window 792576 minus proven completion reservation 256000) (model window 792576, model=deepseek-flash; usage-baseline=725876 local-est=979055); preflight compressing before forward
2026-10-31T21:47:57.327 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] payload ~1367601 tok vs window 792576 (~1.7x) — raising summarization budget 16 -> 28, rounds 16 -> 28
2026-10-31T21:47:59.188 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 1/28: payload ~981355 tok vs window 792576 (deficit 188779), 116 viable range(s)
2026-10-31T21:48:13.274 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m03364–m03465]
2026-10-31T21:48:13.350 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~18063/1333323 tok) · cumulative 33% (~436332/1333323 tok) foldPoint=m03364 blocks=1 anchor≈26949 tok (16 active blocks, sys excluded) postCtx≈896991 → next-request cache ceiling ≥3%
2026-10-31T21:48:15.187 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 2/28: payload ~965140 tok vs window 792576 (deficit 172564), 115 viable range(s)
2026-10-31T21:48:27.319 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] preflight still running after 30000ms grace — committed early SSE headers + keep-alive to hold the client (#568)
2026-10-31T21:48:40.971 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00081–m00094]
2026-10-31T21:48:41.024 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~17316/1333323 tok) · cumulative 34% (~453648/1333323 tok) foldPoint=m00081 blocks=1 anchor≈29118 tok (17 active blocks, sys excluded) postCtx≈879675 → next-request cache ceiling ≥3%
2026-10-31T21:48:42.854 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 3/28: payload ~951591 tok vs window 792576 (deficit 159015), 114 viable range(s)
2026-10-31T21:49:02.787 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00566–m00630]
2026-10-31T21:49:02.843 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~16716/1333323 tok) · cumulative 35% (~470364/1333323 tok) foldPoint=m00566 blocks=1 anchor≈32007 tok (18 active blocks, sys excluded) postCtx≈862959 → next-request cache ceiling ≥3%
2026-10-31T21:49:04.690 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 4/28: payload ~938145 tok vs window 792576 (deficit 145569), 113 viable range(s)
2026-10-31T21:49:21.054 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00004–m00028]
2026-10-31T21:49:21.110 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~16371/1333323 tok) · cumulative 37% (~486735/1333323 tok) foldPoint=m00004 blocks=1 anchor≈33789 tok (19 active blocks, sys excluded) postCtx≈846588 → next-request cache ceiling ≥3%
2026-10-31T21:49:22.934 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 5/28: payload ~923752 tok vs window 792576 (deficit 131176), 112 viable range(s)
2026-10-31T21:49:36.085 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m03952–m04029]
2026-10-31T21:49:36.159 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~15912/1333323 tok) · cumulative 38% (~502647/1333323 tok) foldPoint=m03952 blocks=1 anchor≈35846 tok (20 active blocks, sys excluded) postCtx≈830676 → next-request cache ceiling ≥4%
2026-10-31T21:49:37.965 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 6/28: payload ~909939 tok vs window 792576 (deficit 117363), 111 viable range(s)
2026-10-31T21:49:51.031 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00752–m00773]
2026-10-31T21:49:51.085 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~15585/1333323 tok) · cumulative 39% (~518232/1333323 tok) foldPoint=m00752 blocks=1 anchor≈36953 tok (21 active blocks, sys excluded) postCtx≈815091 → next-request cache ceiling ≥4%
2026-10-31T21:49:52.860 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 7/28: payload ~896590 tok vs window 792576 (deficit 104014), 110 viable range(s)
2026-10-31T21:50:06.773 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00136–m00154]
2026-10-31T21:50:06.826 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~15267/1333323 tok) · cumulative 40% (~533499/1333323 tok) foldPoint=m00136 blocks=1 anchor≈38351 tok (22 active blocks, sys excluded) postCtx≈799824 → next-request cache ceiling ≥4%
2026-10-31T21:50:08.596 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 8/28: payload ~883716 tok vs window 792576 (deficit 91140), 109 viable range(s)
2026-10-31T21:50:25.810 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m01115–m01152]
2026-10-31T21:50:25.867 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~14287/1333323 tok) · cumulative 41% (~547786/1333323 tok) foldPoint=m01115 blocks=1 anchor≈39712 tok (23 active blocks, sys excluded) postCtx≈785537 → next-request cache ceiling ≥5%
2026-10-31T21:50:27.617 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 9/28: payload ~871842 tok vs window 792576 (deficit 79266), 108 viable range(s)
2026-10-31T21:50:49.845 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m02285–m02344]
2026-10-31T21:50:49.907 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~13924/1333323 tok) · cumulative 42% (~561710/1333323 tok) foldPoint=m02285 blocks=1 anchor≈41245 tok (24 active blocks, sys excluded) postCtx≈771613 → next-request cache ceiling ≥5%
2026-10-31T21:50:51.645 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 10/28: payload ~859467 tok vs window 792576 (deficit 66891), 107 viable range(s)
2026-10-31T21:51:13.091 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00095–m00107]
2026-10-31T21:51:13.149 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~13624/1333323 tok) · cumulative 43% (~575334/1333323 tok) foldPoint=m00095 blocks=1 anchor≈43003 tok (25 active blocks, sys excluded) postCtx≈757989 → next-request cache ceiling ≥5%
2026-10-31T21:51:14.922 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 11/28: payload ~849148 tok vs window 792576 (deficit 56572), 106 viable range(s)
2026-10-31T21:51:49.015 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00109–m00120]
2026-10-31T21:51:49.072 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~13560/1333323 tok) · cumulative 44% (~588894/1333323 tok) foldPoint=m00109 blocks=1 anchor≈44826 tok (26 active blocks, sys excluded) postCtx≈744429 → next-request cache ceiling ≥6%
2026-10-31T21:51:50.796 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 12/28: payload ~839155 tok vs window 792576 (deficit 46579), 105 viable range(s)
2026-10-31T21:52:11.969 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m01322–m01391]
2026-10-31T21:52:12.031 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~12847/1333323 tok) · cumulative 45% (~601741/1333323 tok) foldPoint=m01322 blocks=1 anchor≈46136 tok (27 active blocks, sys excluded) postCtx≈731582 → next-request cache ceiling ≥6%
2026-10-31T21:52:13.774 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 13/28: payload ~828304 tok vs window 792576 (deficit 35728), 104 viable range(s)
2026-10-31T21:52:24.475 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m02201–m02230]
2026-10-31T21:52:24.533 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~12675/1333323 tok) · cumulative 46% (~614416/1333323 tok) foldPoint=m02201 blocks=1 anchor≈47654 tok (28 active blocks, sys excluded) postCtx≈718907 → next-request cache ceiling ≥6%
2026-10-31T21:52:26.228 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 14/28: payload ~817163 tok vs window 792576 (deficit 24587), 103 viable range(s)
2026-10-31T21:52:42.663 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00155–m00195]
2026-10-31T21:52:42.719 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~12668/1333323 tok) · cumulative 47% (~627084/1333323 tok) foldPoint=m00155 blocks=1 anchor≈48950 tok (29 active blocks, sys excluded) postCtx≈706239 → next-request cache ceiling ≥6%
2026-10-31T21:52:44.439 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 15/28: payload ~807350 tok vs window 792576 (deficit 14774), 102 viable range(s)
2026-10-31T21:52:59.400 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m03206–m03278]
2026-10-31T21:52:59.471 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~12581/1333323 tok) · cumulative 48% (~639665/1333323 tok) foldPoint=m03206 blocks=1 anchor≈50477 tok (30 active blocks, sys excluded) postCtx≈693658 → next-request cache ceiling ≥7%
2026-10-31T21:53:01.126 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 16/28: payload ~796366 tok vs window 792576 (deficit 3790), 101 viable range(s)
2026-10-31T21:53:17.027 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m01565–m01583]
2026-10-31T21:53:17.085 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~12524/1333323 tok) · cumulative 49% (~652189/1333323 tok) foldPoint=m01565 blocks=1 anchor≈51681 tok (31 active blocks, sys excluded) postCtx≈681134 → next-request cache ceiling ≥7%
2026-10-31T21:53:20.794 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] nudge idle: usage=67% (530213/792576), growth=-255594/22500 (ref=785807, interval=50000), pendingT1=533118/50000 model=deepseek-flash, reason="growth -255594 < floor 22500, ready: T1 533118"
2026-10-31T21:53:20.825 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] preflight compressed 16 range(s), ~195532 tokens saved (981355 → 785823) in 323512ms
2026-10-31T21:53:20.846 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] slow-session: 2908 msgs / inbound=5.8MiB took local=326048ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:53:20.846 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] forward POST → https://api.deepseek.com/anthropic/v1/messages
2026-10-31T21:53:21.840 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] upstream context overflow (model=deepseek-flash) — window 1048576 stated upstream, rejected payload ~991404 tokens stated, completion reservation 256000 tokens; armed emergency shrink at 792576 (clamped to the judging limit 792576, #3738), declared window unchanged (#987)
2026-10-31T21:53:23.764 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] nudge INJECT T1: usage=100% (792576/792576), growth=262363/22500 (ref=530213, interval=50000), pendingT1=533118/50000 model=deepseek-flash, reason="EMERGENCY T1: max effective pending 533118, usage 100%"
2026-10-31T21:53:23.863 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] context 792576 tokens reached preflight target 792576 (window 792576 minus proven completion reservation 256000) (model window 792576, model=deepseek-flash; usage-baseline=792576 local-est=739285); preflight compressing before forward
2026-10-31T21:53:23.879 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] payload ~1367601 tok vs window 792576 (~1.7x) — raising summarization budget 16 -> 28, rounds 16 -> 28
2026-10-31T21:53:25.531 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 1/28: payload ~741585 tok vs window 792576 (deficit 0), 100 viable range(s)
2026-10-31T21:53:40.935 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m01584–m01659]
2026-10-31T21:53:40.999 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~12470/1333323 tok) · cumulative 50% (~664659/1333323 tok) foldPoint=m01584 blocks=1 anchor≈52976 tok (32 active blocks, sys excluded) postCtx≈668664 → next-request cache ceiling ≥7%
2026-10-31T21:53:44.653 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] nudge INJECT T1: usage=99% (782170/792576), growth=0/22500 (ref=782170, interval=50000), pendingT1=520648/50000 model=deepseek-flash, reason="EMERGENCY T1: max effective pending 520648, usage 99%"
2026-10-31T21:53:44.681 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] preflight compressed 1 range(s), ~10406 tokens saved (792576 → 731613) in 20818ms
2026-10-31T21:53:44.684 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] slow-session: 2908 msgs / inbound=5.8MiB took local=349887ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:53:45.530 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] context overflow — refold retry still rejected (HTTP 400); passing the retry response through (#1195)
2026-10-31T21:54:42.185 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] nudge INJECT T1: usage=99% (782170/792576), growth=0/22500 (ref=782170, interval=50000), pendingT1=520648/50000 model=deepseek-flash, reason="EMERGENCY T1: max effective pending 520648, usage 99%"
2026-10-31T21:54:42.295 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] slow-session: 2908 msgs / inbound=5.7MiB took local=2257ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
2026-10-31T21:54:42.296 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] forward POST → https://api.deepseek.com/anthropic/v1/messages
2026-10-31T21:54:43.406 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] upstream context overflow (model=deepseek-flash) — window 1048576 stated upstream, rejected payload ~922919 tokens stated, completion reservation 256000 tokens; armed emergency shrink at 792576 (clamped to the judging limit 792576, #3738), declared window unchanged (#987)
2026-10-31T21:54:45.122 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] nudge INJECT T1: usage=100% (792576/792576), growth=10406/22500 (ref=782170, interval=50000), pendingT1=520648/50000 model=deepseek-flash, reason="EMERGENCY T1: max effective pending 520648, usage 100%"
2026-10-31T21:54:45.242 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] payload ~1367675 tok vs window 792576 (~1.7x) — raising summarization budget 16 -> 28, rounds 16 -> 28
2026-10-31T21:54:46.879 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 1/28: payload ~913329 tok vs window 792576 (deficit 120753), 99 viable range(s)
2026-10-31T21:55:08.924 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m03282–m03349]
2026-10-31T21:55:08.992 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~12430/1333397 tok) · cumulative 51% (~677089/1333397 tok) foldPoint=m03282 blocks=1 anchor≈55367 tok (33 active blocks, sys excluded) postCtx≈656308 → next-request cache ceiling ≥8%
2026-10-31T21:55:10.591 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 2/28: payload ~955452 tok vs window 792576 (deficit 162876), 98 viable range(s)
2026-10-31T21:55:13.673 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00468–m00492]
2026-10-31T21:55:13.728 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~12016/1333397 tok) · cumulative 52% (~689105/1333397 tok) foldPoint=m00468 blocks=1 anchor≈55444 tok (34 active blocks, sys excluded) postCtx≈644292 → next-request cache ceiling ≥8%
2026-10-31T21:55:15.316 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 3/28: payload ~940738 tok vs window 792576 (deficit 148162), 97 viable range(s)
2026-10-31T21:55:15.355 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] preflight still running after 30000ms grace — committed early SSE headers + keep-alive to hold the client (#568)
2026-10-31T21:55:31.666 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-proxy: compress requested 1 range(s): m00712–m00722]
2026-10-31T21:55:31.733 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [acp-compress-obs] shrink 1% this-fold (~11779/1333397 tok) · cumulative 53% (~700884/1333397 tok) foldPoint=m00712 blocks=1 anchor≈57516 tok (35 active blocks, sys excluded) postCtx≈632513 → next-request cache ceiling ≥9%
2026-10-31T21:55:33.446 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [preflight] round 4/28: payload ~928964 tok vs window 792576 (deficit 136388), 96 viable range(s)
2026-10-31T21:59:05.743 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] nudge INJECT T1: usage=96% (761374/792576), growth=-169963.12096285203/22500 (ref=931337.120962852, interval=50000), pendingT1=484423/50000 model=deepseek-flash, reason="EMERGENCY T1: max effective pending 484423, usage 96%"
2026-10-31T21:59:05.794 [info] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] preflight compressed 3 range(s), ~0 tokens saved (913329.2691087177 → 875788.6967605876) in 260566ms
2026-10-31T21:59:05.795 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] preflight aborted (the client disconnected during preflight compression); not forwarding
2026-10-31T21:59:05.795 [warn] [sess=session-7cbb9708-db37-49e9-a099-750e661e32b8_sub:67c7fac0eb516238] [session-7cbb9708-db37-49e9-a099-750e661e32b8|sub:67c7fac0eb516238] slow-session: 2908 msgs / inbound=5.7MiB took local=265764ms — per-turn O(messages) synchronous scans are starving the event loop (#4528); consider closing/restarting the session or enabling compression
/acp or acp_status output (optional)
Activity
Leon-dbh commentedon Oct 31, 2026
issue-5370-followup-comment.md
ranxianglei commentedon Oct 31, 2026
(ai: vllm-qwen/qwen3.8-27b)
查重: 不重复。 相关条目与差异:
785,823+256,000 < 1,048,576纸面上放得下);标签:
bug/dsh/scope/kernel(src 侧压缩判定面)/p1(会话完全不可用直到人工干预)。审核已完成(v0.1.209 与 master 在全部相关文件上逐字节一致, 结论适用于你的版本):
k̂=后缀(校准时必打印)——学到的因子没有指导过任何一次后续决策。所以根因不是「功能缺失」, 是「学习闭环在这个场景下没合上」。bias = stated/estimate、target 除以 bias——这在代数上等价于把 k̂ 应用到 fit 判定(fold 到 est×k̂ ≤ budget ⟺ est ≤ budget/k̂)。我们会收敛到既有 k̂ 机制, 不另立平行变量。follow-up 信息全部收到并记录: 第 4 次 forward 是 #2313 证据探针、raw 400 body(request_id 已留)、闭环分析(dsh native compaction 按设计拒绝 #1729 + preflight 降不到目标之下)、max_tokens 绕行验证、以及三处更正(detached proxy 进程 / typo / 标题精度)。
下一步: 搭定向复现测试(mock 上游按 DeepSeek 形状回 400, 驱动真实管道), 钉死上面三个断点的具体位置, 然后修复 + 回归测试 + PR。有结果即回。
Leon-dbh commentedon Oct 31, 2026
补充一条证据：k̂ 确实参与过判定，断点更准确的说法是「太晚 + 太慢」
感谢这份诊断，三个断点的方向和修法（bias = stated/estimate、target / bias）我都认同。这里只补一条与「学到的因子没有指导过任何一次后续决策」相左的日志证据，它可能影响定向复现测试的断言。
代码块
2026-10-31T21:54:45.206 [warn] [...] context 913329.2691087177 tokens reached preflight target 792576
(window 792576 minus proven completion reservation 256000) (model window 792576, model=deepseek-flash;
usage-baseline=792576 local-est=911029 raw=729419 k̂=1.25); preflight compressing before forward
这一行发生在 21:53:45 与 21:54:43 两次 400 之后、同一条 lane 的下一轮判定。关键在 raw=729419：不乘 k̂ 时 729,419 < 792,576，这一轮会被直接放行；乘上 1.25 后得到 local-est=911029（判定口径 913,329）才越过目标、触发折叠。所以「k̂ 从未指导任何后续决策」不成立——它至少指导了 21:54:45 这一次，而且方向是对的。
另外说明：本会话日志里 k̂= 只出现在这一行；preflight trigger fired on estimate only（21:44:52.107）那种行确实没有 k̂ 后缀，但它是校准之前的探针投递（#2313），不能用来证明之后也没参与。
代码块
21:54:46.879 [preflight] round 1/28: payload ~913329 tok vs window 792576 (deficit 120753), 99 viable range(s)
...
21:59:05.794 preflight compressed 3 range(s), ~0 tokens saved (913329.2691087177 → 875788.6967605876) in 260566ms
21:59:05.795 preflight aborted (the client disconnected during preflight compression); not forwarding
21:59:05.795 slow-session: 2908 msgs / inbound=5.7MiB took local=265764ms ...
从 round 1/28 到 abort 共 260,566ms，只完成 3 个区间，净收益被记成 ≈0（自估差额 37,540 tok 却写 ~0 tokens saved），缺口还剩 ~120k。若单轮能省 ~40–50k 而不是 ~0，5 分钟内足以从 913k 折到 634k（对应 real ≈ 792k）。
所以这次事故的因果链是 k̂ 迟到（探针投递已经发出）+ k̂ 到位后折叠吞吐不足，而不是「因子没有参与」。
21:54:42.296 forward POST 那一次确实是 estimate 级基线（nudge usage=99% (782170/792576)，且没有 trigger 行），这条成立。但 21:54:45.206 这次判定读到的基线是 usage-baseline=792576 + k̂=1.25，不是 estimate 级。若要把「fold 后重建路径把权威基线覆盖成 estimate 级」作为第三个断点，需要解释为什么同一轮里两处读到的基线不同（一处 782,170、一处 792,576）。
代码块
21:44:52.107 preflight trigger fired on estimate only (~947711 text + ~2300 image vs window 792576) ...
forwarding once to acquire usage/overflow evidence before compressing (#2313)
21:44:52.110 forward POST -> https://api.deepseek.com/anthropic/v1/messages
21:44:53.379 upstream context overflow ... rejected payload ~1174837 tokens stated
这次探针投递的 payload 不在正文列的 785,823 / 731,613 / 782,170 里，因此比率样本少一个（现有 1.262 / 1.261 / 1.180，加上它是 1.237，区间不变）。
我们把客户端 DSH 的 max_tokens 从 256,000 降到 32,768（窗口分母变成 1,015,808），并解封 DSH 原生压缩之后，同一会话在 22:49 恢复：
代码块
22:49:12.290 ... dsh compaction call identified (...) — ANSWERED LOCALLY with the bili snapshot (#3733 authored checkpoint)
22:51:09.586 [acp-usage] input=169316 cached=169088 (cache hit 100%)
22:51:10.287 nudge idle: usage=17% (169316/1015808)
之后不再出现 400。这与「降预留 / 提前压缩」的修法方向一致，供复现测试参考。
需要更细的切片（例如那四轮 preflight 的完整 round 日志）我可以补。
ranxianglei commentedon Oct 31, 2026
(ai: vllm-qwen/qwen3.8-27b)
感谢补充——这条证据很关键，逐条回应：
1. 撤回「k̂ 从未指导任何后续判定」。 21:54:45.206 那行证明环在样本积累后发布了 1.25 并直接改变了那次判定：raw 729,419 单独看低于目标会被放行，乘上 k̂ 才越线触发折叠。准确表述修正为：k̂ 迟到（探针投递与前三次 400 都发生在发布之前）+ 到位后的折叠吞吐不足，而不是「因子没参与」。我的定向复现测试不会断言「因子从未生效」，而是断言修复后的行为：首次 overflow 起判定就按 stated 口径走。
2. 探针投递漏记，确认。 完整是四次投递，比率样本 1.237 / 1.262 / 1.261 / 1.180（区间不变）。
3. 断点 3 收窄，同意拆开。 21:54:42 那次 forward 是 estimate 级基线（nudge 782,170/792,576、无 trigger 行）成立；但 21:54:45 读到的是 arm 值 792,576 + k̂。同一轮两处读数不同（782,170 vs 792,576）说明「重建路径把权威基线覆盖成 estimate」不是全部故事——我把它降级为待验证假设，等完整 round 日志再下结论。
4. 新增子缺陷，并入本 issue 清单（同症状不拆单）： 21:54:46→21:59:05 的折叠吞吐塌缩——260s 只完成 3/99 个区间、客户端断开中止；且「~0 tokens saved」与括号内实际自估降幅 37,540 矛盾（保存量记账/日志缺陷，独立小点）。主因判断：每区间一次 summarize 上游调用，吞吐受上游延迟约束（事故里约 80s/次量级），bili 侧能做的是让校准口径减少需要的折叠深度（这正是本次修复的一部分）。
5. 请补切片： 那四轮 preflight 的完整 round 日志（尤其 21:54:46 那轮的 28 个 round 行）——用来定位 ~0 收益轮次是震荡/视图抖动还是纯 summarize 慢，决定要不要在 bili 侧加「无进展区间快速跳过」。
6. 恢复数据点已记录（max_tokens 32,768 + 解封原生压缩 → 22:49 快照本地应答、cache hit 100%、nudge 17%）——与「降预留/提前压缩」方向一致。
修复进行中（方向你已认同）：首次 overflow 即保留 clamp(stated/local-est, [0.25,4]) 的临时偏置，按 origin+model 门控应用到触发判定/折叠停止/输出钳制（含 overflow-arm 下的比较器），直到环发布取代它——把「太晚」压缩到第一次 400 之后立即生效。复现测试遇到一个有意思的现象：静态语料下未修复代码会靠「折到耗尽」自愈，必须造出与事故同构的基线降级场景才能钉住永久循环——正在用带仪表的场景扫描锁定参数域，锁定后回报。
Leon-dbh commentedon Oct 31, 2026
第四次 preflight（k̂=1.25 之后那次）的完整 round 日志
按你们的要求切出来了，见附件
bili-preflight-round4-2026-10-31.log（197 行，2026-10-31 21:54:46.879–21:59:06.276，lanesub:67c7fac0eb516238；只删了每行重复的[sess=…] [v=0.1.209] [session-…|sub:…]前缀，其余原样）。下面是一轮表和三个数字对不上的地方。轮次表
观察 1：round 2 的 payload 不降反升，而同一时刻 postCtx 在降
折叠把 postCtx 从 656,308 降了 12,430，但下一轮 payload 反而比上一轮高 42,123。两个口径在这一步是反向的。
观察 2：三轮折叠都"省了"~12k，round 侧的 deficit 却从 120,753 涨到 136,388
913329.2691087177 → 875788.6967605876，即 −37,540，却被标记为~0 tokens saved同一个过程有四个"省了多少"的数字（36,225 / 23,795 / 37,540 / −15,635），这也是我们之前说"可观测性互相矛盾"的具体形态。
观察 3：payload 与 postCtx 的差值在漂
差值从 257,021（round 1 vs fold 1 的 postCtx）漂到 296,451，而且在缩小。如果差值应恒定（例如固定 overhead），这里就不成立；如果差值应随折叠增长（摘要/块表进上下文），方向又相反。
观察 4：第 4 轮折叠根本没发出去，210 秒空等
前三次折叠从 round 行到
compress requested分别隔 22.0s / 3.1s / 16.4s；第 4 轮在 21:55:33 之后再没有发起过折叠。也就是说 260,566ms 里有 210 秒（81%） 花在第 4 轮折叠的准备/渲染上。顺带：被折（或待折）的区间里有三次出现 "rendered nothing" 的 part（m03282:m03349 16 个、m00468:m00492 3 个、m00029:m00068 1 个），但前两次仍按 ~12k 记账。
观察 5：客户端看到的是"模型已经开始回复"
825 字节就是这 261 秒里写回客户端的全部内容（SSE 头和 keep-alive）；客户端在 4 分 21 秒后断开，bili 才在 21:59:05 记
preflight aborted … not forwarding，而那条← upstream 400（request_id217bbff1-…，1,178,919 = 922,919 + 256,000）是 21:54:42 那次 forward 迟到的响应体。对定向复现的两条建议断言
round N+1 payload ≤ round N payload − 本轮 fold 写入量。本次 round 2 违反了（+42,123），且 round 1→4 净增 15,635。round payload − 折叠后 postCtx在折叠前后应保持同一常量；本次从 257,021 漂到 296,451。需要 21:41–21:54 那三段 preflight 的完整 round 日志（含两次
preflight aborted … not forwarding的细节）也可以再切。bili-preflight-round4-2026-10-31.log
ranxianglei commentedon Oct 31, 2026
(ai: vllm-qwen/qwen3.8-27b)
修复完成，PR：https://github.com/ranxianglei/billion-context/pull/5382（Closes #5373）。
先直接回应你切出来的两条断言：都成立，且都已钉死机制。
Math.max(0, start−current)，视图漂移让表涨过起点后被 max 钳到 0。本 PR 已把这行日志改成引用自己的两个端点（表字段本身不动，auto-fold sharp edges: a sub-floorautoFoldTargetTokenscauses a fold storm, andexternalSummary.*file edits do not take effect until aPUT /__bili/config#3444 backoff 门控还在用它）。BILI_UPSTREAM_TIMEOUT_MS，默认 12 分钟、每来一个 chunk 重新武装）——也就是说如果客户端不断开，bili 会在一个卡死的 summarize 上等满约 12 分钟。而代码里有明确设计注释禁止在这里加更短的 fetch 定时器（保护本地模型多分钟 prefill），所以这项不能靠「加个超时」修，需要别的机制（如整个 preflight 的墙钟预算），涉及设计取舍——列为待办，不擅自做。八问：
clamp(stated/local-est, [0.25, 4])保留为该路由+模型上的 provisional bias（持久化、恢复时逐字段校验），该路由所有本地判定经统一入口选因子：ring k̂（适用于本路由时）优先，否则用 provisional bias，否则维持 raw。armed 比较器在因子生效时按 est×k̂ ≤ budget 停折。代数上等价于你提的 target≈640,800。边界保护：stated/local-est 超出 [0.25,4] 带说明声明计数描述的是 bili 不持有的载荷（[Bug][dsh native] preflight fold target sits ABOVE the engine's own denominator (1048576 vs 1000000) and the upstream-stated window from a 400 never feeds it — 'deficit 0' forwards an over-window payload → context_length_exceeded kills the turn #3450 形态），标记 mismatched 不用于导向，保留 master 的 burn-and-net 行为（e2e [Bug][dsh native] preflight fold target sits ABOVE the engine's own denominator (1048576 vs 1000000) and the upstream-stated window from a 400 never feeds it — 'deficit 0' forwards an over-window payload → context_length_exceeded kills the turn #3450 T1 继续通过验证了这一点）。行为变更披露（旧 → 新）：
待办（记在本 issue，暂不单开）：
收工判定：本 issue 主缺陷闭环（PR #5382，等 CI + review）；上面三项是已知开放项，建议先定第 2 项的方向，它决定这类事故的最坏等待时长。
Leon-dbh commentedon Nov 1, 2026
来补充了
bili-preflight-2141-2026-10-31.log
bili-preflight-2144-2026-10-31.log
bili-preflight-2147-2026-10-31.log
ranxianglei commentedon Nov 1, 2026
(ai: vllm-qwen/qwen3.8-27b)
三段都拿到了，和 round-4 段拼起来逐轮核过。结论先行：「四个省了多少」的口径问题已全部钉死；单调性反例定位到了确切发生位置（只出现在一种特定情形）；口径漂移大部分可解释。逐项说：
① 「四个数字」= 四个不同口径（已钉死）
estimateCoreMessages(客户端全量重发数组)，含已被折叠覆盖的原始消息（折叠只存在于 bili 内部状态里，客户端每回合仍重发全部历史）Math.max(0, start−current)，视图漂移涨过起点时被钳 0关键证据：cycle 2 的 entry=1,367,515 而 round 1=958,873，差 408,642 ≈ cycle 1 累计折叠 339,724 + 视图churn——即 entry 口径把 cycle 1 折掉的内容又数了一遍（它按客户端重发的原始数组算，这是预算放大的保守设计，不是 bug）。同一行日志流里混着这两个口径才是「互相矛盾」的来源。
② 单调性：跳变只发生在「refold 的第一次轮间过渡」
四段拼起来逐轮差分（Δ = 下轮 payload − 本轮 payload，对照本轮 fold 量）：
即：两个 refold 都在第一轮折叠后的重新渲染里一次性涨了 54k/91k（净 +42k/+71k），普通 preflight 从不发生。分解上，cycle 2 r2 的 1,029,881 ≈ 折叠后 nudge 列出的 48 个可折 range 之和 ~825K + anchor 16.8K + system/tools 等视图外项 ~180K——也就是 r1 时还不可见的若干 range 在 r2 重新进入了渲染视图。
机制候选（按证据排序）：
区分两者需要内核侧「每次 reconcile 哪些块的声明丢失/新增」的日志——那是
kernel/变更，人工门禁。我可以先在你这套 harness 形状上试 hermetic 复现（复现出来就能本地二分到具体节点；复现不出就说明还有 dsh 客户端特有的重发行为参与），要我做的话说一声。③ 口径稳定性：恒定性本来就不成立，但漂移大部分可解释
payload 与 postCtx 是构造上不同的量：payload 不含 system+tools（它们不在 turn.messages 里），postCtx 是 V 基内核总量——所以「差值应恒定」这个前提不成立。可解释的部分：cycle 1 正确配对（round N 对 fold N−1 后的 postCtx）后差值 37,950→54,346 平滑增长 ~1.5k/轮，与 anchor 增长 496→15,451（11 折 ≈1.4k/轮）同步——即每新增一个块，wire 视图多带一份块表/tag 开销。你的表里 round N 配的是 fold N 之后的 postCtx（off-by-one 反向），放大了观感漂移。结论：漂移本身不是缺陷，但两种口径并排打印却不标注口径是观测缺陷——建议后续在日志行加口径标记（这可以并进 #5382 或单开小修，你定）。
对修复的影响
无。#5382 的校准停折判据用的就是 round 级同一口径；跳变只会让救援多干一轮活，不会阻止退出条件触发。
待办更新：① 从「未钉死」改为「口径图完成、跳变定位到 refold 首轮过渡、机制候选已排序，待内核侧插桩/hermetic 复现区分」；② summarize 零响应挂起的墙钟上界仍需设计决策；③ rendered-nothing 记账降级评估不变。
ranxianglei commentedon Nov 1, 2026
(ai: vllm-qwen/qwen3.8-27b)
本地跑了两个受控实验（直驱内核、单变量对照），排除了两个候选机制：
这把领先候选收窄到两个：
|sub:），其块声明针对父会话历史建立，而客户端每回合重发形状都在变（4,901→3,744→3,537→2,700 条）；每次 reshape 后第一次折叠触发一次性 resync，失配 span 重新进 wire。我的受控实验用的是「活建块 + 稳定数组」的简单情形，恰好覆盖不到这条；区分这两者需要其一：(i) 你提供 dsh desktop 的 billion-context 配置（compress/crush/absorb/messageFilters 几段即可），我按同配置复现；(ii) 内核侧加「每次 reconcile 块声明增减」的 debug 日志——那是 kernel/ 变更，人工门禁，需要你点头。待办①更新为「候选机制已收窄至上述两条，等配置或插桩授权」。
Leon-dbh commentedon Nov 1, 2026
配置补充项
bili-config-dsh-desktop-2026-11-01.md