Repository navigation
fix(cli): measure token speed from the first chunk and trim the toolbar - #386
Merged
Merged
Conversation
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`.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
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 areasoning_effort=maxrun the toolbar could show single digits while the model was actually decoding at normal speed.Two changes:
Speed measurement
usageevents now carry three timings, so nothing is lost by narrowing the speed denominator:elapsed_secondsttft_secondsNonewhen the call never streamed one.total_secondsThe numerator is unchanged:
output_tokensstill 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
textorreasoningstream event.tool_callis deliberately excluded: Republic releasesToolCallReadyonly when the response ends, so it would measure a near-empty span for a call that streamed its arguments all along. Refusals fold intotextupstream.Toolbar
Before:
thinking:collapse speed:42.1 token/s model:... entries:12 anchors:3 last:session/startAfter:
speed:42.1 tok/s ttft:2.5s model:... entries:12 last:session/startthinkingdropped — the state is already toggled and reported by the,thinkingcommand.anchorsdropped — visible viabub tape info, which shows entries, anchors, and last anchor together.token/sshortened totok/s.ttftadded, shown only when the provider actually streamed a chunk.Impacted modules
src/bub/core/agent.py—run_onceusage event, newFIRST_CHUNK_KINDSsrc/bub/channels/cli/__init__.py—_update_token_speed,_render_bottom_toolbar,_is_positive_numberhelperwebsite/src/content/docs/{docs,zh-cn/docs}/operate/channels/cli.mdx— both locales updatedBackward compatibility
elapsed_secondskeeps its name but narrows in meaning;total_secondsis the field to read for full call duration. The only in-repo consumer is the CLI toolbar. Any external consumer of theusagestream event that divides tokens byelapsed_secondswill get a higher (and more meaningful) number.Verification
uv run pytest -q→ 700 passed, 20 skippeduv run ruff check src/ tests/→ cleanuv run mypy src→ clean (76 files)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_tokentest_cli_toolbar_shows_latest_call_token_speed(unchanged assertions, new unit)Docs build not run; the mdx edits are prose-only.