From b660905098da6b4938ba7534ac726461ed23e9e9 Mon Sep 17 00:00:00 2001 From: iris-ai <4+iris-ai@noreply.localhost> Date: Sat, 19 Sep 2026 15:44:04 -0400 Subject: [PATCH] Say which half of the wait a llama turn is in A turn has two waits in front of the first token and they were one word. `SessionStatus::Loading` was already the model coming off disk; this adds `SessionStatus::Reading` for llama-server processing the prompt -- emitted when the request goes out, cleared by the first thing the model says of any kind, so it covers every generate in a tool loop rather than only the first. Prefill is the expensive half on this machine: measured 9.5s for 6,068 tokens and 22s for 14,068 on the 27B with the GPU to itself. Reported as `running` that was indistinguishable from a model thinking, which is the thing the reader is waiting for. The phone draws both with the working spinner and its own words -- "loading model" and "reading prompt" -- and the session screen's status row now spins for all three busy states instead of only `running`, which is also how `loading` stops being a bare word with nothing moving. Measured while checking the tok/s figure, and recorded in the rigs skill: the 27B holds 55.5 to 50.3 tok/s between 1.5k and 14k of context, so decode decays gently, while the 0.6B on the CPU falls 30.1 to 11.5 over 6k. A shared GPU is a different failure -- the model does not load at all. Verified on the emulator against a real llama session: "loading model" while the server started, then "reading prompt" with the spinner through prompt processing, then the thinking card. Co-Authored-By: Claude Opus 5 --- .claude/skills/ai-app-rigs/SKILL.md | 25 +++++++++++++ AGENTS.md | 8 +++++ PLAN.md | 9 ++++- .../main/kotlin/com/example/aiapp/Events.kt | 2 +- .../kotlin/com/example/aiapp/SessionScreen.kt | 14 ++++++-- .../com/example/aiapp/SessionStatusWords.kt | 13 +++++-- server/src/session/driver.rs | 14 ++++++++ server/src/session/llama/mod.rs | 35 +++++++++++++++++++ 8 files changed, 114 insertions(+), 6 deletions(-) diff --git a/.claude/skills/ai-app-rigs/SKILL.md b/.claude/skills/ai-app-rigs/SKILL.md index 3a7b22d..42d00ca 100644 --- a/.claude/skills/ai-app-rigs/SKILL.md +++ b/.claude/skills/ai-app-rigs/SKILL.md @@ -258,6 +258,31 @@ where it was instead of half-deleted. worth another 7% in a single sample and is deliberately *not* passed — one sample on a virtualised GPU is not a number to hardcode. +- **Prompt processing is the expensive part of a llama turn here, and decode + speed falls only slowly with context.** Taken 2026-09-19 on a free GPU, the + 27B with `--spec-type draft-mtp -np 1`, generating 160 tokens each time: + + | context | decode | prefill of that prompt | + | --- | --- | --- | + | 88 | 43.4 tok/s (cold) | 21s | + | 1,569 | 55.5 tok/s | (model still warming) | + | 6,068 | 53.2 tok/s | 9.5s | + | 14,068 | 50.3 tok/s | 22s | + + So a turn on a long conversation spends tens of seconds before the first + token, and that is what `SessionStatus::Reading` exists to say. The same + sweep on the 0.6B **on the CPU** falls much harder -- 30.1 tok/s at 44 + tokens of context to 11.5 at 6,024 -- which is the shape somebody means by + "it gets slower as the conversation goes on". The figure the app draws is + `timings.predicted_per_second`, decode only, so prefill is never mixed into + it. + +- **A busy GPU is a model that will not load at all**, not a slow one: + `radv/amdgpu: Failed to allocate a buffer` and `failed to load model` while + something else holds VRAM. A 0.6B that had been decoding at 149 tok/s ran at + 16.7 in that window before its server died, so a tok/s figure taken while + the card is shared says nothing about the model. + - **Asking for the head when the file has none is fatal**, not ignored: `context type MTP requested but model doesn't contain MTP layers` and the server exits. Without the flag the same file logs `unused tensor diff --git a/AGENTS.md b/AGENTS.md index 7595a3a..2d3fea2 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -70,6 +70,14 @@ Module-by-module intent is in PLAN.md's "Backend layout". `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`. + **A turn's wait has two halves and says which** (2026-09-19): + `SessionStatus::Loading` is the model coming off disk and + `SessionStatus::Reading` is `llama-server` processing the prompt -- emitted + when the request goes out and cleared by the first thing the model says, of + any kind. Prefill is the expensive half here (~10s at 6k tokens, ~22s at + 14k), and as `running` it looked exactly like thinking. The phone draws + both with the working spinner and its own words, "loading model" and + "reading prompt". **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 52617a7..14ac2b4 100644 --- a/PLAN.md +++ b/PLAN.md @@ -155,7 +155,14 @@ seq N", so there is no separate history path to drift from the live one. - `Answered { id, answer }` — so a question card resolves on every connected device, not just the one that answered. - `Status { state }` — idle / running / awaiting-input / compacting / - **waiting** / exited / unknown. `waiting` (2026-09-06) is the session's own + **loading** / **reading** / **waiting** / exited / unknown. `loading` is a + process that is up and cannot be spoken to yet (a model coming off disk); + `reading` (2026-09-19) is the model holding the prompt and not yet + answering, which on a long conversation is tens of seconds -- measured at + 9.5s for 6,068 tokens and 22s for 14,068 on the 27B here. Reported as + `running` that was indistinguishable from a model thinking, which is the + thing the reader is actually waiting for. Both are working states: nothing + settles and nothing is invited. `waiting` (2026-09-06) is the session's own turn being over while work it started is not: a backgrounded subagent, or a command left running. Its own state because `idle` and it differ in *kind* — `idle` means the session is waiting for a person, and this means it is 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 22d8a42..8ac2551 100644 --- a/app/androidApp/src/main/kotlin/com/example/aiapp/Events.kt +++ b/app/androidApp/src/main/kotlin/com/example/aiapp/Events.kt @@ -357,7 +357,7 @@ fun parseSeqEvent(json: String): SeqEvent { * split mid-stream. */ fun sessionWorking(state: String): Boolean = - state == "running" || state == "compacting" || state == "loading" + state == "running" || state == "compacting" || state == "loading" || state == "reading" /** Whether the latest events still say this session needs an explicit provider login. */ internal fun authenticationPromptAfter(open: Boolean, event: SessionEvent): Boolean = 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 33ab189..458be8b 100644 --- a/app/androidApp/src/main/kotlin/com/example/aiapp/SessionScreen.kt +++ b/app/androidApp/src/main/kotlin/com/example/aiapp/SessionScreen.kt @@ -2628,7 +2628,15 @@ private fun SessionStatusRow( modifier = Modifier.weight(1f).padding(horizontal = 8.dp), ) } - "running" -> { + // The three states with something happening in them and nothing wanted from the + // reader. One branch, because what they share is the spinner -- the machine is busy -- + // and what differs is only which part of the wait this is: the model coming off disk, + // the model reading what it was given, and the model answering. Reading used to be + // reported as running, so the minutes a long conversation spends on prompt processing + // were indistinguishable from a model thinking. + "running", + "reading", + "loading" -> { CircularProgressIndicator( // Smaller than the line beside it, so the row keeps the text's own height: a // control taller than a line re-centres it and knocks it out of line with the @@ -2637,7 +2645,9 @@ private fun SessionStatusRow( strokeWidth = 2.dp, ) Text( - "working", + // "working" rather than "running" for the one that is generating: the word is + // there to say the machine is busy, and the other two say what it is busy at. + if (status == "running") "working" else sessionStatusWord(status, subagent), style = MaterialTheme.typography.labelSmall, color = MaterialTheme.colorScheme.onSurfaceVariant, modifier = Modifier.padding(start = 8.dp), diff --git a/app/androidApp/src/main/kotlin/com/example/aiapp/SessionStatusWords.kt b/app/androidApp/src/main/kotlin/com/example/aiapp/SessionStatusWords.kt index 2fa0513..dc1f619 100644 --- a/app/androidApp/src/main/kotlin/com/example/aiapp/SessionStatusWords.kt +++ b/app/androidApp/src/main/kotlin/com/example/aiapp/SessionStatusWords.kt @@ -25,7 +25,15 @@ fun sessionStatusWord(status: String, subagent: Boolean = false): String = // Not "running": a model coming off disk is not a model answering, and the difference is // minutes. Said in its own word so a first message that waits is explained rather than // looking like a session that has stopped responding. See `SessionStatus::Loading`. - "loading" -> "loading" + // + // "model" rather than "loading" alone, because there are two waits before an answer and + // the reader is entitled to know which one they are in: this one happens once, and + // "reading prompt" below happens on every turn. + "loading" -> "loading model" + // The model has the prompt and has not started answering. Its own word for the same + // reason: a long conversation spends real time here, and reported as "running" it looked + // like a model thinking. See `SessionStatus::Reading`. + "reading" -> "reading prompt" // Its own word, because the state it is easily mistaken for means the opposite: "idle" // invites the reader to type something, and a waiting session is going to carry on without // them. See `SessionStatus::Waiting`. @@ -59,7 +67,8 @@ fun sessionStatusColour(status: String): Color = "compacting" -> commandColor // The same accent as the other states that are busy on their own account, because that is // what this is: something is happening and nothing is wanted from the reader. - "loading" -> commandColor + "loading", + "reading" -> commandColor "waiting" -> waitingColor else -> MaterialTheme.colorScheme.onSurfaceVariant } diff --git a/server/src/session/driver.rs b/server/src/session/driver.rs index 780d015..bde16d3 100644 --- a/server/src/session/driver.rs +++ b/server/src/session/driver.rs @@ -658,6 +658,20 @@ pub enum SessionStatus { /// state -- a driver that reports it is responsible for holding what it /// is sent until it can deliver it -- but this is what says so on screen. Loading, + /// The model is reading what it was given, and has not begun answering. + /// + /// Its own state for the same reason [`SessionStatus::Loading`] is, one + /// level down: prompt processing is work the machine does before a turn + /// produces anything, and on a long conversation it is the part of the + /// wait somebody is looking at. Reported as `Running` it was + /// indistinguishable from a model thinking, which is what the reader is + /// actually waiting to see. + /// + /// It is still a turn in progress -- nothing settles, nothing is invited + /// -- and it is not a measurement of the prompt: it says the request is + /// out and the model has said nothing yet, which for a server serving one + /// slot is what reading the prompt looks like. + Reading, /// The session's own turn is over, but work it started is still going: /// a backgrounded subagent, or a command left running. /// diff --git a/server/src/session/llama/mod.rs b/server/src/session/llama/mod.rs index b9da734..625b6d2 100644 --- a/server/src/session/llama/mod.rs +++ b/server/src/session/llama/mod.rs @@ -1588,6 +1588,12 @@ fn generate( map.insert(key.clone(), value.clone()); } + // Prompt processing starts the moment this is sent and nothing comes back + // until it is done, so this is where the wait somebody is watching begins. + // Cleared by the first thing the model says, whatever kind it is. + shared.emit(Event::Status { + state: SessionStatus::Reading, + }); let mut response = ureq::post(format!("{endpoint}/v1/chat/completions")) .config() // A turn can be long: a slow model on a long prompt, and the whole @@ -1627,6 +1633,9 @@ fn generate( // timestamps. `None` between blocks -- a turn can think, speak, call a // tool and think again. let mut thinking: Option = None; + // Whether the model has produced anything at all yet; until it has, this + // turn is still reading its prompt. + let mut speaking = false; // 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. @@ -1672,6 +1681,12 @@ fn generate( let Some(delta) = chunk.pointer("/choices/0/delta") else { continue; }; + if !speaking && says_something(delta) { + speaking = true; + shared.emit(Event::Status { + state: SessionStatus::Running, + }); + } if let Some(fragment) = delta.get("reasoning_content").and_then(Value::as_str) && !fragment.is_empty() { @@ -1717,6 +1732,26 @@ fn generate( Ok(Reply { text, calls }) } +/// Whether a delta carries anything the model produced, of any kind. +/// +/// The first one of these is the end of prompt processing. The chunk that only +/// opens the message -- `{"role": "assistant", "content": null}` -- is not one, +/// which is why this asks what is *in* the delta rather than that one arrived. +fn says_something(delta: &Value) -> bool { + let said = |key| { + delta + .get(key) + .and_then(Value::as_str) + .is_some_and(|text| !text.is_empty()) + }; + // Not `is_some`: a dialect that sends the key as an explicit null on every + // chunk would end prompt processing on the one that opens the message. + let calling = delta + .get("tool_calls") + .is_some_and(|calls| !calls.is_null()); + said("content") || said("reasoning_content") || calling +} + /// How long one completion may take before the turn is abandoned. const GENERATE_TIMEOUT: std::time::Duration = std::time::Duration::from_secs(1800);