vh/ratatoskr
1
0
Fork 0
Code Issues 4 Pull Requests Actions Packages Projects Releases Wiki Activity

feat(sse,tui): bump spec pin to v0.29.0 + AwaitingLlmFirstToken (v0.14.0)

Browse Source 
Spec pin moved da93ca7 (v0.28.0) → 562001a (v0.29.0); vendored
conversation-api-spec.md + conversation_api.contract.md re-snapshotted.
The only material delta is Worldtree #201's awaiting_llm_first_token
SSE heartbeat — a top-level event (NOT a worker_phase extension, per
INV-053's three-field stability) that fires at a configurable interval
(default 5s) during the BuildingPrompt → CallingLLM gap.

Wire layer (sse_client.py):
- New `AwaitingLlmFirstToken` dataclass: sse_id / turn_id /
  elapsed_ms_since_building_prompt (server-authoritative monotonic)
- Added to Event union + _envelope_for_type dispatch branch
- Without this, ratatoskr would crash on any slow-first-token turn
  from a v0.29.0 server (unknown SSE event type → ValueError)

TUI layer (tui.py):
- Audit pipeline: per-event debug-pane line with elapsed in seconds
- Live transcript indicator: first heartbeat mounts a Static
  ("awaiting first token · 5.0s"); subsequent heartbeats update it
  in place; any non-heartbeat event removes it (the gap closed)
- Turn-summary line now carries heartbeat count
- Indicator demoted via .awaiting-label CSS so it reads as ambient
  progress, not content

Tests: 2 wire-layer (single + monotonic sequence) + 3 presenter
(audit line shape, single-mount semantic, indicator removal on gap
close). Suite: 318 passing.
This commit is contained in:
Vuong Hoang
2026-05-25 22:57:33 -07:00
parent 44138590ad
commit 78bfcadb9e
9 changed files with 363 additions and 11 deletions
Download Patch File Download Diff File Expand all files Collapse all files
docs/SPEC-PIN.md
+7 -6
View File
@@ -7,17 +7,18 @@ documents the pin, the vendored artifacts, and the bump procedure.
| Field | Value |
|---|---|
| Worldtree git SHA | `da93ca7cf613f1dc229a7a44d07fc1d7efc78e25` |
| Worldtree HEAD message | `feat(#204): v0.28.0 — persona-state observability surface` |
| Pinned on | 2026-05-25 |
| Pinned by | ratatoskr-dev (bump for #204 affect_update SSE) |
| Worldtree version at pin | `v0.28.0` |
| Worldtree git SHA | `562001af28d752c3a60d449c7ddd09f44fa9dc9a` |
| Worldtree HEAD message | `feat(#201): v0.29.0 — awaiting_llm_first_token SSE heartbeat` |
| Pinned on | 2026-05-26 |
| Pinned by | ratatoskr-dev (bump for #201 awaiting_llm_first_token SSE) |
| Worldtree version at pin | `v0.29.0` |
## Pin history
| Date | SHA | Version | Notable deltas consumed |
|---|---|---|---|
| 2026-05-25 | `da93ca7` | v0.28.0 | #204 — new SSE event `affect_update` (current/scheduled), new endpoint `GET /agents/{id}/persona_state` (not yet consumed), auth-model doc edits |
| 2026-05-26 | `562001a` | v0.29.0 | #201 — new SSE event `awaiting_llm_first_token` (heartbeat during BuildingPrompt → CallingLLM gap, default 5s interval) |
| 2026-05-25 | `da93ca7` | v0.28.0 | #204 — new SSE event `affect_update` (current/scheduled), new endpoint `GET /agents/{id}/persona_state`, auth-model doc edits |
| 2026-05-20 | `55101e9` | v0.19.0 | initial scaffold pin |
## Vendored artifacts
docs/conversation-api-spec.md
+20
View File
@@ -1980,6 +1980,26 @@ Emitted after the post-turn appraisal task has been scheduled (per #177 Phase A'
Bootstrap reads available via `GET /agents/{agent_id}/persona_state` (same `snapshot` shape, requires `persona.read` scope).
### awaiting_llm_first_token
Periodic heartbeat event (issue #201) emitted at a configurable interval during the gap between `worker_phase: phase="BuildingPrompt"` and `worker_phase: phase="CallingLLM"`. Solves the legitimate-slow first-token visibility gap: consumer TUIs can render a "thinking for Ns…" timer rather than a frozen line during heavy-CoT prompt warmup.
```json
{
"type": "awaiting_llm_first_token",
"turn_id": 42,
"elapsed_ms_since_building_prompt": 5012.3
}
```
`elapsed_ms_since_building_prompt` is the server-authoritative wall-clock milliseconds since `BuildingPrompt` was emitted. Independent of network latency or clock skew.
Heartbeats stop the moment the engine produces its first event (the `CallingLLM` marker). They do NOT re-fire during tool-roundtrip `CallingLLM` re-entries — the heartbeat is scoped to the FIRST `BuildingPrompt → CallingLLM` gap only.
**Configuration:** `conversation_api.awaiting_llm_first_token_heartbeat_s` (default `5.0`). Per-agent override via `agent.conversation.awaiting_llm_first_token_heartbeat_s`. Value `0.0` disables emission entirely.
Cancellation paths (stall watchdog, user-cancel) also stop the heartbeat — no `awaiting_llm_first_token` event appears after the terminal `cancelled` event.
### thinking
Incremental reasoning/thinking content (from thinking-enabled models).
docs/conversation_api.contract.md
+67
View File
@@ -1881,6 +1881,73 @@ SQLite `consumer_agents` table.
through `_publish`, so SSE resume / replay handles them with no
special case.
## Amendment — AwaitingLLMFirstToken heartbeat (issue #201, INV-201-1..7)
Adds a periodic SSE heartbeat event during the gap between
`BuildingPrompt` and `CallingLLM` so consumers can distinguish
"engine is thinking" from "engine is wedged" without out-of-band
server inspection. Filed by ratatoskr-dev; ships in v0.29.0.
- **INV-201-1 (new top-level event type)**: `awaiting_llm_first_token`
is a new top-level SSE event type, sibling to `worker_phase` /
`tool_*` / `text` / `thinking` / `debug` / `done` / `affect_update`.
`_WORKER_PHASE_VOCAB` is NOT extended; INV-053 / INV-054 unchanged.
Same precedent as #204's `affect_update`.
- **INV-201-2 (config-gated emission)**: Heartbeat emission requires
`awaiting_llm_first_token_heartbeat_s > 0.0`. When the resolved
value is `0.0`, the heartbeat task is never started and zero
`awaiting_llm_first_token` events emit for the turn. When > 0.0,
the task starts immediately after `_publish_phase("BuildingPrompt")`
and emits an event every `interval` seconds until cancelled.
- **INV-201-3 (defense-in-depth cancellation)**: The heartbeat task
is cancelled at three sites (idempotent via the `_cancel_heartbeat`
helper): (a) immediately before `_publish_phase("CallingLLM")` on
the engine-first-event path; (b) inside the `cancelled`/`error`
handling that wraps `_handle_cancel` (covers stall + user-cancel
paths); (c) in the outer `finally` block alongside
`_clear_stall_timer`. After cancellation, no further
`awaiting_llm_first_token` events emit.
- **INV-201-4 (wire shape)**: Payload is exactly `{type:
"awaiting_llm_first_token", turn_id: <int>,
elapsed_ms_since_building_prompt: <float>}` plus the composite `id:
"<turn_id>:<seq>"` stamped by `_publish`. No additional fields.
`elapsed_ms_since_building_prompt` is `(time.monotonic() -
building_prompt_t) * 1000.0` where `building_prompt_t` is captured
immediately before `BuildingPrompt` is published.
- **INV-201-5 (first-gap-only scope)**: Heartbeat is scoped to the
FIRST `BuildingPrompt → CallingLLM` gap of the turn. Tool round-trip
`CallingLLM` re-entries (INV-058) emit ZERO
`awaiting_llm_first_token` events. Out-of-scope sub-phases
(`AwaitingToolResult`, `AwaitingNextLLMCall`) would be separate
follow-up features.
- **INV-201-6 (replay participation)**: Heartbeat events flow through
`_publish → _replay_buffer + queue` per INV-060 — same replay
semantics as worker_phase events. On `Last-Event-ID` reconnect,
prior heartbeats replay identically.
- **INV-201-7 (config resolution precedence)**: Per-agent
`agent.conversation.awaiting_llm_first_token_heartbeat_s` →
`api_cfg.awaiting_llm_first_token_heartbeat_s` → built-in `5.0`.
Negative values raise `ConfigurationError` at agent load; `0.0`
is valid and means "disabled." Mirrors the `_resolve_stall_timeout_s`
precedence pattern (INV-038).
### Mechanism note
The heartbeat task is a separate `asyncio.Task` (NOT `loop.call_later`,
because heartbeats repeat at an interval rather than fire once at a
timeout). An `asyncio.Queue` shared between the heartbeat task and the
generator carries events; the generator uses
`asyncio.wait(return_when=FIRST_COMPLETED)` to race the engine's
`__anext__` against the heartbeat queue's `get` ONLY during the first
iteration. After `CallingLLM` fires, the heartbeat task is cancelled
and subsequent iterations use the original non-race pattern.
### Storage extension
The `consumer_agents` table lives in `core/heimdall/storage/sqlite.py`
pyproject.toml
+4 -4
View File
@@ -4,7 +4,7 @@ build-backend = "hatchling.build"
[project]
name = "ratatoskr"
version = "0.13.0"
version = "0.14.0"
description = "Worldtree Conversation API debug TUI — multi-pane observability dashboard"
readme = "README.md"
requires-python = ">=3.12"
@@ -42,9 +42,9 @@ Repository = "https://gitea.phasefinal.com/vh/ratatoskr"
# Ratatoskr is built against Worldtree at this commit; the vendored
# spec snapshot in docs/ reflects that SHA.
[tool.ratatoskr.spec-pin]
worldtree-spec-rev = "da93ca7cf613f1dc229a7a44d07fc1d7efc78e25"
worldtree-version = "v0.28.0"
pinned-on = "2026-05-25"
worldtree-spec-rev = "562001af28d752c3a60d449c7ddd09f44fa9dc9a"
worldtree-version = "v0.29.0"
pinned-on = "2026-05-26"
[tool.hatch.build.targets.wheel]
packages = ["src/ratatoskr"]
src/ratatoskr/sse_client.py
+35
View File
@@ -111,6 +111,31 @@ class Cancelled:
partial_message_id: int | None
@dataclass(frozen=True)
class AwaitingLlmFirstToken:
"""SSE event `awaiting_llm_first_token`: heartbeat during slow first-token.
Fires at the configured interval (default 5s) during the gap between
`worker_phase` phase=BuildingPrompt and phase=CallingLLM. Lets clients
render a live "thinking for Ns…" indicator instead of a frozen line
during legitimate-slow first-token latency. Stops the moment CallingLLM
fires (defense-in-depth at three sites); no heartbeat after Cancelled
or stalled terminal events. Tool round-trip re-entries do NOT re-fire
heartbeats — INV-201-5 scopes the mechanism to the FIRST gap only.
`elapsed_ms_since_building_prompt` is server-authoritative
`time.monotonic()`-based — independent of network latency or clock
skew, monotonically increasing across the heartbeat sequence.
See docs/conversation-api-spec.md § awaiting_llm_first_token
(Worldtree #201, v0.29.0).
"""
sse_id: SseId
turn_id: int
elapsed_ms_since_building_prompt: float
@dataclass(frozen=True)
class AffectUpdate:
"""SSE event `affect_update`: persona-state observability snapshot.
@@ -146,6 +171,7 @@ Event = (
| Error
| Cancelled
| AffectUpdate
| AwaitingLlmFirstToken
)
@@ -309,6 +335,15 @@ def _envelope_for_type(body: dict[str, Any], sse_id: SseId) -> Event:
reason=body.get("reason"),
partial_message_id=body.get("partial_message_id"),
)
if t == "awaiting_llm_first_token":
# Worldtree #201 / v0.29.0: top-level heartbeat during BuildingPrompt
# → CallingLLM gap. Lets clients render live elapsed-time indicators
# instead of frozen lines on legitimate-slow first-token latency.
return AwaitingLlmFirstToken(
sse_id=sse_id,
turn_id=body["turn_id"],
elapsed_ms_since_building_prompt=body["elapsed_ms_since_building_prompt"],
)
if t == "affect_update":
# Worldtree #204 / v0.28.0: persona-state observability event.
# status="current" carries full snapshot at turn start;
src/ratatoskr/tui.py
+55
View File
@@ -46,6 +46,7 @@ from ratatoskr.sessions import (
)
from ratatoskr.sse_client import (
AffectUpdate,
AwaitingLlmFirstToken,
CancelAlreadyCompleted,
CancelFailed,
Cancelled,
@@ -295,6 +296,12 @@ def _audit_line(event: Event) -> str:
)
elif isinstance(event, Cancelled):
detail = f"turn_id={event.turn_id} reason={event.reason!r}"
elif isinstance(event, AwaitingLlmFirstToken):
# Worldtree #201 / v0.29.0. Compact: turn_id + elapsed in seconds
# (the heartbeat itself fires every 5s by default; seconds-rounding
# is the natural unit for operator scanning).
secs = event.elapsed_ms_since_building_prompt / 1000.0
detail = f"turn_id={event.turn_id} elapsed={secs:.1f}s"
elif isinstance(event, AffectUpdate):
# Worldtree #204 / v0.28.0. status="current" carries the full
# snapshot; surface dominant_emotion + PAD inline so the operator
@@ -347,6 +354,13 @@ class TuiPresenterState:
thinking_delta_count: int = 0
thinking_byte_count: int = 0
turn_start_ts: float = 0.0
# v0.14.0: Worldtree #201 heartbeat surface. First
# `awaiting_llm_first_token` mounts a Static; subsequent heartbeats
# update it in place; any non-heartbeat event clears it (the gap
# closed). awaiting_widget is the Static reference (None when
# closed); heartbeat_count tracks emissions for the turn-summary.
awaiting_widget: object = None
heartbeat_count: int = 0
def render(
self,
@@ -383,6 +397,7 @@ class TuiPresenterState:
(
WorkerPhase, Thinking, Text, TextBoundary,
ToolStart, ToolResult, Done, Error, Cancelled, AffectUpdate,
AwaitingLlmFirstToken,
),
)
from rich.text import Text as RichText
@@ -430,6 +445,37 @@ class TuiPresenterState:
# the event regardless.
pass
return
# v0.14.0: AwaitingLlmFirstToken (Worldtree #201) gets the audit
# line (above) plus a live transcript indicator. First heartbeat
# mounts a Static; subsequent heartbeats update it in place.
# Any non-heartbeat event below closes the gap and the indicator
# is removed (the first text/thinking/done arrived).
if isinstance(event, AwaitingLlmFirstToken):
from rich.text import Text as RichText
self.heartbeat_count += 1
secs = event.elapsed_ms_since_building_prompt / 1000.0
label = RichText(
f"awaiting first token · {secs:.1f}s",
style=_AU_DEMOTED,
)
try:
if self.awaiting_widget is None:
self.awaiting_widget = Static(label, classes="awaiting-label")
transcript.mount(self.awaiting_widget)
else:
self.awaiting_widget.update(label)
transcript.scroll_end(animate=False)
except Exception:
pass
return
# Any non-heartbeat event past this point means the gap closed —
# remove the awaiting indicator if it's still mounted.
if self.awaiting_widget is not None:
try:
self.awaiting_widget.remove()
except Exception:
pass
self.awaiting_widget = None
# v0.7.1: Thinking deltas coalesce by newline before flushing.
# Worldtree emits Thinking events at token granularity; per-delta
# RichLog writes produce one visual line per token (per-token-per-
@@ -525,6 +571,7 @@ class TuiPresenterState:
f"text_bytes={self.text_byte_count} "
f"thinking_deltas={self.thinking_delta_count} "
f"thinking_bytes={self.thinking_byte_count} "
f"heartbeats={self.heartbeat_count} "
f"elapsed_ms={elapsed_ms}"
))
# Terminal event: finalize the response widget (clear ref so
@@ -838,6 +885,14 @@ class RatatoskrApp(App[int]):
height: auto;
padding: 0 1;
}
/* v0.14.0: Worldtree #201 — live "awaiting first token · Ns" indicator
in the transcript during the BuildingPrompt → CallingLLM gap.
Demoted styling so it reads as ambient progress, not content. */
.awaiting-label {
height: auto;
padding: 0 1;
color: $au-dark-60;
}
/* v0.8.1: #current-text Static removed. Streaming text now coalesces
on `\n` and writes directly to #transcript (same pattern as v0.7.1
thinking fix). Eliminates the dock-bottom-growth-overlap bug. */
tests/test_sse_client.py
+85
View File
@@ -6,6 +6,7 @@ import respx
from ratatoskr.sse_client import (
AffectUpdate,
AwaitingLlmFirstToken,
CancelAlreadyCompleted,
Cancelled,
CancelResult,
@@ -955,3 +956,87 @@ class TestAffectUpdate:
assert affect.turn_id == 42
assert affect.snapshot is None
assert affect.sse_id == SseId(42, 2)
class TestAwaitingLlmFirstToken:
"""Worldtree #201 / v0.29.0 — `awaiting_llm_first_token` SSE heartbeat.
Top-level event (not a worker_phase extension) fired during the
BuildingPrompt → CallingLLM gap at the configured interval (default
5s). Server-authoritative elapsed_ms is time.monotonic()-based and
monotonically increasing across the heartbeat sequence.
See docs/conversation-api-spec.md § awaiting_llm_first_token.
"""
@respx.mock
async def test_single_heartbeat_parsed(self) -> None:
"""single_heartbeat_parsed [tracer]: type=awaiting_llm_first_token →
AwaitingLlmFirstToken(turn_id, elapsed_ms_since_building_prompt).
"""
stream = _sse_chunk(
"42:1",
{
"type": "awaiting_llm_first_token",
"turn_id": 42,
"elapsed_ms_since_building_prompt": 5012.3,
},
) + _sse_chunk("42:2", _DONE_42_6)
respx.post("https://w.example/sessions/s1/messages").mock(
return_value=httpx.Response(
200, headers={"content-type": "text/event-stream"}, content=stream
)
)
async with httpx.AsyncClient(base_url="https://w.example") as client:
events = [e async for e in stream_turn(client, "s1", "hi")]
beat = events[0]
assert isinstance(beat, AwaitingLlmFirstToken)
assert beat.turn_id == 42
assert beat.elapsed_ms_since_building_prompt == 5012.3
assert beat.sse_id == SseId(42, 1)
@respx.mock
async def test_heartbeat_sequence_monotonic(self) -> None:
"""heartbeat_sequence_monotonic [scenario]: three consecutive heartbeats
in one turn — elapsed_ms_since_building_prompt monotonically increases,
all carry the same turn_id.
"""
stream = (
_sse_chunk(
"42:1",
{
"type": "awaiting_llm_first_token",
"turn_id": 42,
"elapsed_ms_since_building_prompt": 5000.0,
},
)
+ _sse_chunk(
"42:2",
{
"type": "awaiting_llm_first_token",
"turn_id": 42,
"elapsed_ms_since_building_prompt": 10005.4,
},
)
+ _sse_chunk(
"42:3",
{
"type": "awaiting_llm_first_token",
"turn_id": 42,
"elapsed_ms_since_building_prompt": 15011.8,
},
)
+ _sse_chunk("42:4", _DONE_42_6)
)
respx.post("https://w.example/sessions/s1/messages").mock(
return_value=httpx.Response(
200, headers={"content-type": "text/event-stream"}, content=stream
)
)
async with httpx.AsyncClient(base_url="https://w.example") as client:
events = [e async for e in stream_turn(client, "s1", "hi")]
beats = [e for e in events if isinstance(e, AwaitingLlmFirstToken)]
assert len(beats) == 3
elapsed = [b.elapsed_ms_since_building_prompt for b in beats]
assert elapsed == sorted(elapsed) # monotonically increasing
assert all(b.turn_id == 42 for b in beats)
tests/test_tui.py
+89
View File
@@ -719,6 +719,95 @@ class TestPresenterAuditLogging:
assert not tools_log.write.called
assert not thinking_log.write.called
def test_awaiting_llm_first_token_mounts_indicator(self) -> None:
"""awaiting_llm_first_token_mounts_indicator [v0.14.0]: first heartbeat
mounts a Static into the transcript and bumps heartbeat_count;
debug-pane audit line carries turn_id + elapsed in seconds.
"""
from ratatoskr.sse_client import AwaitingLlmFirstToken
from ratatoskr.tui import TuiPresenterState
transcript = MagicMock()
debug_log = MagicMock()
state = TuiPresenterState()
state.render(
AwaitingLlmFirstToken(
sse_id=SID, turn_id=42, elapsed_ms_since_building_prompt=5012.3
),
transcript=transcript,
tools_log=MagicMock(),
debug_log=debug_log,
thinking_log=MagicMock(),
raw=False,
)
assert state.heartbeat_count == 1
assert state.awaiting_widget is not None
assert transcript.mount.call_count == 1
audit = _text_of(debug_log.write.call_args[0][0])
assert "awaitingllmfirsttoken" in audit
assert "turn_id=42" in audit
assert "elapsed=5.0s" in audit
def test_awaiting_subsequent_heartbeats_update_in_place(self) -> None:
"""awaiting_subsequent_heartbeats_update_in_place [v0.14.0]: second+
heartbeats reuse the existing Static (no new mount); heartbeat_count
tracks the total.
"""
from ratatoskr.sse_client import AwaitingLlmFirstToken
from ratatoskr.tui import TuiPresenterState
transcript = MagicMock()
state = TuiPresenterState()
for elapsed in (5000.0, 10005.4, 15011.8):
state.render(
AwaitingLlmFirstToken(
sse_id=SID, turn_id=42, elapsed_ms_since_building_prompt=elapsed
),
transcript=transcript,
tools_log=MagicMock(),
debug_log=MagicMock(),
thinking_log=MagicMock(),
raw=False,
)
assert state.heartbeat_count == 3
assert transcript.mount.call_count == 1 # mounted once on first
def test_awaiting_indicator_removed_when_gap_closes(self) -> None:
"""awaiting_indicator_removed_when_gap_closes [v0.14.0]: any non-
heartbeat event after one or more heartbeats removes the indicator
and clears the awaiting_widget reference. Text event simulates the
gap closing (CallingLLM fires, text begins).
"""
from ratatoskr.sse_client import AwaitingLlmFirstToken
from ratatoskr.tui import TuiPresenterState
transcript = MagicMock()
state = TuiPresenterState()
state.render(
AwaitingLlmFirstToken(
sse_id=SID, turn_id=42, elapsed_ms_since_building_prompt=5000.0
),
transcript=transcript,
tools_log=MagicMock(),
debug_log=MagicMock(),
thinking_log=MagicMock(),
raw=False,
)
widget = state.awaiting_widget
assert widget is not None
state.render(
Text(sse_id=SID, content="hello"),
transcript=transcript,
tools_log=MagicMock(),
debug_log=MagicMock(),
thinking_log=MagicMock(),
raw=False,
)
# State reference cleared (the widget itself is a real Static whose
# .remove() schedules removal — we verify the cleanup intent via
# the state field, which is the contract callers actually observe).
assert state.awaiting_widget is None
def test_affect_update_scheduled_has_no_pad_detail(self) -> None:
"""affect_update_scheduled_has_no_pad_detail [v0.11.0]: status=scheduled
carries no snapshot — the audit line omits dominant_emotion / pad and
uv.lock
Generated
+1 -1
View File
@@ -968,7 +968,7 @@ wheels = [
[[package]]
name = "ratatoskr"
version = "0.13.0"
version = "0.14.0"
source = { editable = "." }
dependencies = [
{ name = "httpx" },