feat(tui): debug-pane audit logging surface (v0.10.0)

Adds wire-level visibility appropriate for a debugging TUI. Every
SSE event arrival now lands as one debug-pane line; token-rate Text
and Thinking deltas get aggregated counters surfaced in a per-turn
summary instead of per-delta spam.

Audit surfaces added (all routed to the debug pane):
- per-event arrival: timestamp + event type + sse_id + event-specific
  summary for WorkerPhase / ToolStart / ToolResult / TextBoundary /
  Done / Error / Cancelled
- turn-summary at terminal events: text_deltas / text_bytes /
  thinking_deltas / thinking_bytes / elapsed_ms
- app-level state-machine transitions via new RatatoskrApp._transition
  helper (idle → streaming → cancelling → idle, with reason)
- worker_spawn line at on_input_submitted with content_len
- ctrl_c / ctrl_d audit lines documenting action + exit code
- cancel POST lifecycle: _cancel_via_sse takes an optional audit
  callback and emits issued / ok / failed lines
- app_mounted bootstrap line at on_mount (server + agent + session
  tail + raw + end_user_id)
- wire-error exception class + body audit at _stream_turn_worker

Helpers:
- TuiPresenterState: text_delta_count / text_byte_count /
  thinking_delta_count / thinking_byte_count / turn_start_ts
- module-level _ts() + _audit_line() + RatatoskrApp._audit() /
  _transition()

Tests: 6 new test cases lock in audit-line shape, turn-summary
aggregation, cancel-POST lifecycle callback, and the silence of
per-Text-delta debug writes.

pyproject.toml

@@ -4,7 +4,7 @@ build-backend = "hatchling.build"
 
 [project]
 name = "ratatoskr"
-version = "0.9.0"
+version = "0.10.0"
 description = "Worldtree Conversation API debug TUI — multi-pane observability dashboard"
 readme = "README.md"
 requires-python = ">=3.12"

src/ratatoskr/tui.py

@@ -10,7 +10,9 @@ from __future__ import annotations
 
 import asyncio
 import sys
+import time as _time
 from dataclasses import dataclass
+from datetime import datetime as _datetime
 from typing import ClassVar, Literal
 
 import httpx
@@ -178,6 +180,48 @@ def _plain_label(event: Event) -> str:
     return f"[unknown_event] {type(event).__name__}"
 
 
+def _ts() -> str:
+    """HH:MM:SS.fff wall-clock timestamp for debug-pane log lines."""
+    now = _datetime.now()
+    return now.strftime("%H:%M:%S") + f".{now.microsecond // 1000:03d}"
+
+
+def _audit_line(event: Event) -> str:
+    """One-line wire-level audit summary for the debug pane.
+
+    v0.10.0: every SSE event arrival lands as one of these in the debug
+    pane (Text and Thinking deltas are aggregated into the turn summary
+    instead — token-rate per-delta lines would drown the pane). Shape:
+    `[HH:MM:SS.fff] event_type sse_id=T:S key=val …`.
+    """
+    sid = getattr(event, "sse_id", None)
+    sid_str = f"{sid.turn_id}:{sid.seq}" if sid is not None else "-"
+    kind = type(event).__name__.lower()
+    if isinstance(event, WorkerPhase):
+        detail = f"phase={event.phase} turn_id={event.turn_id}"
+    elif isinstance(event, ToolStart):
+        detail = f"name={event.name} args={event.arguments!r:.80}"
+    elif isinstance(event, ToolResult):
+        detail = f"name={event.name} duration_ms={event.duration_ms}"
+    elif isinstance(event, TextBoundary):
+        detail = f"kind={event.kind} char_offset={event.char_offset}"
+    elif isinstance(event, Done):
+        detail = (
+            f"turn_id={event.sse_id.turn_id} model={event.model} "
+            f"duration_ms={event.duration_ms}"
+        )
+    elif isinstance(event, Error):
+        detail = (
+            f"turn_id={event.sse_id.turn_id} code={event.error_code} "
+            f"message={event.message!r:.80}"
+        )
+    elif isinstance(event, Cancelled):
+        detail = f"turn_id={event.turn_id} reason={event.reason!r}"
+    else:  # Text / Thinking handled by counter path; fallback for safety
+        detail = ""
+    return f"[{_ts()}] {kind} sse_id={sid_str} {detail}".rstrip()
+
+
 @dataclass(slots=True)
 class TuiPresenterState:
     """Per-turn presenter state for TUI mode (issue #12).
@@ -202,6 +246,15 @@ class TuiPresenterState:
     # v0.9.0: reference to the Static widget holding the current turn's
     # response Markdown Renderable. None between turns.
     current_response_widget: object = None
+    # v0.10.0: per-turn counters for the debug-pane turn-summary line. Text
+    # and Thinking events arrive at token rate; emitting per-delta debug
+    # lines would drown the pane. Instead we count them and surface
+    # aggregated totals when the turn closes.
+    text_delta_count: int = 0
+    text_byte_count: int = 0
+    thinking_delta_count: int = 0
+    thinking_byte_count: int = 0
+    turn_start_ts: float = 0.0
 
     def render(
         self,
@@ -240,6 +293,29 @@ class TuiPresenterState:
             return RichText(s, style=_AU_DEMOTED)
 
         try:
+            # v0.10.0: per-event audit log line to debug pane. Text and
+            # Thinking arrive at token rate, so we count them rather than
+            # emit a line per delta — totals are reported in the turn-
+            # summary on Done/Error/Cancelled. Everything else gets one
+            # debug-pane line per arrival with timestamp + sse_id + a short
+            # event-specific summary, giving the operator a wire-level
+            # timeline of what the server sent.
+            if isinstance(event, Text):
+                if self.text_delta_count == 0:
+                    if self.turn_start_ts == 0.0:
+                        self.turn_start_ts = _time.monotonic()
+                self.text_delta_count += 1
+                self.text_byte_count += len(event.content)
+            elif isinstance(event, Thinking):
+                if self.thinking_delta_count == 0:
+                    if self.turn_start_ts == 0.0:
+                        self.turn_start_ts = _time.monotonic()
+                self.thinking_delta_count += 1
+                self.thinking_byte_count += len(event.content)
+            else:
+                if self.turn_start_ts == 0.0:
+                    self.turn_start_ts = _time.monotonic()
+                debug_log.write(_dim(_audit_line(event)))
             # 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-
@@ -315,6 +391,28 @@ class TuiPresenterState:
                 transcript.scroll_end(animate=False)
                 return
             if isinstance(event, (Done, Error, Cancelled)):
+                # v0.10.0: emit turn-summary to debug pane before clearing
+                # counters. Aggregates the per-event totals (Text + Thinking
+                # deltas don't get per-event audit lines because they arrive
+                # at token rate; the summary surfaces what was elided).
+                elapsed_ms = (
+                    int((_time.monotonic() - self.turn_start_ts) * 1000)
+                    if self.turn_start_ts
+                    else 0
+                )
+                turn_id = (
+                    event.sse_id.turn_id
+                    if hasattr(event, "sse_id")
+                    else getattr(event, "turn_id", "?")
+                )
+                debug_log.write(_dim(
+                    f"[{_ts()}] turn_summary turn_id={turn_id} "
+                    f"text_deltas={self.text_delta_count} "
+                    f"text_bytes={self.text_byte_count} "
+                    f"thinking_deltas={self.thinking_delta_count} "
+                    f"thinking_bytes={self.thinking_byte_count} "
+                    f"elapsed_ms={elapsed_ms}"
+                ))
                 # Terminal event: finalize the response widget (clear ref so
                 # the next turn mounts a fresh one). The accumulated text is
                 # already rendered as Markdown in the widget — no post-Done
@@ -793,6 +891,14 @@ class RatatoskrApp(App[int]):
         )
         self.state = "idle"
         self._set_hint(self.HINT_IDLE)
+        # v0.10.0: startup audit so the debug pane carries a complete
+        # session bootstrap line (server URL, agent, end_user_id, raw flag,
+        # session tail) before the first turn fires.
+        self._audit(
+            f"app_mounted server={self.args.server_url} agent_id={self.agent_id!r} "
+            f"session={self.session_id[-8:]} raw={self.args.raw} "
+            f"end_user_id={getattr(self.args, 'end_user_id', None)!r}"
+        )
 
     def _write_turn_headers(self, turn_id: int) -> None:
         """v0.6.0: turn-ID headers across every pane for cross-pane
@@ -833,6 +939,37 @@ class RatatoskrApp(App[int]):
             # Widget may be gone during shutdown; ignore.
             pass
 
+    def _audit(self, line: str) -> None:
+        """Write a timestamped audit line to the debug pane.
+
+        v0.10.0: shared sink for app-level events that don't pass through
+        the presenter — state transitions, worker spawn/cancel, cancel POST
+        lifecycle, startup probes. The presenter's per-event audit lives at
+        `_audit_line()`; this is its app-side counterpart.
+        """
+        try:
+            from rich.text import Text as RichText
+            self.query_one("#debug-log", RichLog).write(
+                RichText(f"[{_ts()}] {line}", style=_AU_DEMOTED)
+            )
+        except Exception:
+            # Widget may not exist yet (pre-mount) or be tearing down.
+            pass
+
+    def _transition(
+        self, new_state: Literal["idle", "streaming", "cancelling"], reason: str
+    ) -> None:
+        """Set self.state with debug-pane audit log.
+
+        Every state machine transition flows through here so the debug pane
+        carries a complete idle→streaming→cancelling→idle timeline with the
+        triggering reason. Cheap; safe to call from any context.
+        """
+        old = self.state
+        self.state = new_state
+        if old != new_state:
+            self._audit(f"state {old} → {new_state} reason={reason}")
+
     async def on_input_submitted(self, event: Input.Submitted) -> None:
         """Echo user prompt, spawn stream worker; busy notice if not idle.
 
@@ -863,7 +1000,8 @@ class RatatoskrApp(App[int]):
         )
         transcript.scroll_end(animate=False)
         event.input.value = ""
-        self.state = "streaming"
+        self._transition("streaming", "input_submitted")
+        self._audit(f"worker_spawn content_len={len(content)}")
         self._set_hint(self.HINT_STREAMING)
         self.stream_worker = self.run_worker(
             self._stream_turn_worker(content), exclusive=True
@@ -909,17 +1047,22 @@ class RatatoskrApp(App[int]):
                 if isinstance(event, (Done, Error, Cancelled)):
                     break
         except SseConnectFailed as exc:
+            self._audit(f"sse_connect_failed status={exc.status} body={exc.body!r:.120}")
             _mount_wire_error(f"[sse_connect_failed] status={exc.status} body={exc.body!r}")
         except SseConnectionDropped as exc:
+            self._audit(f"connection_dropped last_seen={exc.last_seen_sse_id}")
             _mount_wire_error(f"[connection_dropped] last_seen={exc.last_seen_sse_id}")
         except MalformedSseId as exc:
+            self._audit(f"malformed_sse_id raw={exc.raw!r}")
             _mount_wire_error(f"[malformed_sse_id] raw={exc.raw!r}")
         except MalformedSseData as exc:
+            self._audit(f"malformed_sse_data raw={exc.raw!r:.120}")
             _mount_wire_error(f"[malformed_sse_data] raw={exc.raw!r}")
         except TurnIdFlip as exc:
+            self._audit(f"turn_id_flip expected={exc.established} got={exc.got}")
             _mount_wire_error(f"[turn_id_flip] expected={exc.established} got={exc.got}")
         finally:
-            self.state = "idle"
+            self._transition("idle", "worker_finally")
             self.active_turn_id = None
             self._set_hint(self.HINT_IDLE)
 
@@ -931,29 +1074,35 @@ class RatatoskrApp(App[int]):
         """Two-stage Ctrl-C state machine per INV-003."""
         assert self.state in ("idle", "streaming", "cancelling")
         if self.state == "idle":
+            self._audit("ctrl_c state=idle action=exit code=0")
             self.exit(0)
         elif self.state == "streaming":
             if self.active_turn_id is None:
+                self._audit("ctrl_c state=streaming active_turn_id=None action=force_exit code=3")
                 if self.stream_worker is not None:
                     self.stream_worker.cancel()
                 self.exit(3)
                 return
-            self.state = "cancelling"
+            self._audit(f"ctrl_c state=streaming turn_id={self.active_turn_id} action=cancel_post")
+            self._transition("cancelling", "ctrl_c_cancel_post_issued")
             self._set_hint(self.HINT_CANCELLING)
             transcript = self.query_one("#transcript-scroll", VerticalScroll)
             self.run_worker(
                 _cancel_via_sse(
                     self.client, self.session_id, self.active_turn_id,
                     transcript=transcript,
+                    audit=self._audit,
                 )
             )
         elif self.state == "cancelling":
+            self._audit("ctrl_c state=cancelling action=force_exit code=3")
             if self.stream_worker is not None:
                 self.stream_worker.cancel()
             self.exit(3)
 
     def action_quit(self) -> None:
         """Ctrl-D — immediate exit regardless of state."""
+        self._audit(f"ctrl_d state={self.state} action=exit code=0")
         if self.stream_worker is not None and not self.stream_worker.is_finished:
             self.stream_worker.cancel()
         self.exit(0)
@@ -1095,17 +1244,27 @@ async def _cancel_via_sse(
     turn_id: int,
     *,
     transcript: VerticalScroll,
+    audit: "Callable[[str], None] | None" = None,
 ) -> None:
     """Fire-and-forget cancel; never raises (mirrors cli._cancel_and_log; #3 INV-009).
 
     v0.9.0: mounts a `[cancel_failed]` Static into the transcript-scroll
     container on failure (was log.write to RichLog).
+    v0.10.0: optional `audit` callback (RatatoskrApp._audit) receives one
+    line on POST issue + one on POST result, so the debug pane carries the
+    full cancel lifecycle. Defaults to no-op for legacy callers.
     """
     assert client is not None
     assert isinstance(turn_id, int) and turn_id > 0
+    if audit is not None:
+        audit(f"cancel_post issued session_id={session_id} turn_id={turn_id}")
     try:
         await cancel_turn(client, session_id, turn_id)
+        if audit is not None:
+            audit(f"cancel_post ok turn_id={turn_id}")
     except (CancelFailed, CancelTurnNotFound, CancelAlreadyCompleted, httpx.RequestError) as exc:
+        if audit is not None:
+            audit(f"cancel_post failed turn_id={turn_id} {type(exc).__name__}: {exc!s:.120}")
         try:
             transcript.mount(Static(
                 f"[cancel_failed] {type(exc).__name__}: {exc}",

tests/test_tui.py

@@ -605,6 +605,122 @@ class TestTuiPresenterState:
         assert "usage 6756 in → 126 out (6882 total, 0 cached)" in done_line
 
 
+class TestPresenterAuditLogging:
+    """v0.10.0 — per-event audit lines + turn-summary in the debug pane.
+
+    The presenter emits one debug-pane line per arriving event (Text and
+    Thinking are aggregated into the turn-summary instead of per-delta to
+    avoid drowning the pane at token rate).
+    """
+
+    def test_worker_phase_emits_audit_line(self) -> None:
+        """worker_phase_emits_audit_line: WorkerPhase arrival adds an audit
+        line to debug_log alongside the existing `· worker_phase:` entry.
+        Audit line shape: `[HH:MM:SS.fff] workerphase sse_id=N:M …`.
+        """
+        from ratatoskr.tui import TuiPresenterState
+
+        debug_log = MagicMock()
+        state = TuiPresenterState()
+        state.render(
+            WorkerPhase(sse_id=SID, phase="streaming", turn_id=42),
+            transcript=MagicMock(),
+            tools_log=MagicMock(),
+            debug_log=debug_log,
+            thinking_log=MagicMock(),
+            raw=False,
+        )
+        # Two writes: audit line + worker_phase telemetry.
+        assert debug_log.write.call_count == 2
+        audit_line = _text_of(debug_log.write.call_args_list[0][0][0])
+        assert "workerphase" in audit_line
+        assert "sse_id=42:5" in audit_line
+        assert "phase=streaming" in audit_line
+
+    def test_tool_start_emits_audit_line(self) -> None:
+        """tool_start_emits_audit_line: ToolStart adds one audit line to
+        debug_log even though the tool event itself routes to tools_log.
+        """
+        from ratatoskr.tui import TuiPresenterState
+
+        debug_log = MagicMock()
+        state = TuiPresenterState()
+        state.render(
+            ToolStart(sse_id=SID, name="read_file", arguments={"path": "/x"}),
+            transcript=MagicMock(),
+            tools_log=MagicMock(),
+            debug_log=debug_log,
+            thinking_log=MagicMock(),
+            raw=False,
+        )
+        assert debug_log.write.call_count == 1
+        audit_line = _text_of(debug_log.write.call_args[0][0])
+        assert "toolstart" in audit_line
+        assert "sse_id=42:5" in audit_line
+        assert "name=read_file" in audit_line
+
+    def test_text_delta_counted_not_per_event_audit_line(self) -> None:
+        """text_delta_counted_not_per_event_audit_line: a Text delta does
+        NOT emit a per-event audit line (token-rate would drown the pane);
+        instead it bumps text_delta_count / text_byte_count for the turn-
+        summary at Done.
+        """
+        from ratatoskr.tui import TuiPresenterState
+
+        debug_log = MagicMock()
+        state = TuiPresenterState()
+        state.render(
+            Text(sse_id=SID, content="hello world"),
+            transcript=MagicMock(),
+            tools_log=MagicMock(),
+            debug_log=debug_log,
+            thinking_log=MagicMock(),
+            raw=False,
+        )
+        # No debug-pane writes — text deltas are silent at token rate.
+        assert not debug_log.write.called
+        assert state.text_delta_count == 1
+        assert state.text_byte_count == len("hello world")
+
+    def test_done_emits_turn_summary_line(self) -> None:
+        """done_emits_turn_summary_line: when Done arrives the presenter
+        emits a `turn_summary` line aggregating per-delta Text + Thinking
+        counters. The shape exposes the totals that per-event audit lines
+        elided.
+        """
+        from ratatoskr.tui import TuiPresenterState
+
+        debug_log = MagicMock()
+        state = TuiPresenterState()
+        # 3 Text deltas + 2 Thinking deltas, then Done.
+        state.render(
+            Text(sse_id=SID, content="a"),
+            transcript=MagicMock(), tools_log=MagicMock(),
+            debug_log=debug_log, thinking_log=MagicMock(), raw=False,
+        )
+        state.render(
+            Text(sse_id=SID, content="bc"),
+            transcript=MagicMock(), tools_log=MagicMock(),
+            debug_log=debug_log, thinking_log=MagicMock(), raw=False,
+        )
+        state.render(
+            Thinking(sse_id=SID, content="thought\n"),
+            transcript=MagicMock(), tools_log=MagicMock(),
+            debug_log=debug_log, thinking_log=MagicMock(), raw=False,
+        )
+        state.render(
+            _make_tui_done(),
+            transcript=MagicMock(), tools_log=MagicMock(),
+            debug_log=debug_log, thinking_log=MagicMock(), raw=False,
+        )
+        writes = [_text_of(c[0][0]) for c in debug_log.write.call_args_list]
+        summary = next(w for w in writes if "turn_summary" in w)
+        assert "text_deltas=2" in summary
+        assert "text_bytes=3" in summary  # "a" + "bc"
+        assert "thinking_deltas=1" in summary
+        assert "elapsed_ms=" in summary
+
+
 def _text_of(write_arg: object) -> str:
     """Extract plain text from a RichLog.write() arg (str or rich.text.Text).
 
@@ -715,6 +831,47 @@ class TestCancelViaSse:
         assert "[cancel_failed]" in line
         assert "ConnectError" in line
 
+    @respx.mock
+    async def test_audit_callback_records_lifecycle(self) -> None:
+        """audit_callback_records_lifecycle [v0.10.0]: when the caller passes
+        an `audit` callback, _cancel_via_sse emits two lines on the happy
+        path (`cancel_post issued …` + `cancel_post ok …`) and two lines on
+        the failure path (`issued` + `failed …`). Gives the debug pane a
+        complete cancel-POST timeline.
+        """
+        respx.post("https://w.example/sessions/s-1/turns/42/cancel").mock(
+            return_value=httpx.Response(200, json=_CANCEL_OK_RESP)
+        )
+        transcript = MagicMock()
+        audit_lines: list = []
+        async with httpx.AsyncClient(base_url="https://w.example") as client:
+            await _cancel_via_sse(
+                client, "s-1", 42, transcript=transcript, audit=audit_lines.append
+            )
+        assert len(audit_lines) == 2
+        assert audit_lines[0].startswith("cancel_post issued ")
+        assert "session_id=s-1" in audit_lines[0]
+        assert "turn_id=42" in audit_lines[0]
+        assert audit_lines[1] == "cancel_post ok turn_id=42"
+
+    @respx.mock
+    async def test_audit_callback_records_failure(self) -> None:
+        """audit_callback_records_failure [v0.10.0]: failure path emits
+        `cancel_post issued` then `cancel_post failed …` with exception type.
+        """
+        respx.post("https://w.example/sessions/s-1/turns/42/cancel").mock(
+            return_value=httpx.Response(500, content=b"boom")
+        )
+        transcript = MagicMock()
+        audit_lines: list = []
+        async with httpx.AsyncClient(base_url="https://w.example") as client:
+            await _cancel_via_sse(
+                client, "s-1", 42, transcript=transcript, audit=audit_lines.append
+            )
+        assert len(audit_lines) == 2
+        assert audit_lines[0].startswith("cancel_post issued ")
+        assert audit_lines[1].startswith("cancel_post failed turn_id=42 CancelFailed")
+
 
 class TestAppMount:
     """on_mount narrows per issue #6: only identity-widget population.

uv.lock

@@ -968,7 +968,7 @@ wheels = [
 
 [[package]]
 name = "ratatoskr"
-version = "0.9.0"
+version = "0.10.0"
 source = { editable = "." }
 dependencies = [
     { name = "httpx" },