Skip to content

fix(cli): measure token speed from the first chunk and trim the toolbar - #386

Merged
frostming merged 1 commit into
mainfrom
fix/token-speed-excludes-ttft
Oct 26, 2026
Merged

frostming merged 1 commit into
mainfrom
fix/token-speed-excludes-ttft

Conversation

@frostming

Copy link
Copy Markdown
Contributor

What changed and why

The CLI toolbar reported token speed as output_tokens / whole model call. That denominator carried TCP setup, queueing, prefill and time-to-first-token, so the number read like a stalled model rather than a decode rate — badly so for thinking models, which emit nothing for many seconds while tokens accumulate in the numerator. On a reasoning_effort=max run the toolbar could show single digits while the model was actually decoding at normal speed.

Two changes:

  1. Start the speed clock at the first streamed chunk. The excluded span is reported separately instead of being silently folded in.
  2. Trim the bottom toolbar while the area was already being touched.

Speed measurement

usage events now carry three timings, so nothing is lost by narrowing the speed denominator:

field meaning
elapsed_seconds first chunk → end of response. This is the new speed denominator.
ttft_seconds request start → first chunk, or None when the call never streamed one.
total_seconds request start → end of response, unchanged in meaning.

The numerator is unchanged: output_tokens still counts every generated token, reasoning included, matching what providers bill and what tracing already reports. A call that never streams a chunk (e.g. usage-only responses) has nothing to measure, so it falls back to timing the whole call rather than reporting a fabricated speed.

First chunk is the first text or reasoning stream event. tool_call is deliberately excluded: Republic releases ToolCallReady only when the response ends, so it would measure a near-empty span for a call that streamed its arguments all along. Refusals fold into text upstream.

Toolbar

Before: thinking:collapse speed:42.1 token/s model:... entries:12 anchors:3 last:session/start
After: speed:42.1 tok/s ttft:2.5s model:... entries:12 last:session/start

  • thinking dropped — the state is already toggled and reported by the ,thinking command.
  • anchors dropped — visible via bub tape info, which shows entries, anchors, and last anchor together.
  • token/s shortened to tok/s.
  • ttft added, shown only when the provider actually streamed a chunk.

Impacted modules

  • src/bub/core/agent.py — run_once usage event, new FIRST_CHUNK_KINDS
  • src/bub/channels/cli/__init__.py — _update_token_speed, _render_bottom_toolbar, _is_positive_number helper
  • website/src/content/docs/{docs,zh-cn/docs}/operate/channels/cli.mdx — both locales updated

Backward compatibility

elapsed_seconds keeps its name but narrows in meaning; total_seconds is the field to read for full call duration. The only in-repo consumer is the CLI toolbar. Any external consumer of the usage stream event that divides tokens by elapsed_seconds will get a higher (and more meaningful) number.

Verification

  • uv run pytest -q → 700 passed, 20 skipped
  • uv run ruff check src/ tests/ → clean
  • uv run mypy src → clean (76 files)
  • New tests: test_streaming_measures_generation_time_without_time_to_first_chunk, test_streaming_without_any_chunk_times_the_whole_call, test_cli_toolbar_shows_time_to_first_token
  • Updated: test_cli_toolbar_shows_latest_call_token_speed (unchanged assertions, new unit)

Docs build not run; the mdx edits are prose-only.

The CLI reported output tokens divided by the whole model call, so the
denominator carried request latency and prefill. Thinking models emit
nothing for many seconds, which made the number read like a stalled
model rather than a decode rate.

Start the clock at the first streamed chunk instead. The excluded time
is now reported separately as `ttft_seconds`, alongside `total_seconds`,
so the full call duration stays observable without polluting the speed.
A call that never streams a chunk falls back to timing the whole call.

Trim the bottom toolbar while touching it: drop `thinking` and `anchors`,
which are already reachable through `,thinking` and `bub tape info`, and
shorten the unit to `tok/s`.
@frostming
frostming merged commit c14941a into main Oct 26, 2026
7 checks passed
@frostming
frostming deleted the fix/token-speed-excludes-ttft branch October 26, 2026 12:53
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant