A thinking block that says how long and how much

Each block reports its own round now. `reasoning_ms` was the reply's first
burst, written once, so on the fifteen-block reply GPT-OSS actually produces
only the first could claim a duration and the other fourteen said "Thought" and
nothing at all. `Generation.thinking_ms` accumulates per round and `close_step`
stamps it cumulatively, so steps.py diffs it exactly as it already diffs the
three lengths beside it.

The interval between a round's first and last reasoning delta, deliberately, not
a sum of gaps between deltas -- that would count the network's latency as the
model's thinking.

While it runs: "Thinking" with an ellipsis that types itself, and the seconds
and tokens climbing beside it. The ellipsis is a `content` keyframe, so there is
no timer to start, stop or clean up when the block is swapped away -- it stops
existing when the element does. The numbers come from a `think` frame, and
`round_thinking_ms` is written by the producer rather than computed by the
follower from a start time: a model that has stopped thinking and moved on to a
tool should show a settled number, not a clock that keeps running.

Tokens read exactly up to 200 and as `0.4k` above it, from one helper shared by
the live label and the stored one, so the two cannot drift into two conventions.
The live duration is terser than the finished one -- `6s` against `6 seconds` --
because it sits beside an animating word and changes every second, where "less
than a second" flickering into "1 second" reads as a glitch.

Checked against the real endpoint: fourteen marks carrying 919ms through
14223ms, per-block labels from "less than a second · 111" to "4 seconds · 0.5k",
and the live frames resetting each round rather than accumulating.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
Jaroslav Beneš
2026-08-04 21:03:25 +02:00
parent 74dd19588b
commit 30ddcba787
9 changed files with 385 additions and 10 deletions
+21
View File
@@ -1044,3 +1044,24 @@ def test_the_composer_form_answers_only_its_own_request():
assert "event.target === this" in handler.group(1), (
"a descendant's request will run this handler without the guard"
)
def test_the_think_frame_lands_beside_the_reasoning_body_not_around_it():
"""The live block has two swap targets inside one static `<details>` -- the
label and the body. Two siblings is fine; one inside the other is what
blanked every agent chat, because the outer swap tears out the inner
element while the frames aimed at it are still arriving."""
from pathlib import Path
import lembas
source = (
Path(lembas.__file__).parent / "web/templates/chat/_message.html"
).read_text()
label = source.index('sse-swap="think"')
body = source.index('sse-swap="reasoning"')
between = source[min(label, body) : max(label, body)]
# Neither element may open a tag that the other closes: siblings, not nested.
assert "</span>" in between or "</div>" in between
assert between.count("<div") <= 1
+65
View File
@@ -613,3 +613,68 @@ async def test_a_reply_that_calls_nothing_writes_no_marks(db, user_id, monkeypat
message = db.get(Message, message_id)
db.refresh(message)
assert message.steps_json == []
async def test_thinking_time_is_recorded_per_round(db, user_id, monkeypatch):
"""Each thinking block reports its own round. `reasoning_ms` is the reply's
*first* burst and is written once, so it could never say how long round
seven thought for -- every block but the first said "Thought" and nothing.
"""
import asyncio as _asyncio
from lembas.db.models import Message
settings_store.update(db, {"enabled": True}, key=settings_store.SEARCH)
chat_id, message_id = _chat_with_tools(db, user_id)
monkeypatch.setattr("lembas.services.search.run", _empty_search)
async def slow_stream(_endpoint, payload):
"""Two rounds, each thinking for a measurable moment."""
yield {"choices": [{"delta": {"reasoning_content": "mulling it over"}}]}
await _asyncio.sleep(0.05)
yield {"choices": [{"delta": {"reasoning_content": " some more"}}]}
if len([m for m in payload["messages"] if m.get("role") == "tool"]) == 0:
yield _tool_call_chunk("web_search", '{"query": "x"}')
else:
yield _text_chunk("Done.")
monkeypatch.setattr(generation_service, "stream_chat", slow_stream)
monkeypatch.setattr("lembas.services.chat.generate_title", _never_called_title)
generation = generation_service.Generation(chat_id=chat_id, message_id=message_id)
await generation_service._run(generation)
assert generation.thinking_ms > 0, "the reply spent time thinking"
assert generation.steps, "and closed a step"
assert generation.steps[0]["thinking_ms"] > 0, "stamped on the mark"
# Cumulative on the mark, so a block's own duration is the difference --
# the same rule the three lengths beside it follow.
assert generation.steps[0]["thinking_ms"] <= generation.thinking_ms
db.expire_all()
stored = db.get(Message, message_id)
assert stored.reasoning_ms == generation.thinking_ms, (
"the row keeps the summed figure, not the first burst"
)
async def test_the_round_clock_settles_when_thinking_stops(db, user_id, monkeypatch):
"""`round_thinking_ms` is written by the producer, not computed from a start
time by the follower -- a model that has stopped thinking and moved on to a
tool should show a settled number rather than a clock that keeps running."""
settings_store.update(db, {"enabled": True}, key=settings_store.SEARCH)
chat_id, message_id = _chat_with_tools(db, user_id)
monkeypatch.setattr("lembas.services.search.run", _empty_search)
monkeypatch.setattr(
generation_service,
"stream_chat",
_stub_stream([[_text_chunk("No thinking at all.")]], []),
)
monkeypatch.setattr("lembas.services.chat.generate_title", _never_called_title)
generation = generation_service.Generation(chat_id=chat_id, message_id=message_id)
await generation_service._run(generation)
assert generation.round_thinking_ms == 0
assert generation.thinking_ms == 0
+61
View File
@@ -346,3 +346,64 @@ def _live_steps(generation):
events=list(generation.tool_events),
marks=list(generation.steps),
)
# --- What a thinking block says about itself ----------------------------------
def test_a_token_count_stays_exact_until_the_digits_stop_meaning_anything():
assert steps.format_tokens(0) == ""
assert steps.format_tokens(86) == "86"
assert steps.format_tokens(200) == "200"
assert steps.format_tokens(201) == "0.2k"
assert steps.format_tokens(1500) == "1.5k"
def test_the_live_label_is_terser_than_the_finished_one():
"""It sits beside an animating word and changes every second. "less than a
second" flickering into "1 second" reads as a glitch, not a measurement."""
assert steps.thinking_label(ms=6000, tokens=400, live=True) == "6s · 0.4k"
assert steps.thinking_label(ms=6000, tokens=400, live=False) == "6 seconds · 0.4k"
assert steps.thinking_label(ms=64000, tokens=0, live=True) == "1m 04s"
def test_a_block_with_nothing_to_report_says_nothing():
"""Rather than "Thought for 0 seconds", which is worse than the bare word."""
assert steps.thinking_label(ms=0, tokens=0, live=False) == ""
assert steps.thinking_label(ms=0, tokens=0, live=True) == ""
def test_each_block_reports_its_own_round_not_the_reply():
"""The whole point of the per-round timing. It used to read the reply's
total, so only the first block could honestly claim it and every other one
said "Thought" and nothing else."""
built = steps.for_message(
_message(
reasoning="a" * 400 + "b" * 800,
events=[{"name": "x"}],
marks=[
{"round": 1, "thinking_to": 400, "text_to": 0, "tools_to": 1, "thinking_ms": 4000}
],
ms=9000,
)
)
labels = [s.label for s in built if s.kind == "thinking"]
assert labels[0].startswith("4 seconds")
# The last round closes no mark -- it is the one that stopped calling
# tools -- so its duration is whatever the reply spent beyond the last mark.
assert labels[1].startswith("5 seconds")
def test_a_row_with_no_per_round_timing_falls_back_to_the_reply():
"""Every reply written before the marks carried a duration. One block, and
the reply's own figure is exactly right for it."""
built = steps.for_message(_message(reasoning="a" * 400, ms=3000))
assert built[0].label.startswith("3 seconds")
def test_a_running_block_carries_no_label_of_its_own():
"""The live one is fed by the `think` frame, which knows the clock. Baking a
stale number into the markup would be a number that never moved."""
generation = _generation(reasoning=["still thinking"])
assert [s.label for s in _live_steps(generation)] == [""]