fix: include hidden thinking in TPS timing

[SaladDay]

Change

The TUI can show thousands of TPS when a provider hides thinking text. The reported case showed 1,389 tok/s with a model configured as claude-opus-5-5.

outputTokens includes thinking tokens, but the timer previously waited for a non-empty thinking or text delta. When thinking was hidden, it divided all output tokens by only the short final-answer interval.

Start the timer at the first thinking_start, using its original observedAtMs. Keep the existing fallback for other streams, message reset, and tool-time exclusion. The UI still shows TPS. No model-specific rules, caps, or estimated token counts are added.

References:

• GuideLLM #742 includes reasoning events in first-token timing.
• pi-token-speed starts timing on thinking_start.

These support the timing boundary; this PR does not copy either project's full algorithm.

Evidence

Two real mcode requests used a synthetic arithmetic prompt, one per MiniMax model. Each captured stream was replayed through the original and patched EventBridge. The hidden replay removed only thinking deltas and kept thinking_start, text events, original timestamps, and the provider's output token count.

Model	Output tokens (thinking)	Original: visible / hidden TPS	Patched: visible / hidden TPS
MiniMax-M3.1-Flash-Preview	204 (203)	146.73 / 1,693.95	146.65 / 146.65
MiniMax-M3	926 (868)	214.99 / 2,868.08	214.96 / 214.96

Earlier real Claude-compatible requests also reproduced the failure. These rows compare both algorithms on the same captured request, not two separate speed benchmarks:

Thinking display	Output tokens	Original duration → patched duration	Original → patched TPS
summarized	344	2,184.968 → 4,441.292 ms	157.44 → 77.45
omitted	284	13.286 → 3,141.477 ms	21,376.55 → 90.40

Timing data for the MiniMax replays

Milliseconds are relative to the client capture start. TPS = output tokens × 1,000 / duration. The original visible replay starts at first_delta_ms; the original hidden replay starts at first_text_ms. Both patched replays start at thinking_start_ms. All end at message_stop_ms.

model,output_tokens,thinking_start_ms,first_delta_ms,first_text_ms,last_delta_ms,message_stop_ms
MiniMax-M3.1-Flash-Preview,204,3.659292,4.488750,1274.339000,1274.339000,1394.767250
MiniMax-M3,926,2.007750,2.500625,3986.876750,4188.882708,4309.741208

The prompt asked for the smallest positive integer satisfying n % 7 = 3, n % 11 = 5, and n % 13 = 7, with no tools and only the answer returned.

Limits: these are client-side observations and event replays, not server generation timings or a test of Claude Code internals. The MiniMax hidden cases simulate suppression of thinking deltas; they do not establish how those servers implement native hidden thinking. Each model has only one sample. The final frame arrived about 120 ms after the last content delta in both MiniMax samples; that existing tail remains included. Fully buffered streams without an early thinking event remain outside this fix. The original screenshot has no matching trace, so its exact cause is unconfirmed.

Validation

• Focused timing and TUI stream tests: 22 passed.
• Capability tests: 5,161 passed, 17 skipped.
• Type checking, build, source inventory, build boundary, and CLI smoke tests passed during development.
• Independent code review and experiment review completed with no blocking findings.
• pnpm verify on 911e34b: all 15 applicable gates passed on macOS arm64, Node 22.23.2 (full profile). Windows and release-package gates were not applicable.
• Performance: perf:full; the CI result is required before merge.
• NOT RUN: live interactive TUI acceptance and Linux/Windows local checks.

Publication and contribution checks

• Changes use the existing licenses; references are linked and existing notices are preserved.
• No credentials, account data, raw session logs, private source history, or real user prompt content is included.
• Only existing source and test files changed; no inventory or test registration changes are needed.
• No shared documentation change is needed. Live requests and offline replay results are distinguished above.

Maintainer handoff

Publication scope and licenses: unchanged. Shared-source port: pending.

---

^{Need help on this PR? Tag @codesmith-bot with what you need. Autofix is disabled.}

[hetaoBackend]

Reviewed the timing change and its consumers. LGTM overall: one nit inline and one non-blocking follow-up.

What I checked:

• Every pi provider that emits thinking_start does so when a real reasoning block opens: Anthropic thinking/redacted_thinking content_block_start, the Responses reasoning item, and Completions, Bedrock, Google, and Mistral on the first reasoning content. None synthesizes it early enough to pull prefill or queue wait into the decode window.
• observedAtMs is captured in pi-turn-runner/events.ts before the serialized queue, and later events wait for message id allocation. The activeAssistantMessageId guard therefore does not drop the normal thinking_start.
• The only consumers of decode_duration_ms (TUI TuiTurnOutputRate and local-runtime-v2 content application) divide provider output tokens by it, so moving the start boundary earlier is the right fix at this layer.
• Locally, restoring bridge.ts from main makes 4 of the new tests fail (expected 20 to be 3000 / 60000). All 11 pass on this branch.

Non-blocking follow-up: OpenAI Chat Completions-style endpoints that hide reasoning entirely never emit thinking_start, while completion_tokens already includes reasoning_tokens (openai-completions.ts L1036-1037). TPS on that path stays inflated. The description covers this in general terms ("fully buffered streams without an early thinking event"); a tracking issue naming this path would make it easier to pick up later.

[hetaoBackend]

Nit: the field doc for firstTokenMs (L167) still reads "First nonempty text/thinking/tool token". The boundary can now also be the first thinking_start, so please update it too, for example: First thinking_start or nonempty text/thinking/tool token; excludes first-token wait from throughput. Otherwise a later reader may fold this block back into the nonempty-delta check below and reintroduce the bug.

[hetaoBackend]

Addressed in 4bff012: updated the firstTokenMs field doc to mention thinking_start.

[hetaoBackend]

Pushed d6ff1ed, unrelated to the TPS change: verify (windows-latest) failed on 4bff012 because test/windows-contract.test.mjs > "accepts the Windows checkout on a local NTFS volume" took 6082 ms against Vitest's 5000 ms default. The check spawns PowerShell for a CIM query with its own 15 s timeout, so the test now has a 30 s budget. main hit the same test on 2026-09-28 (run 36450570911, 15067 ms).