From bb5ac1a242c22faf67c64bbd12be75e839e7dd0d Mon Sep 17 00:00:00 2001 From: iris-ai <4+iris-ai@noreply.localhost> Date: Sat, 19 Sep 2026 15:07:25 -0400 Subject: [PATCH] Draw a model's thinking, and what a reply cost to produce MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A llama.cpp session's `reasoning_content` becomes `Event::Thinking` deltas closed by an `Event::ThinkingDone` carrying the span the driver measured, and the phone draws it as a card of its own: "Thinking" with the spinner a running command has, then "Thought for 12.4s". Deliberately not a tool call, so a run of calls cannot collapse the reasoning into "Called 6 tools"; the reasoning is also kept out of the next prompt, which `conversation` already ignored. `UsageDelta` gains `tokensPerSecond`, the provider's own figure or nothing -- llama.cpp reports `timings.predicted_per_second` and the coding CLIs report no such thing -- and a finished reply carries a small line under it saying when it was sent and, where there is one, how fast it came out: "3:00 PM · 149 tok/s". The compact usage bar drops the provider's name for the window and puts its length after the time left instead: "42% · 3h 20m left / 5h". Three things that had to come with it: the transcript coalesces runs of thinking deltas as it does reply deltas, so one block is one row of a page rather than a page of its own; `joinPages` welds a block cut by a page boundary (`healSplitThinking`), since the half with no ending spun for ever; and `UsageDelta` now reaches the fold, which is what carries the rate to the reply. Verified on the emulator against a real Qwen3-0.6B session and the echo rig's new `/think [seconds]`: the spinner while it runs, "Thought for 1.4s" and "2:54 PM · 149 tok/s" after, the reasoning on tapping the card, and the usage bar reading "42% · 3h 19m left / 5h". Co-Authored-By: Claude Opus 5 --- .claude/skills/ai-app-rigs/SKILL.md | 4 + AGENTS.md | 8 + PLAN.md | 46 +++++- .../main/kotlin/com/example/aiapp/Events.kt | 29 +++- .../kotlin/com/example/aiapp/ReplyFooter.kt | 69 ++++++++ .../kotlin/com/example/aiapp/SessionScreen.kt | 135 +++++++++------- .../com/example/aiapp/SessionUsageBar.kt | 15 +- .../kotlin/com/example/aiapp/SpawnScreen.kt | 2 +- .../kotlin/com/example/aiapp/ThinkingCard.kt | 79 ++++++++++ .../com/example/aiapp/TranscriptItems.kt | 112 +++++++++++-- .../com/example/aiapp/TranscriptUnits.kt | 39 +++++ .../kotlin/com/example/aiapp/ThinkingTest.kt | 137 ++++++++++++++++ server/src/session/claude/translate.rs | 14 +- server/src/session/codex/translate.rs | 11 +- server/src/session/driver.rs | 41 +++++ server/src/session/echo.rs | 33 ++++ server/src/session/llama/mod.rs | 78 ++++++++- server/src/session/transcript.rs | 149 +++++++++++++++--- 18 files changed, 900 insertions(+), 101 deletions(-) create mode 100644 app/androidApp/src/main/kotlin/com/example/aiapp/ReplyFooter.kt create mode 100644 app/androidApp/src/main/kotlin/com/example/aiapp/ThinkingCard.kt create mode 100644 app/androidApp/src/test/kotlin/com/example/aiapp/ThinkingTest.kt diff --git a/.claude/skills/ai-app-rigs/SKILL.md b/.claude/skills/ai-app-rigs/SKILL.md index 5fe2f71..3a7b22d 100644 --- a/.claude/skills/ai-app-rigs/SKILL.md +++ b/.claude/skills/ai-app-rigs/SKILL.md @@ -81,6 +81,10 @@ Each exists because something was invisible without it. `debug-transcript.sh` when it is *what the transcript draws*. The sandbox's version also handles `auth login`: it prints an inert Anthropic-shaped URL, rejects any code except `sandbox-code`, and exits successfully for that one. +- **`/think [seconds]` in an echo session puts up a thinking card**, long + enough to watch it spin before it closes with the span it actually took. + The rest of the turn is the ordinary echo reply, so it is also the rig for + a block and a reply meeting. - **`app/transcript-bench.sh`** is the standard scroll measurement: it opens the first session (or `-k` keeps the current screen), scrolls a fixed gesture loop, and prints the app's render report — the same one the in-app diff --git a/AGENTS.md b/AGENTS.md index 5ea9736..7595a3a 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -62,6 +62,14 @@ Module-by-module intent is in PLAN.md's "Backend layout". MTP draft head is a 50% speed-up or a 33% loss; and `--spec-type draft-mtp` is conditional on the file actually having a head, because asking for one that is not there makes `llama-server` **exit**. + **A llama session's thinking is drawn** (2026-09-19): `reasoning_content` + becomes `Event::Thinking` deltas closed by an `Event::ThinkingDone` carrying + the span the *driver* measured, and the phone draws a card that spins while + the block is open and says "Thought for 12.4s" once it is not. The reasoning + is deliberately not part of the next prompt (`conversation` ignores it), and + `timings.predicted_per_second` off the same stream becomes `UsageDelta`'s + `tokensPerSecond`, which is the "149 tok/s" under a finished reply — nothing + else here measures one, so every other driver sends `None`. **Every one of those is a default rather than a constant** (2026-09-19): `DriverKind::params` declares what a provider takes — key, label, shape, and whether a change waits for a restart — and the phone renders whatever diff --git a/PLAN.md b/PLAN.md index 6dd217c..52617a7 100644 --- a/PLAN.md +++ b/PLAN.md @@ -135,6 +135,19 @@ seq N", so there is no separate history path to drift from the live one. `Patch { diff }`. Patch success boilerplate is omitted and failures remain as output. This normalization belongs in the drivers, before persistence; the phone never decodes a provider's tool schema. +- `Thinking { delta }` / `ThinkingDone { ms }` (2026-09-19) — the model's + working, streamed the way its reply is, and its own kind because it is not + what the session *said*: the phone draws it as a card of its own, shut, and + no driver folds it back into the next prompt. Only a provider that actually + streams its reasoning sends it — llama.cpp does, as `reasoning_content`; + nothing is inferred for one that does not, since a card that appeared + whenever a turn was slow would be a guess wearing a measurement's clothes. + The duration is **measured by the driver**, because a reader only knows when + an event arrived: the last fragment of a block followed by a slow tool call + is indistinguishable from thinking that went on that long. A block with no + `ThinkingDone` is one still being thought, which is what the card's spinner + says; one closed by the turn ending without a duration says "Thought" and + names no span rather than inventing one. - `Image { ref }` — saved under the session dir, fetched by URL. - `Question { id, prompt, options }` — anything needing a human. Claude's AskUserQuestion and permission requests (canUseTool) are the same shape; @@ -149,8 +162,13 @@ seq N", so there is no separate history path to drift from the live one. waiting for itself and will speak again with nobody having typed anything. Reporting it as idle sent a "finished" notification at the one moment that was untrue. -- `UsageDelta { tokens, context }` — what a turn cost and how much the model - was holding when it ended. `context` is prompt plus both cache figures, +- `UsageDelta { tokens, context, tokensPerSecond }` — what a turn cost, how + much the model was holding when it ended, and how fast it was generated. + `tokensPerSecond` (2026-09-19) is the provider's own measurement or nothing: + llama.cpp reports `timings.predicted_per_second`, and the coding CLIs report + no such figure, so dividing what this server watched a reply arrive over + would count the network, the tool calls and the reader's own permission + answers as generation. The phone draws it under the reply it measured. `context` is prompt plus both cache figures, taken from the **last assistant message** rather than the turn's `result`: measured 2026-08-30 against CLI 2.1.237, the result adds a turn's messages up, so its cache read of 40,211 was the same conversation counted twice. @@ -779,6 +797,11 @@ nothing at all for it — not a zero, and not "unknown". The session's usage dialog applies the same machine-and-provider match and shows every billing pool for that provider; it does not turn opening one session into a comparison with the other providers on that machine. +The compact bar names no window (2026-09-19): the provider's own name for it +("5-hour window") became a denominator after the span instead — "42% · 3h 20m +left / 5h" — which says in one reading both how much of the cycle is to come +and which cycle it is. Where the provider reported no duration there is +nothing after the span, since the name it gave is not a measurement of one. For a provider with several pools, the compact bar selects the pool named by the session's model (including Luna's `gpt-reserve` name), falling back to the provider's generic pool, and shows the shortest cycle that pool actually @@ -1237,8 +1260,25 @@ dev-updater (Kotlin 2.4.x, CMP 1.11.x, JDK 21). decision (`groupToolRuns`) and a cut run's pieces are keyed there — the first piece keeps the run's name, since that name is what survives a page of history landing in front of it. + - **The model's working is a card of its own** (2026-09-19) — "Thinking" + with the same spinner a running command has while it goes, and "Thought + for 12.4s" once it is over. Deliberately not a tool call, because a run + of tool calls collapses into "Called 6 tools" and the reasoning would be + filed as one of them; it therefore also breaks a run, which is right — + the model stopped to think in the middle of it. A block cut by a page + boundary is welded like a reply is (`healSplitThinking`), since the half + with no ending would otherwise spin for the rest of the conversation. + - **A finished reply carries a line under it saying when it was sent and, + where the provider measured one, how fast it was generated** (2026-09-19) + — "3:00 PM · 149 tok/s", small and set back, right-aligned because it + closes the message rather than opening one. The time is the transcript's + own timestamp, so every device draws the same one; the rate is the + provider's own figure or nothing at all. It is a list unit of its own + (`ReplyFoot`), because a settled reply *is* its blocks and there is no + row left to hang it on. - **Anything that is a note *about* the conversation rather than a turn in - it is closed by default** — a tool call, a peer message, a memory note. + it is closed by default** — a tool call, a peer message, a memory note, + a thinking block. Open-ness is the screen's, never the card's: a card that remembered for itself forgets the moment the lazy list stops composing it, so a note opened and scrolled past would shut behind the reader. diff --git a/app/androidApp/src/main/kotlin/com/example/aiapp/Events.kt b/app/androidApp/src/main/kotlin/com/example/aiapp/Events.kt index e5cbfde..22d8a42 100644 --- a/app/androidApp/src/main/kotlin/com/example/aiapp/Events.kt +++ b/app/androidApp/src/main/kotlin/com/example/aiapp/Events.kt @@ -64,6 +64,21 @@ sealed class SessionEvent { /** The durable value of the open assistant message, replacing its provisional deltas. */ data class AssistantTextFinal(val text: String) : SessionEvent() + /** + * The model's working, streamed the way its reply is: its own card, and deliberately not part + * of what the session said. Only a provider that actually streams its reasoning sends it. + */ + data class Thinking(val delta: String) : SessionEvent() + + /** + * The thinking above this finished, having taken [ms]. + * + * Measured by the driver, because only it can see when the model stopped: this app knows when + * an event *arrived*, and the last fragment of a block followed by a slow tool call looks + * exactly like thinking that went on that long. + */ + data class ThinkingDone(val ms: Long) : SessionEvent() + data class ToolStart(val id: String, val tool: String, val input: String) : SessionEvent() data class ToolUpdate(val id: String, val output: String) : SessionEvent() @@ -161,7 +176,16 @@ sealed class SessionEvent { * so adding turns up would report a figure the session stopped being true of. Null where the * dialect did not say, which leaves the context unmeasured rather than unchanged. */ - data class UsageDelta(val tokens: Long, val context: Long?) : SessionEvent() + data class UsageDelta( + val tokens: Long, + val context: Long?, + /** + * How fast the reply came out, where the provider measured it -- null everywhere else, + * which is most of them. Never worked out here: the time this app watched a reply arrive + * over includes the network and whatever the server was doing between tokens. + */ + val tokensPerSecond: Double? = null, + ) : SessionEvent() /** How much context this session's model has, which is what [UsageDelta.context] is out of. */ data class ContextWindow(val tokens: Long) : SessionEvent() @@ -237,6 +261,8 @@ fun parseSeqEvent(json: String): SeqEvent { "messageDropped" -> SessionEvent.MessageDropped(body.getString("id")) "assistantText" -> SessionEvent.AssistantText(body.getString("delta")) "assistantTextFinal" -> SessionEvent.AssistantTextFinal(body.getString("text")) + "thinking" -> SessionEvent.Thinking(body.getString("delta")) + "thinkingDone" -> SessionEvent.ThinkingDone(body.getLong("ms")) "toolStart" -> SessionEvent.ToolStart( id = body.getString("id"), @@ -301,6 +327,7 @@ fun parseSeqEvent(json: String): SeqEvent { SessionEvent.UsageDelta( body.getLong("tokens"), if (body.has("context")) body.getLong("context") else null, + if (body.has("tokensPerSecond")) body.getDouble("tokensPerSecond") else null, ) "compacted" -> SessionEvent.Compacted( diff --git a/app/androidApp/src/main/kotlin/com/example/aiapp/ReplyFooter.kt b/app/androidApp/src/main/kotlin/com/example/aiapp/ReplyFooter.kt new file mode 100644 index 0000000..90c75c3 --- /dev/null +++ b/app/androidApp/src/main/kotlin/com/example/aiapp/ReplyFooter.kt @@ -0,0 +1,69 @@ +package com.example.aiapp + +import androidx.compose.foundation.layout.fillMaxWidth +import androidx.compose.material3.MaterialTheme +import androidx.compose.material3.Text +import androidx.compose.runtime.Composable +import androidx.compose.ui.Modifier +import androidx.compose.ui.text.style.TextAlign +import java.time.Instant +import java.time.ZoneId +import java.time.format.DateTimeFormatter +import java.time.format.FormatStyle +import java.util.Locale + +/** + * The line under a finished reply: when it was sent, and how fast it was generated. + * + * Small and set back, in the tone the session's own subtitle takes: it is about the message rather + * than part of it, and at the reply's own size it would read as the last thing the model said. + * + * Right-aligned because it closes the message rather than opening one -- a reader scanning down the + * left edge is reading what was said, and this is where that ends. + */ +@Composable +fun ReplyFooter(ts: Double, tokensPerSecond: Double?, modifier: Modifier = Modifier) { + val text = replyFooterText(ts, tokensPerSecond, ZoneId.systemDefault()) ?: return + Text( + text, + style = MaterialTheme.typography.labelSmall, + color = MaterialTheme.colorScheme.onSurfaceVariant, + textAlign = TextAlign.End, + modifier = modifier.fillMaxWidth(), + ) +} + +/** + * What the footer says, or null when there is nothing to say. + * + * Split out so the wording is testable without a screen, and [zone] is a parameter for the same + * reason [limitSummary] takes one: a test has to say the same thing wherever it runs. + * + * A rate is drawn only where the provider measured one. Most do not -- a coding CLI reports what a + * turn cost and never how long the model spent -- and the time this app watched a reply arrive over + * is not the same quantity: it counts the network, the pauses between tokens and whatever the + * server was doing in them. So the line is the time alone rather than a plausible figure beside it. + */ +fun replyFooterText(ts: Double, tokensPerSecond: Double?, zone: ZoneId): String? { + val at = + if (ts <= 0.0) null + else + try { + DateTimeFormatter.ofLocalizedTime(FormatStyle.SHORT) + .withZone(zone) + .format(Instant.ofEpochMilli((ts * 1000).toLong())) + } catch (_: Exception) { + null + } + // A tenth up to three digits, where the difference between 18 and 18.4 tok/s is something a + // reader comparing two models can use; past that the tenth is noise on a figure that moves by + // more than that between turns. + val rate = + tokensPerSecond + ?.takeIf { it > 0.0 } + ?.let { + if (it >= 100) String.format(Locale.getDefault(), "%.0f tok/s", it) + else String.format(Locale.getDefault(), "%.1f tok/s", it) + } + return listOfNotNull(at, rate).joinToString(" · ").ifEmpty { null } +} diff --git a/app/androidApp/src/main/kotlin/com/example/aiapp/SessionScreen.kt b/app/androidApp/src/main/kotlin/com/example/aiapp/SessionScreen.kt index 154314e..33ab189 100644 --- a/app/androidApp/src/main/kotlin/com/example/aiapp/SessionScreen.kt +++ b/app/androidApp/src/main/kotlin/com/example/aiapp/SessionScreen.kt @@ -283,6 +283,10 @@ fun SessionScreen( // Which messages from other agents are open, by the seq that identifies their row. Closed by // default, which is the rule for anything new in this transcript. var expandedNotes by remember { mutableStateOf(setOf()) } + // Which thinking blocks are open, by the seq that identifies their row -- the same rule as a + // peer note, and shut by default like everything else in this transcript that is not what was + // said. + var expandedThinking by remember { mutableStateOf(setOf()) } // Which memory notes are open, by the note's own text. Held here rather than in the card so a // note opened and scrolled past is still open on the way back. var openMemories by remember { mutableStateOf(setOf()) } @@ -500,40 +504,35 @@ fun SessionScreen( // clear move this as much as a turn does. See `contextAfter`. contextTokens = contextAfter(contextTokens, entry.event) contextLimit = contextLimitAfter(contextLimit, entry.event) - when (val event = entry.event) { - // Nothing further: what it carries was folded into the context above. - is SessionEvent.UsageDelta -> {} - else -> { - // What the session says it is set to now, which is the only thing that says it: - // picking from either menu asks, and the answer comes back here. - if (event is SessionEvent.Settings) { - event.model?.let { model = it } - event.permissionMode?.let { permissionMode = it } - } - if (event is SessionEvent.Status) { - // The event's own timestamp, so a compaction that began before this screen - // opened is timed from when it actually began -- and a compaction worth asking - // about is a long one. - compactingSince = - when { - event.state != "compacting" -> null - status == "compacting" -> compactingSince - else -> entry.ts - } - status = event.state - } - if (event is SessionEvent.BackgroundTasks && !isSubagent) { - backgroundTasks = event.count - } - if (!isSubagent) loginOpen = authenticationPromptAfter(loginOpen, event) - // In order, always: one late event recorded ahead of the backlog would fold a - // streamed delta into whatever row happened to be last by then. - // Read on the UI thread (the stream below marshals every frame here). This direct - // check closes the small window before the scroll observer records the gesture. - if (listState.isScrollInProgress && !atNewest) followingNewest = false - if (followingNewest && held.isEmpty()) record(entry) else held = held + entry - } + val event = entry.event + // What the session says it is set to now, which is the only thing that says it: + // picking from either menu asks, and the answer comes back here. + if (event is SessionEvent.Settings) { + event.model?.let { model = it } + event.permissionMode?.let { permissionMode = it } } + if (event is SessionEvent.Status) { + // The event's own timestamp, so a compaction that began before this screen + // opened is timed from when it actually began -- and a compaction worth asking + // about is a long one. + compactingSince = + when { + event.state != "compacting" -> null + status == "compacting" -> compactingSince + else -> entry.ts + } + status = event.state + } + if (event is SessionEvent.BackgroundTasks && !isSubagent) { + backgroundTasks = event.count + } + if (!isSubagent) loginOpen = authenticationPromptAfter(loginOpen, event) + // In order, always: one late event recorded ahead of the backlog would fold a + // streamed delta into whatever row happened to be last by then. + // Read on the UI thread (the stream below marshals every frame here). This direct + // check closes the small window before the scroll observer records the gesture. + if (listState.isScrollInProgress && !atNewest) followingNewest = false + if (followingNewest && held.isEmpty()) record(entry) else held = held + entry } /** @@ -733,11 +732,7 @@ fun SessionScreen( // merges streaming text into the item before it, so replaying an older page through // the live list would glue it onto the newest message rather than its own. var earlier = listOf() - older.forEach { entry -> - if (entry.event !is SessionEvent.UsageDelta) { - earlier = foldEvent(earlier, entry) - } - } + older.forEach { entry -> earlier = foldEvent(earlier, entry) } older.first().seq to earlier } // A stream reset can replace the transcript while the page request is out. Its answer is a @@ -827,11 +822,7 @@ fun SessionScreen( suspend fun open(page: List) { withContext(Dispatchers.IO) { var scratch = listOf() - page.forEach { entry -> - if (entry.event !is SessionEvent.UsageDelta) { - scratch = foldEvent(scratch, entry) - } - } + page.forEach { entry -> scratch = foldEvent(scratch, entry) } warm(replies, scratch) } page.forEach { apply(it) } @@ -1718,6 +1709,8 @@ fun SessionScreen( ) { unit -> when (unit) { is TranscriptUnit.Block -> MarkdownPiece(unit.text, unit.piece, replies) + is TranscriptUnit.ReplyFoot -> + ReplyFooter(unit.ts, unit.tokensPerSecond) is TranscriptUnit.PeerHead -> PeerHeadRow( unit.item, @@ -1808,18 +1801,31 @@ fun SessionScreen( onOpenImage = ::openImage, ) is TranscriptItem.AssistantMsg -> - // A whole assistant row is only ever the reply - // still arriving -- every settled reply is - // flattened into block units instead. Live is - // what earns its blocks a layer each while - // deltas land. - AssistantMessage( - item.text, - replies, - openNotes = openMemories, - onToggleNote = ::toggleMemory, - live = true, - ) + // A whole assistant row is the reply still + // arriving -- every settled reply is flattened + // into block units instead, bar the one frame + // between a reply settling and its parse being + // warm. Live is what earns its blocks a layer + // each while deltas land. + Column { + AssistantMessage( + item.text, + replies, + openNotes = openMemories, + onToggleNote = ::toggleMemory, + live = !item.settled, + ) + // The footer travels with the reply + // whichever way it is drawn, so the line + // does not appear a frame after the rest. + if (item.settled) { + Spacer(Modifier.height(2.dp)) + ReplyFooter( + item.ts, + item.tokensPerSecond, + ) + } + } is TranscriptItem.ToolRun -> ToolCard( tool = item, @@ -1845,6 +1851,25 @@ fun SessionScreen( ) }, ) + is TranscriptItem.ThinkingRow -> + ThinkingCard( + item = item, + expanded = item.seq in expandedThinking, + onToggle = { + toggleAnchored( + row, + closing = + item.seq in expandedThinking, + ) { + expandedThinking = + if ( + item.seq in expandedThinking + ) + expandedThinking - item.seq + else expandedThinking + item.seq + } + }, + ) is TranscriptItem.QuestionCard -> QuestionRow(item, ::answerAll) is TranscriptItem.ErrorMsg -> diff --git a/app/androidApp/src/main/kotlin/com/example/aiapp/SessionUsageBar.kt b/app/androidApp/src/main/kotlin/com/example/aiapp/SessionUsageBar.kt index ca94d23..a67e168 100644 --- a/app/androidApp/src/main/kotlin/com/example/aiapp/SessionUsageBar.kt +++ b/app/androidApp/src/main/kotlin/com/example/aiapp/SessionUsageBar.kt @@ -265,16 +265,25 @@ private fun UsageNote(text: String) { } /** - * "42% -- 2h 15m left": how much is gone, then how long what is left has to last. + * "42% -- 2h 15m left / 5h": how much is gone, then how long what is left has to last, then how + * long the whole window is. * * The percentage on its own does not answer the question it gets asked, which is whether to start * something now; 80% with twenty minutes to go and 80% with four hours to go are opposite answers. * + * The window's *length* is what the provider's own name for it used to carry ("5-hour window"), and + * it is worth more beside the time left than in front of the percentage: "3h 42m left / 5h" says in + * one reading both how much of the cycle is to come and which cycle this is. Where the provider + * reported no duration there is simply nothing after the span -- the name it gave is not a + * measurement of one, so nothing is inferred from it. + * * The window's end has two missing cases, worded differently on purpose; see [WindowEnd]. A window * that is not running gets the percentage and nothing else. */ private fun usageWindowLabel(window: UsageWindow, now: OffsetDateTime): String { - val percent = "${window.label} · ${window.percent.toInt()}%" + val percent = "${window.percent.toInt()}%" + val outOf = + window.durationMinutes?.takeIf { it > 0 }?.let { " / ${formatMillis(it * 60_000)}" } ?: "" return when (val end = windowEnd(window.resetsAt, now)) { // Between blocks a window can have no reset time, and saying so is a fact about nothing: // there is no window to run out. The percentage is the whole answer. @@ -284,7 +293,7 @@ private fun usageWindowLabel(window: UsageWindow, now: OffsetDateTime): String { // Under a minute, including past the end: the number would round to "0m left", which // reads as a measurement rather than as the window having run out. if (end.until < Duration.ofMinutes(1)) "$percent · refresh soon" - else "$percent · ${formatSpan(end.until)} left" + else "$percent · ${formatSpan(end.until)} left$outOf" } } diff --git a/app/androidApp/src/main/kotlin/com/example/aiapp/SpawnScreen.kt b/app/androidApp/src/main/kotlin/com/example/aiapp/SpawnScreen.kt index 3084775..868ff05 100644 --- a/app/androidApp/src/main/kotlin/com/example/aiapp/SpawnScreen.kt +++ b/app/androidApp/src/main/kotlin/com/example/aiapp/SpawnScreen.kt @@ -238,7 +238,7 @@ fun SpawnScreen( // machine that will serve them, which is not always this backend. providerModels.isEmpty() && isLlama -> Text( - "No models on ${machine?.name}. The Models screen downloads " + + "No models on ${machine.name}. The Models screen downloads " + "to the backend; another machine needs the file put there itself.", style = MaterialTheme.typography.bodyMedium, color = MaterialTheme.colorScheme.onSurfaceVariant, diff --git a/app/androidApp/src/main/kotlin/com/example/aiapp/ThinkingCard.kt b/app/androidApp/src/main/kotlin/com/example/aiapp/ThinkingCard.kt new file mode 100644 index 0000000..05eb75c --- /dev/null +++ b/app/androidApp/src/main/kotlin/com/example/aiapp/ThinkingCard.kt @@ -0,0 +1,79 @@ +package com.example.aiapp + +import androidx.compose.foundation.clickable +import androidx.compose.foundation.layout.Column +import androidx.compose.foundation.layout.Row +import androidx.compose.foundation.layout.Spacer +import androidx.compose.foundation.layout.fillMaxWidth +import androidx.compose.foundation.layout.height +import androidx.compose.foundation.layout.padding +import androidx.compose.foundation.layout.width +import androidx.compose.material3.Card +import androidx.compose.material3.CircularProgressIndicator +import androidx.compose.material3.MaterialTheme +import androidx.compose.material3.Text +import androidx.compose.runtime.Composable +import androidx.compose.ui.Alignment +import androidx.compose.ui.Modifier +import androidx.compose.ui.unit.dp + +/** + * A model's working, shut until somebody asks for it. + * + * Shut by default, like a tool call and a memory note and for the same reason: it is not what the + * session said, and left open it puts the reasoning between the question and the answer -- which on + * a small model is most of the conversation. + * + * The heading is the whole of what the reader gets for free, so it carries the one thing worth + * knowing without opening anything: whether this is still going, and if not how long it took. A + * spinner while it runs, because that is the same fact a running command reports and it is drawn + * the same way here. + */ +@Composable +fun ThinkingCard( + item: TranscriptItem.ThinkingRow, + expanded: Boolean, + onToggle: () -> Unit, + modifier: Modifier = Modifier, +) { + Card(modifier.fillMaxWidth().clickable(onClick = onToggle)) { + Column(Modifier.padding(12.dp)) { + Row(verticalAlignment = Alignment.CenterVertically) { + Text(thinkingHeadline(item), style = MaterialTheme.typography.titleSmall) + Spacer(Modifier.width(8.dp)) + if (item.open) { + CircularProgressIndicator( + modifier = Modifier.width(16.dp).height(16.dp), + strokeWidth = 2.dp, + ) + } + } + if (expanded) { + // Plain text rather than markdown: this is a model talking to itself, so its + // half-finished lists and stray backticks are not markup it meant to write, and + // rendering them as such makes the working look like an answer. + Text( + item.text, + style = MaterialTheme.typography.bodySmall, + color = MaterialTheme.colorScheme.onSurfaceVariant, + modifier = Modifier.padding(top = 6.dp), + ) + } + } + } +} + +/** + * "Thinking", "Thought for 12.4s", or "Thought". + * + * The third is the one worth keeping: a block whose turn ended before the model said anything -- + * interrupted, stopped, a process that exited -- was thought about for a length of time nobody + * measured. Naming a span there would be this screen inventing one, and the reader has no way to + * tell an invented one from the rest. + */ +fun thinkingHeadline(item: TranscriptItem.ThinkingRow): String = + when { + item.open -> "Thinking" + item.ms != null -> "Thought for ${formatMillis(item.ms)}" + else -> "Thought" + } diff --git a/app/androidApp/src/main/kotlin/com/example/aiapp/TranscriptItems.kt b/app/androidApp/src/main/kotlin/com/example/aiapp/TranscriptItems.kt index 9abbd67..42c6772 100644 --- a/app/androidApp/src/main/kotlin/com/example/aiapp/TranscriptItems.kt +++ b/app/androidApp/src/main/kotlin/com/example/aiapp/TranscriptItems.kt @@ -65,6 +65,41 @@ sealed class TranscriptItem { val settled: Boolean = false, /** A final value that supersedes provisional deltas behind a page boundary. */ val replacesPrefix: Boolean = false, + /** + * When the reply was sent, in epoch seconds: the time on its newest delta, which is the + * moment it finished rather than the moment it started. + * + * The transcript's own timestamp rather than a clock read here, so every device draws the + * same time under the same reply and a replayed page agrees with the live stream. + */ + val ts: Double = 0.0, + /** + * How fast it was generated, where the provider measured it; null everywhere else. + * + * Folded on from the turn's usage event rather than carried by the text, because it is not + * known until the reply is over. + */ + val tokensPerSecond: Double? = null, + ) : TranscriptItem() + + /** + * The model's working before -- or between -- the things it said. + * + * Its own row rather than part of the reply, and deliberately not a [ToolRun]: a run of tool + * calls collapses into one card, and folding a model's reasoning into "Called 6 tools" would + * file it as one of them. Shut by default, like every other card that is not what was said. + * + * Three states, because two of them are not the same absence. [open] is a block still being + * thought, which is what the spinner is for. A closed one with an [ms] says how long it took; a + * closed one without is a block whose turn ended before anything said -- an interrupted reply, + * a session stopped mid-thought -- and it says so by not naming a duration rather than by + * naming a wrong one. + */ + data class ThinkingRow( + override val seq: Long, + val text: String, + val ms: Long? = null, + val open: Boolean = true, ) : TranscriptItem() data class ToolRun( @@ -256,7 +291,7 @@ private fun runIdFor(items: List, id: String, tool: String): Str * with the seam wherever the reader happened to have paged. */ fun joinPages(earlier: List, later: List): List { - val (older, newer) = healSplitMessage(earlier, later) + val (older, newer) = healSplitThinking(healSplitMessage(earlier, later)) val startedEarlier = older.filterIsInstance().mapTo(mutableSetOf()) { it.id } val endedLater = @@ -314,6 +349,29 @@ private fun healSplitMessage( return earlier.dropLast(1) to (listOf(tail.copy(text = head.text + tail.text)) + later.drop(1)) } +/** + * Rejoins a thinking block the page boundary cut, the same way [healSplitMessage] rejoins a reply. + * + * A block streams a fragment at a time exactly as a reply does, so a boundary lands inside one as + * readily. The older half then holds an open block whose [SessionEvent.ThinkingDone] is on the + * newer page -- so it spun for the rest of the conversation, saying the machine was working on a + * thought it finished minutes ago, and the same working was drawn as two blocks. + * + * Only where the older half is still open: a closed one has its own ending and the two are two + * blocks that happen to meet here. The newer half keeps its identity, for the reason [adoptRun] + * gives -- it is the part already on screen. + */ +private fun healSplitThinking( + pages: Pair, List> +): Pair, List> { + val (earlier, later) = pages + val head = earlier.lastOrNull() + val tail = later.firstOrNull() + if (head !is TranscriptItem.ThinkingRow || tail !is TranscriptItem.ThinkingRow) return pages + if (!head.open) return pages + return earlier.dropLast(1) to (listOf(tail.copy(text = head.text + tail.text)) + later.drop(1)) +} + /** * Hands the older calls at the join the name of the run they are joining. * @@ -403,7 +461,7 @@ fun foldEvent(items: List, entry: SeqEvent): List, entry: SeqEvent): List { val last = items.lastOrNull() if (last is TranscriptItem.AssistantMsg && !last.settled) { - items.dropLast(1) + last.copy(text = event.text, replacesPrefix = true) + items.dropLast(1) + + last.copy(text = event.text, replacesPrefix = true, ts = entry.ts) } else { val between = if (last is TranscriptItem.AssistantMsg) @@ -429,9 +488,23 @@ fun foldEvent(items: List, entry: SeqEvent): List { + // Deltas grow the open block, keeping the seq of the first of them, for the same + // reason a reply's do: a row whose identity changed per delta is a new row per frame. + val last = items.lastOrNull() + if (last is TranscriptItem.ThinkingRow && last.open) { + items.dropLast(1) + last.copy(text = last.text + event.delta) + } else { + items + TranscriptItem.ThinkingRow(entry.seq, event.delta) + } + } + // The newest block still open, rather than whatever row happens to be last. + is SessionEvent.ThinkingDone -> + closeThinking(items) { it.copy(ms = event.ms, open = false) } is SessionEvent.ToolStart -> // A call id names one call for its whole lifetime. Codex can repeat the start while // recovering an in-flight item; appending that replay made two rows with one key, and @@ -553,8 +626,16 @@ fun foldEvent(items: List, entry: SeqEvent): List items - // Screen-level state, not transcript rows -- see SessionScreen. - is SessionEvent.UsageDelta -> items + // No row of its own -- the counts are screen-level state, see SessionScreen -- but the + // generation speed belongs under the reply it measured, and this is where that reply ends. + // Only onto the newest row, and only when that row is a reply: a turn whose usage arrives + // after a tool call has nothing here to put it on, which draws as a footer without it. + is SessionEvent.UsageDelta -> + when (val last = items.lastOrNull()) { + is TranscriptItem.AssistantMsg -> + items.dropLast(1) + last.copy(tokensPerSecond = event.tokensPerSecond) + else -> items + } is SessionEvent.ContextWindow -> items } @@ -566,9 +647,22 @@ fun foldEvent(items: List, entry: SeqEvent): List, state: String): List { if (sessionWorking(state)) return items - val last = items.lastOrNull() as? TranscriptItem.AssistantMsg ?: return items - if (last.settled) return items - return items.dropLast(1) + last.copy(settled = true) + // A block the turn ended in the middle of is over, however it ended. Left open it spins for + // the rest of the conversation, which says the machine is working when nothing is. + val ended = closeThinking(items) { it.copy(open = false) } + val last = ended.lastOrNull() as? TranscriptItem.AssistantMsg ?: return ended + if (last.settled) return ended + return ended.dropLast(1) + last.copy(settled = true) +} + +/** [change] applied to the newest thinking block still open, if there is one. */ +private fun closeThinking( + items: List, + change: (TranscriptItem.ThinkingRow) -> TranscriptItem.ThinkingRow, +): List { + val at = items.indexOfLast { it is TranscriptItem.ThinkingRow && it.open } + if (at < 0) return items + return items.toMutableList().apply { this[at] = change(this[at] as TranscriptItem.ThinkingRow) } } private fun updateTool( diff --git a/app/androidApp/src/main/kotlin/com/example/aiapp/TranscriptUnits.kt b/app/androidApp/src/main/kotlin/com/example/aiapp/TranscriptUnits.kt index 2733f54..80a88b9 100644 --- a/app/androidApp/src/main/kotlin/com/example/aiapp/TranscriptUnits.kt +++ b/app/androidApp/src/main/kotlin/com/example/aiapp/TranscriptUnits.kt @@ -130,6 +130,24 @@ sealed class TranscriptUnit { get() = "u$seq:$ordinal" } + /** + * The line under a finished reply: when it was sent, and how fast it was generated. + * + * A unit of its own rather than something drawn inside the last block, because a settled reply + * *is* its blocks -- there is no row left to hang it on, and the last block is a piece of + * markdown that knows nothing about the message it came from. + */ + data class ReplyFoot( + override val seq: Long, + override val ordinal: Int, + val ts: Double, + val tokensPerSecond: Double?, + override val gap: Dp, + ) : TranscriptUnit() { + override val key: Any + get() = "f$seq" + } + /** One memory note of a settled reply; see [MemoryNote]. */ data class Memory( override val seq: Long, @@ -237,6 +255,18 @@ fun transcriptUnits( } } } + // Unconditional, because being in this branch is what says the reply is over: + // [splitWanted] is settled-or-overtaken. The case to keep out is a message still + // arriving, whose "sent at" is not yet the one it ends up with, and that is drawn + // whole. + units += + TranscriptUnit.ReplyFoot( + row.startSeq, + ordinal, + item.ts, + item.tokensPerSecond, + gap(FOOT_SPACING), + ) } else { units += TranscriptUnit.Whole(row, rowGap) } @@ -280,6 +310,14 @@ fun unwarmedReplies(rows: List, replies: ParsedReplies): List "peer block" is TranscriptUnit.UserChunk -> "user slice" is TranscriptUnit.Memory -> "memory note" + is TranscriptUnit.ReplyFoot -> "reply footer" is TranscriptUnit.Whole -> when (val row = row) { is TranscriptRow.Tools -> "tool group" diff --git a/app/androidApp/src/test/kotlin/com/example/aiapp/ThinkingTest.kt b/app/androidApp/src/test/kotlin/com/example/aiapp/ThinkingTest.kt new file mode 100644 index 0000000..fb77f69 --- /dev/null +++ b/app/androidApp/src/test/kotlin/com/example/aiapp/ThinkingTest.kt @@ -0,0 +1,137 @@ +package com.example.aiapp + +import java.time.ZoneId +import kotlin.test.Test +import kotlin.test.assertEquals +import kotlin.test.assertNull +import kotlin.test.assertTrue + +/** + * The model's working as its own row, and the line under a finished reply. + * + * Both have the same shape of hazard: a state nothing measured must not come out looking like one + * that was. A block interrupted mid-thought has no duration, and a provider that reports no + * generation speed has no figure -- neither may borrow one. + */ +class ThinkingTest { + private var seq = 0L + + private fun fold(items: List, event: SessionEvent, ts: Double = 1.0) = + foldEvent(items, SeqEvent(seq = ++seq, ts = ts, event = event)) + + private fun fold(vararg events: SessionEvent) = + events.fold(emptyList()) { items, event -> fold(items, event) } + + private fun thinking(items: List) = + items.filterIsInstance() + + @Test + fun `deltas accumulate into one block that ends with its duration`() { + val items = + fold( + SessionEvent.Thinking("the user "), + SessionEvent.Thinking("wants a card"), + SessionEvent.ThinkingDone(12_400), + SessionEvent.AssistantText("Here it is."), + ) + val block = thinking(items).single() + assertEquals("the user wants a card", block.text) + assertEquals(12_400, block.ms) + assertEquals("Thought for 12.4s", thinkingHeadline(block)) + // Its own row, above the reply rather than inside it. + assertEquals(1, items.filterIsInstance().size) + } + + @Test + fun `a block the turn ended in the middle of stops without naming a span`() { + val items = fold(SessionEvent.Thinking("half a thought"), SessionEvent.Status("idle")) + val block = thinking(items).single() + assertNull(block.ms) + assertTrue(!block.open) + assertEquals("Thought", thinkingHeadline(block)) + } + + @Test + fun `a block still being thought says so`() { + val block = thinking(fold(SessionEvent.Thinking("hmm"))).single() + assertTrue(block.open) + assertEquals("Thinking", thinkingHeadline(block)) + } + + @Test + fun `thinking between two replies is two replies and two blocks`() { + val items = + fold( + SessionEvent.Thinking("first"), + SessionEvent.ThinkingDone(1_000), + SessionEvent.AssistantText("One."), + SessionEvent.Thinking("second"), + SessionEvent.ThinkingDone(2_000), + SessionEvent.AssistantText("Two."), + ) + assertEquals(listOf("first", "second"), thinking(items).map { it.text }) + assertEquals( + listOf("One.", "Two."), + items.filterIsInstance().map { it.text }, + ) + } + + @Test + fun `a reply carries when it was sent and what it was generated at`() { + val items = + fold(emptyList(), SessionEvent.AssistantText("Done."), ts = 1_788_609_600.0).let { + fold(it, SessionEvent.UsageDelta(42, 100, 18.37)) + } + val reply = items.filterIsInstance().single() + assertEquals(1_788_609_600.0, reply.ts) + assertEquals(18.37, reply.tokensPerSecond) + + val footer = replyFooterText(reply.ts, reply.tokensPerSecond, ZoneId.of("UTC")) + // The clock reading rather than the whole string: the platform's own short-time format + // differs by JDK and locale, which is the point of asking it for one. + assertTrue(footer!!.contains("12:00"), footer) + assertTrue(footer.endsWith("18.4 tok/s"), footer) + } + + @Test + fun `a provider that measures no speed gets a footer of the time alone`() { + val footer = replyFooterText(1_788_609_600.0, null, ZoneId.of("UTC")) + assertTrue(footer!!.contains("12:00"), footer) + assertTrue(!footer.contains("tok/s"), footer) + // And a reply with neither has no line at all rather than an empty one. + assertNull(replyFooterText(0.0, null, ZoneId.of("UTC"))) + } + + @Test + fun `a block cut by a page boundary is one block, and it is not still going`() { + // Each page folded on its own, as the app does: the older one holds the fragments before + // the cut and no ending, the newer one the rest and the ending. + val older = fold(SessionEvent.Thinking("half a ")) + val newer = fold(SessionEvent.Thinking("thought"), SessionEvent.ThinkingDone(2_000)) + + val joined = joinPages(older, newer) + val block = thinking(joined).single() + assertEquals("half a thought", block.text) + assertEquals(2_000, block.ms) + assertTrue(!block.open) + } + + @Test + fun `two blocks meeting at a page boundary stay two`() { + val older = fold(SessionEvent.Thinking("first"), SessionEvent.ThinkingDone(1_000)) + val newer = fold(SessionEvent.Thinking("second"), SessionEvent.ThinkingDone(2_000)) + assertEquals(listOf("first", "second"), thinking(joinPages(older, newer)).map { it.text }) + } + + @Test + fun `usage that lands after a tool call is not folded onto an older reply`() { + val items = + fold( + SessionEvent.AssistantText("Reading it."), + SessionEvent.ToolStart("t1", "Read", "{}"), + SessionEvent.ToolEnd("t1", "done"), + SessionEvent.UsageDelta(42, 100, 18.0), + ) + assertNull(items.filterIsInstance().single().tokensPerSecond) + } +} diff --git a/server/src/session/claude/translate.rs b/server/src/session/claude/translate.rs index 4957405..06f646f 100644 --- a/server/src/session/claude/translate.rs +++ b/server/src/session/claude/translate.rs @@ -425,7 +425,11 @@ impl Translator { } let context = self.context.take(); if tokens > 0 { - events.push(Event::UsageDelta { tokens, context }); + events.push(Event::UsageDelta { + tokens, + context, + tokens_per_second: None, + }); } // A level snapshot is authoritative at a turn boundary. In // particular, it repairs a task whose terminal edge was @@ -2548,7 +2552,8 @@ mod tests { vec![ Event::UsageDelta { tokens: 182, - context: None + context: None, + tokens_per_second: None, }, Event::Status { state: SessionStatus::Idle @@ -2590,7 +2595,8 @@ mod tests { }, Event::UsageDelta { tokens: 7, - context: None + context: None, + tokens_per_second: None, }, Event::Status { state: SessionStatus::Idle @@ -2644,6 +2650,7 @@ mod tests { Some(&Event::UsageDelta { tokens: 173, context: Some(26_131), + tokens_per_second: None, }) ); @@ -2660,6 +2667,7 @@ mod tests { Some(&Event::UsageDelta { tokens: 13, context: None, + tokens_per_second: None, }) ); } diff --git a/server/src/session/codex/translate.rs b/server/src/session/codex/translate.rs index 9501695..b9ab353 100644 --- a/server/src/session/codex/translate.rs +++ b/server/src/session/codex/translate.rs @@ -229,6 +229,7 @@ impl Translator { tokens, // Cached input is a subset of this figure, not an additional count. context: last.get("inputTokens").and_then(Value::as_u64), + tokens_per_second: None, }) .into_iter() .collect() @@ -245,6 +246,7 @@ impl Translator { events.push(Event::UsageDelta { tokens: input.unwrap_or(0) + output.unwrap_or(0), context: input, + tokens_per_second: None, }); } } @@ -935,7 +937,8 @@ mod tests { events[0], Event::UsageDelta { tokens: 18, - context: Some(13) + context: Some(13), + tokens_per_second: None, } ); assert!(translator.completed()); @@ -1157,7 +1160,8 @@ mod tests { )), vec![Event::UsageDelta { tokens: 42, - context: Some(39) + context: Some(39), + tokens_per_second: None, }] ); assert_eq!( @@ -1166,7 +1170,8 @@ mod tests { )), vec![Event::UsageDelta { tokens: 65, - context: Some(61) + context: Some(61), + tokens_per_second: None, }] ); assert_eq!( diff --git a/server/src/session/driver.rs b/server/src/session/driver.rs index bc6e96e..780d015 100644 --- a/server/src/session/driver.rs +++ b/server/src/session/driver.rs @@ -212,6 +212,34 @@ pub enum Event { AssistantTextFinal { text: String, }, + /// The model's working, streamed the same way its reply is: the + /// reasoning it produced before -- or between -- the things it said. + /// + /// Its own kind rather than [`Event::AssistantText`], because it is not + /// what the session said. The phone draws it as a card of its own, shut, + /// and no driver folds it back into the next prompt: a provider that + /// wants its own reasoning back sends it back itself. + /// + /// Only a provider that actually streams its working sends this. + /// llama.cpp does, as `reasoning_content`; nothing is inferred for one + /// that does not, since a card that appeared whenever a turn was slow + /// would be a guess wearing a measurement's clothes. + Thinking { + delta: String, + }, + /// The thinking immediately above this finished, having taken `ms`. + /// + /// Measured by the driver rather than worked out by a reader from two + /// event timestamps. A reader only knows when an event *arrived*, so the + /// last delta of a block followed by a slow tool call is indistinguishable + /// from thinking that went on that long -- and a transcript replayed on a + /// phone has to reach the same figure the live stream showed. + /// + /// A block with no end is one still being thought, which is what the card + /// draws a spinner for. + ThinkingDone { + ms: u64, + }, ToolStart { id: String, tool: String, @@ -399,6 +427,17 @@ pub enum Event { /// able to draw. #[serde(default, skip_serializing_if = "Option::is_none")] context: Option, + /// How fast the reply came out, as the provider measured it. + /// + /// `None` wherever nothing measured it, which is most providers: a + /// coding CLI reports what a turn cost and never how long the model + /// took over it, and dividing tokens by the wall time this server + /// waited would count the network, the tool calls and the reader's own + /// permission answers as generation. A figure that is right most of + /// the time is no use here, because nothing on screen could say which + /// times those were. + #[serde(default, skip_serializing_if = "Option::is_none")] + tokens_per_second: Option, }, /// A compaction that finished, and how much context it recovered. /// @@ -850,6 +889,7 @@ mod tests { Event::UsageDelta { tokens: 12, context: Some(30_100), + tokens_per_second: None, } ), Some(30_100) @@ -889,6 +929,7 @@ mod tests { Event::UsageDelta { tokens: 12, context: None, + tokens_per_second: None, } ), Some(30_100) diff --git a/server/src/session/echo.rs b/server/src/session/echo.rs index 6c35421..390d31c 100644 --- a/server/src/session/echo.rs +++ b/server/src/session/echo.rs @@ -666,6 +666,12 @@ impl EchoDriver { let table = text .strip_prefix("/table") .map(|rest| rest.trim().parse::().unwrap_or(6).clamp(1, 12)); + // Seconds to spend thinking before the reply, default three. The rig + // for the thinking card: a block that runs long enough to watch the + // spinner, then ends with a duration to read. + let think = text + .strip_prefix("/think") + .map(|rest| Duration::from_secs(rest.trim().parse::().unwrap_or(3).clamp(1, 600))); let linger = text.strip_prefix("/slow").map(|rest| { Duration::from_secs(rest.trim().parse::().unwrap_or(30).clamp(1, 600)) }); @@ -849,10 +855,31 @@ impl EchoDriver { }); } + if let Some(think) = think { + let started = std::time::Instant::now(); + for remaining in (1..=think.as_secs()).rev() { + send(Event::Thinking { + delta: format!( + "Considering what to echo back, {remaining}s of it left. \ + The reply is the message, which took some working out.\n\n" + ), + }); + tokio::time::sleep(Duration::from_secs(1)).await; + } + // Measured here for the same reason a driver measures it: the + // phone can only see when an event arrived. + send(Event::ThinkingDone { + ms: started.elapsed().as_millis() as u64, + }); + } + + let streaming = std::time::Instant::now(); + let mut words = 0u64; for word in format!("You said: {text}").split_inclusive(' ') { send(Event::AssistantText { delta: word.to_string(), }); + words += 1; tokio::time::sleep(DELTA_DELAY).await; } // A conversation gets bigger, so the pretend context does too: @@ -861,6 +888,12 @@ impl EchoDriver { send(Event::UsageDelta { tokens: spent, context: Some(context.fetch_add(spent + 100, Ordering::SeqCst) + spent + 100), + // A real measurement of a pretend model: what this driver + // emitted, over how long it took. A rig owes the app a figure + // of the shape a real one has, not an invented value. + tokens_per_second: Some(streaming.elapsed().as_secs_f64()) + .filter(|elapsed| *elapsed > 0.0) + .map(|elapsed| words as f64 / elapsed), }); finish(); }); diff --git a/server/src/session/llama/mod.rs b/server/src/session/llama/mod.rs index bfde61e..b9da734 100644 --- a/server/src/session/llama/mod.rs +++ b/server/src/session/llama/mod.rs @@ -1562,9 +1562,12 @@ fn context_window(endpoint: &str) -> Option { /// what happens to them next -- asking, running, reporting -- is the caller's, /// and a call is not in the transcript until it has actually been made. /// -/// `reasoning_content` is dropped, which is what the Claude driver does with -/// thinking deltas. A transcript is what was said, and this app does not draw -/// a model's working. +/// `reasoning_content` is a model's working, and it is emitted as +/// [`Event::Thinking`] rather than mixed into the reply -- its own card, and +/// deliberately not part of what the next prompt is built from (see +/// [`conversation`], which ignores it). The block is closed with +/// [`Event::ThinkingDone`] the moment the model says something else, which is +/// how long it thought for. fn generate( endpoint: &str, messages: &[Message], @@ -1619,6 +1622,24 @@ fn generate( // worst direction for a figure somebody is watching to see how much room // is left. let mut context = None; + // The open thinking block: when it started, so its duration is measured + // where the deltas actually arrive rather than worked out later from two + // timestamps. `None` between blocks -- a turn can think, speak, call a + // tool and think again. + let mut thinking: Option = None; + // What the server says its own generation ran at. Read from it rather than + // divided out of the wall time here, which would count the request, the + // prompt processing and this loop's own scheduling as generation. + let mut per_second = None; + // Closes the open block, which is anything the model says that is not more + // working: the first word of the reply, or a tool call. + let done_thinking = |thinking: &mut Option| { + if let Some(started) = thinking.take() { + shared.emit(Event::ThinkingDone { + ms: started.elapsed().as_millis() as u64, + }); + } + }; for line in std::io::BufRead::lines(reader) { if shared.cancel.load(Ordering::SeqCst) { break; @@ -1642,12 +1663,27 @@ fn generate( tokens = total; context = Some(total); } + if let Some(rate) = chunk + .pointer("/timings/predicted_per_second") + .and_then(Value::as_f64) + { + per_second = Some(rate); + } let Some(delta) = chunk.pointer("/choices/0/delta") else { continue; }; + if let Some(fragment) = delta.get("reasoning_content").and_then(Value::as_str) + && !fragment.is_empty() + { + thinking.get_or_insert_with(std::time::Instant::now); + shared.emit(Event::Thinking { + delta: fragment.to_string(), + }); + } if let Some(fragment) = delta.get("content").and_then(Value::as_str) && !fragment.is_empty() { + done_thinking(&mut thinking); text.push_str(fragment); shared.emit(Event::AssistantText { delta: fragment.to_string(), @@ -1659,11 +1695,20 @@ fn generate( .into_iter() .flatten() { + done_thinking(&mut thinking); absorb(&mut calls, fragment); } } + // A block left open by the end of the stream -- a model that thought and + // then said nothing, or a turn the reader cancelled -- is still a block + // that ended. Without this its card spins for ever. + done_thinking(&mut thinking); if tokens > 0 { - shared.emit(Event::UsageDelta { tokens, context }); + shared.emit(Event::UsageDelta { + tokens, + context, + tokens_per_second: per_second, + }); } // A call whose name never arrived is not a call. It happens when a stream // is cut mid-fragment, and running it would mean inventing what was asked @@ -1815,6 +1860,30 @@ mod tests { ); } + #[test] + /// A model's working is drawn and is deliberately not sent back to it: the + /// prompt is what was said, and feeding reasoning back costs the whole of + /// it in context for a model that never asked to see it again. + fn thinking_is_not_part_of_the_conversation() { + let (_dir, path) = transcript_with(&[ + Event::UserMessage { + id: None, + text: "count".into(), + attachments: Vec::new(), + }, + Event::Thinking { + delta: "the user wants".into(), + }, + Event::ThinkingDone { ms: 1200 }, + Event::AssistantText { + delta: "one two".into(), + }, + ]); + let messages = conversation(&path); + assert_eq!(messages.len(), 2); + assert_eq!(messages[1].content, "one two"); + } + #[test] /// The interrupted case, which decides what a resumed conversation is built /// from: whatever the phone was shown. The deltas that arrived before the @@ -1862,6 +1931,7 @@ mod tests { Event::UsageDelta { tokens: 12, context: Some(12), + tokens_per_second: None, }, ]); let messages = conversation(&path); diff --git a/server/src/session/transcript.rs b/server/src/session/transcript.rs index 24388cf..7485ada 100644 --- a/server/src/session/transcript.rs +++ b/server/src/session/transcript.rs @@ -388,7 +388,12 @@ impl<'a> Indexed<'a> { } /// The newest `limit` *rows* ending at line `end`, with each run of - /// consecutive [`Event::AssistantText`] deltas concatenated into one. + /// consecutive deltas of one streamed kind concatenated into one. + /// + /// Two kinds stream a token at a time -- [`Event::AssistantText`] and + /// [`Event::Thinking`] -- and a run is of one of them, never of both: they + /// are two rows on screen, and welding them would put a model's working + /// inside what it said. /// /// A reply is stored a token at a time, so a window counted in events is a /// fraction of a row for a reply and a whole row for a tool call, and the @@ -404,17 +409,22 @@ impl<'a> Indexed<'a> { fn parse_coalesced(&self, start: usize, end: usize, limit: usize) -> Result> { // Newest first while walking back, reversed to transcript order at the end. let mut out: Vec = Vec::new(); - // The run currently being gathered: its oldest seq/ts so far, and its deltas newest-first. - let mut run: Option<(u64, f64, Vec)> = None; - let flush = |run: &mut Option<(u64, f64, Vec)>, out: &mut Vec| { - if let Some((seq, ts, mut deltas)) = run.take() { + // The run currently being gathered: which kind it is, its oldest + // seq/ts so far, and its deltas newest-first. + let mut run: Option = None; + let flush = |run: &mut Option, out: &mut Vec| { + if let Some(Run { + kind, + seq, + ts, + mut deltas, + }) = run.take() + { deltas.reverse(); out.push(SeqEvent { seq, ts, - event: Event::AssistantText { - delta: deltas.concat(), - }, + event: kind.of_delta(deltas.concat()), }); } }; @@ -428,19 +438,35 @@ impl<'a> Indexed<'a> { } index -= 1; let entry = self.parse_one(index)?; - if let Event::AssistantText { delta } = entry.event { - match run { - Some((ref mut seq, ref mut ts, ref mut deltas)) => { - *seq = entry.seq; - *ts = entry.ts; - deltas.push(delta); + match Streamed::of(entry.event) { + Ok((kind, delta)) => { + // A run of a different kind ends here, whatever it was + // gathering: the two are separate rows. + if run.as_ref().is_some_and(|open| open.kind != kind) { + flush(&mut run, &mut out); + } + match run { + Some(ref mut open) => { + open.seq = entry.seq; + open.ts = entry.ts; + open.deltas.push(delta); + } + None => { + run = Some(Run { + kind, + seq: entry.seq, + ts: entry.ts, + deltas: vec![delta], + }) + } } - None => run = Some((entry.seq, entry.ts, vec![delta])), } - } else { - // The run above this event (newer) is complete: it is a row, and so is this event. - flush(&mut run, &mut out); - out.push(entry); + Err(event) => { + // The run above this event (newer) is complete: it is a row, and so is this + // event. + flush(&mut run, &mut out); + out.push(SeqEvent { event, ..entry }); + } } } flush(&mut run, &mut out); @@ -449,6 +475,41 @@ impl<'a> Indexed<'a> { } } +/// One run of same-kind deltas being gathered by [`Indexed::parse_coalesced`]. +struct Run { + kind: Streamed, + seq: u64, + ts: f64, + deltas: Vec, +} + +/// The event kinds that arrive a fragment at a time and are read as one row. +#[derive(Clone, Copy, PartialEq, Eq)] +enum Streamed { + Text, + Thinking, +} + +impl Streamed { + /// The kind and fragment of a streamed event, or the event back unchanged + /// when it is not one -- so the caller cannot forget to put it back. + fn of(event: Event) -> std::result::Result<(Self, String), Event> { + match event { + Event::AssistantText { delta } => Ok((Self::Text, delta)), + Event::Thinking { delta } => Ok((Self::Thinking, delta)), + other => Err(other), + } + } + + /// The run put back together as the event it was a run of. + fn of_delta(self, delta: String) -> Event { + match self { + Self::Text => Event::AssistantText { delta }, + Self::Thinking => Event::Thinking { delta }, + } + } +} + #[cfg(test)] mod tests { use super::*; @@ -695,6 +756,55 @@ mod tests { ); } + #[test] + /// Thinking streams a fragment at a time exactly as a reply does, so a page + /// counted in rows has to coalesce it too -- otherwise one block of working + /// is a whole page of near-duplicate events. And the two runs stay two: a + /// weld across the boundary would put the model's working inside what it + /// said, in the prompt as well as on screen. + fn thinking_deltas_coalesce_into_a_row_of_their_own() { + let dir = tempfile::tempdir().expect("tempdir"); + let path = dir.path().join("transcript.jsonl"); + let mut transcript = Transcript::open(&path).expect("append"); + for delta in ["think", "ing"] { + transcript + .append( + Event::Thinking { + delta: delta.into(), + }, + 0.0, + ) + .expect("append"); + } + transcript + .append(Event::ThinkingDone { ms: 1200 }, 0.0) + .expect("append"); + for delta in ["said", " it"] { + transcript.append(text(delta), 0.0).expect("append"); + } + + // `before` past the end, since coalescing is only ever done on settled + // history -- see [`read_window`]. + let rows = read_window(&path, Some(6), None, 10, true).expect("window"); + assert_eq!(rows.len(), 3); + assert!(matches!( + &rows[0], + SeqEvent { seq: 1, event: Event::Thinking { delta }, .. } if delta == "thinking" + )); + assert!(matches!( + &rows[1], + SeqEvent { + seq: 3, + event: Event::ThinkingDone { ms: 1200 }, + .. + } + )); + assert!(matches!( + &rows[2], + SeqEvent { seq: 4, event: Event::AssistantText { delta }, .. } if delta == "said it" + )); + } + #[test] fn a_floor_inside_a_delta_run_leaves_the_partial_run_it_cuts() { let dir = tempfile::tempdir().expect("tempdir"); @@ -886,6 +996,7 @@ mod tests { Event::UsageDelta { tokens: 42, context: Some(42), + tokens_per_second: None, }, Event::AuthenticationRequired { message: "sign in again".into(),