Add Client::chat with the first-byte wait, liveness and error mapping

Implemented-By: OpenCode session (model recorded in docs/implementer-log.md)
This commit is contained in:
2026-09-18 13:37:01 -07:00
parent 3663a1e4d5
commit 60557a0634
4 changed files with 447 additions and 0 deletions
+151
View File
@@ -0,0 +1,151 @@
//! One chat request: the wait for the first byte, the liveness of the stream, and the errors.
//!
//! There is no total deadline anywhere. The only question while waiting for the head is whether
//! bytes are still arriving; silence before the first byte means the slot is busy or the server is
//! loading, and only `slots` can say which. Once bytes flow, the only question is whether they keep
//! arriving, measured by the read timeout, never a wall-clock total.
use std::time::Duration;
use super::assemble::Assembler;
use super::{ChatEvent, ChatRequest, Client, Completion, InferError};
use crate::http::{Connection, Head, HttpError, Request, read_capped};
use crate::llama::info::{MAX_BODY, error_text, map_http};
use crate::llama::request::build_body;
use crate::sse::{Events, SseError, SseItem};
pub const MAX_SSE_LINE: usize = 1024 * 1024;
const CHAT: &str = "/v1/chat/completions";
/// What the wait for the head is doing when it times out.
#[derive(Clone, Copy, PartialEq)]
enum WaitState {
/// The head has started to arrive; no poll is needed.
Idle,
/// The request's own slot is processing.
Busy,
/// The server could not answer `/slots`, so it is loading or restarting.
Unavailable,
}
impl Client {
pub fn chat(
&self,
req: &ChatRequest,
on_event: &mut dyn FnMut(&ChatEvent),
) -> Result<Completion, InferError> {
// 1. Send.
let body_text =
build_body(&self.cfg, req).map_err(|e| InferError::Protocol(e.to_string()))?;
let mut conn = Connection::open(&self.cfg.infer.socket).map_err(map_http)?;
conn.send(&Request {
method: "POST",
path: CHAT,
body: Some(body_text.as_bytes()),
})
.map_err(map_http)?;
// 2. Wait for the head.
let head = wait_for_head(&mut conn, self, req, on_event)?;
// 3. Status.
conn.set_read_timeout(Duration::from_millis(self.cfg.limits.liveness_ms))
.map_err(map_http)?;
if head.status != 200 {
let mut body = conn.body(&head).map_err(map_http)?;
let bytes = read_capped(&mut body, MAX_BODY).map_err(map_http)?;
return Err(InferError::Http {
status: head.status,
body: error_text(&bytes),
});
}
// 4. Stream.
let mut body = conn.body(&head).map_err(map_http)?;
let mut events = Events::new(&mut body, MAX_SSE_LINE);
let mut assembler = Assembler::new();
loop {
match events.next_item() {
Ok(Some(SseItem::Data(text))) => {
for event in assembler.push(&text)? {
on_event(&event);
}
}
Ok(Some(SseItem::Done)) | Ok(None) => break,
Err(SseError::Timeout) => return Err(InferError::Stalled),
Err(SseError::Truncated) => return Err(InferError::StreamClosedEarly),
Err(e) => return Err(InferError::Protocol(e.to_string())),
}
}
// 5. Finish. A stream that ended without a finish_reason is a server that died between two
// events.
assembler.finish(false)
}
}
/// Reads the head of the chat response, waiting out a busy, unavailable or idle slot as it goes.
fn wait_for_head(
conn: &mut Connection,
client: &Client,
req: &ChatRequest,
on_event: &mut dyn FnMut(&ChatEvent),
) -> Result<Head, InferError> {
let poll = Duration::from_millis(client.cfg.limits.poll_ms);
conn.set_read_timeout(poll).map_err(map_http)?;
let mut prev: Option<WaitState> = None;
let mut since: Duration = Duration::ZERO;
loop {
match conn.read_head() {
Ok(head) => return Ok(head),
Err(HttpError::Timeout) => {}
Err(e) => return Err(map_http(e)),
}
let received = conn.received_any();
let (state, busy) = if received {
(WaitState::Idle, false)
} else {
match client.slots() {
Ok(slots) => {
let busy = slots
.iter()
.find(|s| s.id == req.slot)
.map(|s| s.is_processing)
.unwrap_or(false);
(
if busy {
WaitState::Busy
} else {
WaitState::Idle
},
busy,
)
}
Err(_) => (WaitState::Unavailable, false),
}
};
// A poll was made exactly when the head had not started to arrive.
if !received {
on_event(&ChatEvent::Waiting { slot_busy: busy });
}
since = if prev == Some(state) {
since + poll
} else {
poll
};
prev = Some(state);
let wait_for = match state {
WaitState::Busy => client.cfg.limits.busy_wait_ms,
WaitState::Unavailable => client.cfg.limits.load_wait_ms,
WaitState::Idle => client.cfg.limits.idle_grace_ms,
};
if since >= Duration::from_millis(wait_for) {
return Err(match state {
WaitState::Busy => InferError::WaitTimeout,
WaitState::Unavailable => InferError::LoadTimeout,
WaitState::Idle => InferError::Stalled,
});
}
}
}
+1
View File
@@ -1,6 +1,7 @@
//! The llama inference server's chat-completions types and the request builder. //! The llama inference server's chat-completions types and the request builder.
pub mod assemble; pub mod assemble;
pub mod chat;
pub mod info; pub mod info;
pub mod request; pub mod request;
+294
View File
@@ -0,0 +1,294 @@
//! Tests for one request: events, waits, liveness and errors. Do not edit.
//!
//! Limits come from `support::test_config`: poll 40 ms, busy wait 400 ms, load wait 300 ms,
//! idle grace 200 ms, liveness 150 ms.
mod support;
use loopd::llama::{ChatEvent, ChatMessage, ChatRequest, Client, FinishReason, InferError};
use std::time::{Duration, Instant};
use support::{FakeServer, Reply};
const CHAT: &str = "/v1/chat/completions";
const IDLE: &str = r#"[{"id":0,"is_processing":false},{"id":1,"is_processing":false}]"#;
const SLOT0_BUSY: &str = r#"[{"id":0,"is_processing":true},{"id":1,"is_processing":false}]"#;
const SLOT1_BUSY: &str = r#"[{"id":0,"is_processing":false},{"id":1,"is_processing":true}]"#;
fn request() -> ChatRequest {
ChatRequest {
slot: 0,
messages: vec![ChatMessage::User {
content: "hi".to_string(),
}],
tools: vec![],
thinking: false,
}
}
fn run(
server: &FakeServer,
) -> (
Result<loopd::llama::Completion, InferError>,
Vec<ChatEvent>,
Duration,
) {
let client = Client::new(support::test_config(&server.socket));
let mut events = Vec::new();
let started = Instant::now();
let result = client.chat(&request(), &mut |e| events.push(e.clone()));
(result, events, started.elapsed())
}
fn waiting(events: &[ChatEvent]) -> Vec<bool> {
events
.iter()
.filter_map(|e| match e {
ChatEvent::Waiting { slot_busy } => Some(*slot_busy),
_ => None,
})
.collect()
}
#[test]
fn a_recorded_completion_comes_back_whole() {
let server = FakeServer::start();
server.route(CHAT, vec![Reply::fixture("tool_call")]);
let (result, events, _) = run(&server);
let done = result.unwrap();
let want = support::expected("tool_call");
assert_eq!(done.finish_reason, FinishReason::ToolCalls);
assert_eq!(done.content.as_deref(), want["content"].as_str());
assert_eq!(done.tool_calls[0].arguments, r#"{"path":"/etc/hostname"}"#);
assert_eq!(done.timings.prompt_n, 312);
assert!(!done.thinking_capped);
assert!(
waiting(&events).is_empty(),
"the answer came at once, so nothing was polled"
);
assert!(matches!(
events.first(),
Some(ChatEvent::Progress { total: 312, .. })
));
let sent = &server.requests_to(CHAT)[0];
assert_eq!(sent.method, "POST");
assert_eq!(sent.json()["messages"][0]["content"], "hi");
assert_eq!(sent.json()["id_slot"], 0);
}
#[test]
fn the_result_does_not_depend_on_how_the_bytes_arrive() {
for piece in [1, 17, 4096] {
let server = FakeServer::start();
server.route(CHAT, vec![Reply::fixture("thinking").trickle(piece, 0)]);
let done = run(&server).0.unwrap();
let want = support::expected("thinking");
assert_eq!(
done.content.as_deref(),
want["content"].as_str(),
"pieces of {piece}"
);
assert_eq!(
done.reasoning_content.as_deref(),
want["reasoning_content"].as_str()
);
assert_eq!(done.reasoning_tokens, 49);
}
}
#[test]
fn a_busy_slot_is_waited_out() {
let server = FakeServer::start();
server.route(CHAT, vec![Reply::fixture("plain").head_delay(250)]);
server.route("/slots", vec![Reply::json(200, SLOT0_BUSY)]);
let (result, events, took) = run(&server);
assert!(result.is_ok(), "{result:?}");
let polls = waiting(&events);
assert!(polls.len() >= 4, "250 ms at 40 ms per poll: {polls:?}");
assert!(polls.iter().all(|busy| *busy));
assert!(took >= Duration::from_millis(250));
assert!(server.requests_to("/slots").len() >= 4);
assert_eq!(
server.requests_to("/slots")[0].target,
"/slots?model=test-model"
);
}
#[test]
fn a_slot_that_stays_busy_is_a_wait_timeout() {
let server = FakeServer::start();
server.route(CHAT, vec![Reply::fixture("plain").head_delay(5_000)]);
server.route("/slots", vec![Reply::json(200, SLOT0_BUSY)]);
let (result, events, took) = run(&server);
assert!(matches!(result, Err(InferError::WaitTimeout)), "{result:?}");
assert!(
took >= Duration::from_millis(400) && took < Duration::from_millis(1500),
"{took:?}"
);
assert!(waiting(&events).iter().all(|busy| *busy));
}
#[test]
fn only_the_requests_own_slot_counts_as_busy() {
// Slot 1 is busy, slot 0 (ours) is idle and silent: that is a stall, not a queue.
let server = FakeServer::start();
server.route(CHAT, vec![Reply::fixture("plain").head_delay(5_000)]);
server.route("/slots", vec![Reply::json(200, SLOT1_BUSY)]);
let (result, events, took) = run(&server);
assert!(matches!(result, Err(InferError::Stalled)), "{result:?}");
assert!(
took >= Duration::from_millis(200) && took < Duration::from_millis(1000),
"{took:?}"
);
assert!(waiting(&events).iter().all(|busy| !*busy));
}
#[test]
fn an_unavailable_server_is_a_load_timeout() {
for slots_reply in [
Reply::json(503, r#"{"error":"loading"}"#),
Reply::raw("").cut_after(0),
] {
let server = FakeServer::start();
server.route(CHAT, vec![Reply::fixture("plain").head_delay(5_000)]);
server.route("/slots", vec![slots_reply]);
let (result, _, took) = run(&server);
assert!(matches!(result, Err(InferError::LoadTimeout)), "{result:?}");
assert!(
took >= Duration::from_millis(300) && took < Duration::from_millis(1500),
"{took:?}"
);
}
}
#[test]
fn the_wait_clocks_restart_when_the_state_changes() {
// Busy for about 5 polls, then idle: the idle grace starts counting from there, so the
// request outlives 200 ms of busy plus most of the 200 ms grace and then completes.
let server = FakeServer::start();
server.route(CHAT, vec![Reply::fixture("plain").head_delay(330)]);
let busy = Reply::json(200, SLOT0_BUSY);
server.route(
"/slots",
vec![
busy.clone(),
busy.clone(),
busy.clone(),
busy.clone(),
busy,
Reply::json(200, IDLE),
],
);
let (result, events, _) = run(&server);
assert!(result.is_ok(), "{result:?}");
let polls = waiting(&events);
assert!(
polls.starts_with(&[true, true, true, true, true]),
"{polls:?}"
);
assert_eq!(polls.last(), Some(&false), "{polls:?}");
}
#[test]
fn silence_in_mid_stream_is_a_stall() {
let server = FakeServer::start();
let reply = Reply::fixture("thinking");
let cut = reply.offset_after_events(10);
server.route(CHAT, vec![reply.hang_after(cut, 5_000)]);
let (result, events, took) = run(&server);
assert!(matches!(result, Err(InferError::Stalled)), "{result:?}");
assert!(
took >= Duration::from_millis(150) && took < Duration::from_millis(1000),
"{took:?}"
);
assert!(
events.iter().any(|e| matches!(e, ChatEvent::Reasoning(_))),
"events before the stall were delivered"
);
}
#[test]
fn a_slow_but_steady_stream_is_not_a_stall() {
// 60 ms between pieces is well inside the 150 ms liveness limit, however long the whole takes.
let server = FakeServer::start();
let size = support::fixture_bytes("http", "turn1.http").len();
server.route(CHAT, vec![Reply::fixture("turn1").trickle(size / 8, 60)]);
let (result, _, took) = run(&server);
assert_eq!(result.unwrap().content.as_deref(), Some("Blue"));
assert!(
took >= Duration::from_millis(400),
"the stream took longer than the liveness limit: {took:?}"
);
}
#[test]
fn a_stream_that_is_cut_is_closed_early_wherever_the_cut_falls() {
let reply = Reply::fixture("plain");
let whole = support::fixture_bytes("http", "plain.http").len();
let after_five = reply.offset_after_events(5);
// After the head only; in the middle of an event; between events; just before [DONE].
for cut in [300, after_five + 20, after_five, whole - 30] {
let server = FakeServer::start();
server.route(CHAT, vec![reply.clone().cut_after(cut)]);
let (result, _, _) = run(&server);
assert!(
matches!(result, Err(InferError::StreamClosedEarly)),
"cut at {cut}: {result:?}"
);
}
// Cut before the head is complete.
let server = FakeServer::start();
server.route(CHAT, vec![reply.cut_after(40)]);
assert!(matches!(run(&server).0, Err(InferError::StreamClosedEarly)));
}
#[test]
fn error_statuses_keep_their_body() {
let server = FakeServer::start();
server.route(CHAT, vec![Reply::fixture("bad_request")]);
match run(&server).0 {
Err(InferError::Http { status: 400, body }) => {
assert!(body.contains("Expected 'messages'"), "{body}")
}
other => panic!("{other:?}"),
}
let server = FakeServer::start();
server.route(
CHAT,
vec![Reply::json(503, r#"{"error":{"message":"Loading model"}}"#)],
);
assert!(matches!(
run(&server).0,
Err(InferError::Http { status: 503, .. })
));
}
#[test]
fn garbage_in_the_stream_is_a_protocol_error() {
let server = FakeServer::start();
let raw = "HTTP/1.1 200 OK\r\nContent-Type: text/event-stream\r\n\r\ndata: {not json}\n\n";
server.route(CHAT, vec![Reply::raw(raw)]);
assert!(matches!(run(&server).0, Err(InferError::Protocol(_))));
let server = FakeServer::start();
let huge = format!(
"HTTP/1.1 200 OK\r\n\r\ndata: {}\n\n",
"x".repeat(2 * 1024 * 1024)
);
server.route(CHAT, vec![Reply::raw(huge)]);
assert!(
matches!(run(&server).0, Err(InferError::Protocol(_))),
"a line over 1 MiB"
);
}
#[test]
fn no_server_is_a_connect_error() {
let server = FakeServer::start();
let mut cfg = support::test_config(&server.socket);
cfg.infer.socket = std::env::temp_dir().join("loopd-no-such-socket.sock");
let result = Client::new(cfg).chat(&request(), &mut |_| {});
assert!(matches!(result, Err(InferError::Connect(_))), "{result:?}");
let e: Box<dyn std::error::Error> = Box::new(InferError::Stalled);
assert!(!e.to_string().is_empty());
}
+1
View File
@@ -24,6 +24,7 @@ reviewer adds findings under "Reviews" once per milestone.
| M2a/07-llama-assemble | 2026-09-18 | done | 3 | fail | none | Wrote crates/loopd/src/llama/assemble.rs (Assembler plus server-format Chunk/Choice/Delta/ToolCallPiece/FunctionPiece/PromptProgress structs with no deny_unknown_fields) and registered `pub mod assemble;`. Accumulation: text goes through get_or_insert_with so content/reasoning stay None until a non-empty piece arrives; tool-call pieces land by index via u32::try_from then usize::try_from and get_mut, a new call only at exactly the end, a skip-ahead or an out-of-range index is Protocol; timings update before the reasoning-token count reads predicted_n; finish checks finish_reason (StreamClosedEarly), then id, then every tool call has id and name. First gate failed on two clippy collapsible_if lints; rewrote the two nested ifs as edition-2024 let-chains and re-ran. All 7 assemble tests pass; `make gate` prints `gate: ok`. | GLM-5.3 (z.ai, default settings) | | M2a/07-llama-assemble | 2026-09-18 | done | 3 | fail | none | Wrote crates/loopd/src/llama/assemble.rs (Assembler plus server-format Chunk/Choice/Delta/ToolCallPiece/FunctionPiece/PromptProgress structs with no deny_unknown_fields) and registered `pub mod assemble;`. Accumulation: text goes through get_or_insert_with so content/reasoning stay None until a non-empty piece arrives; tool-call pieces land by index via u32::try_from then usize::try_from and get_mut, a new call only at exactly the end, a skip-ahead or an out-of-range index is Protocol; timings update before the reasoning-token count reads predicted_n; finish checks finish_reason (StreamClosedEarly), then id, then every tool call has id and name. First gate failed on two clippy collapsible_if lints; rewrote the two nested ifs as edition-2024 let-chains and re-ran. All 7 assemble tests pass; `make gate` prints `gate: ok`. | GLM-5.3 (z.ai, default settings) |
| M2a/08-llama-info | 2026-09-18 | done | 2 | fail | none | Wrote crates/loopd/src/llama/info.rs and registered `pub mod info;`. `call` is one exchange: open socket, set read timeout to `liveness_ms`, send, read head, `read_capped` with `MAX_BODY`; non-200 returns `InferError::Http { status, error_text(&bytes) }`, everything else maps through `map_http` (Connect->Connect, Timeout->Stalled, Closed->StreamClosedEarly, else->Protocol). `error_text` reads the full body via `from_utf8_lossy` then backs up from byte 4096 to a char boundary, so a cut mid-character does not panic. `props` reads `chat_template`, `total_slots`, and `default_generation_settings.n_ctx` from the JSON (unknown fields ignored); `slots` deserializes `Vec<SlotInfo>`; `tokenize` POSTs `{"model","content"}` via `serde_json` and returns `tokens.len()`. `cache_outcome` uses `saturating_add` and `current.cache_n + CACHE_TOLERANCE >= expected`. All 7 tests pass; first gate run failed on rustfmt import order, fixed with `cargo fmt --all`. | ? | | M2a/08-llama-info | 2026-09-18 | done | 2 | fail | none | Wrote crates/loopd/src/llama/info.rs and registered `pub mod info;`. `call` is one exchange: open socket, set read timeout to `liveness_ms`, send, read head, `read_capped` with `MAX_BODY`; non-200 returns `InferError::Http { status, error_text(&bytes) }`, everything else maps through `map_http` (Connect->Connect, Timeout->Stalled, Closed->StreamClosedEarly, else->Protocol). `error_text` reads the full body via `from_utf8_lossy` then backs up from byte 4096 to a char boundary, so a cut mid-character does not panic. `props` reads `chat_template`, `total_slots`, and `default_generation_settings.n_ctx` from the JSON (unknown fields ignored); `slots` deserializes `Vec<SlotInfo>`; `tokenize` POSTs `{"model","content"}` via `serde_json` and returns `tokens.len()`. `cache_outcome` uses `saturating_add` and `current.cache_n + CACHE_TOLERANCE >= expected`. All 7 tests pass; first gate run failed on rustfmt import order, fixed with `cargo fmt --all`. | ? |
| M2a/11-llama-gate-retry | 2026-09-18 | stopped | 0 | n/a | none | The prerequisite `chat` is missing, so this task is impossible as written. The branch is at M2a/07 (assemble); task 09 (llama-chat) has not been done and `crates/loopd/src/llama/chat.rs` does not exist. The retry.rs test calls `client.chat()` and `chat_with_retry()`, and the task says to *modify* chat.rs and add the gate inside `chat` — all of which require a `chat` that was never implemented. The gate and retry pieces are independent of chat, but the 13-test suite cannot pass (it does not even compile) without it. Did not read task 09 per AGENTS.md and did not implement chat, which is another task and would be improvising. Committed only this log row; the copied tests/retry.rs was removed. | ? | | M2a/11-llama-gate-retry | 2026-09-18 | stopped | 0 | n/a | none | The prerequisite `chat` is missing, so this task is impossible as written. The branch is at M2a/07 (assemble); task 09 (llama-chat) has not been done and `crates/loopd/src/llama/chat.rs` does not exist. The retry.rs test calls `client.chat()` and `chat_with_retry()`, and the task says to *modify* chat.rs and add the gate inside `chat` — all of which require a `chat` that was never implemented. The gate and retry pieces are independent of chat, but the 13-test suite cannot pass (it does not even compile) without it. Did not read task 09 per AGENTS.md and did not implement chat, which is another task and would be improvising. Committed only this log row; the copied tests/retry.rs was removed. | ? |
| M2a/09-llama-chat | 2026-09-18 | done | 1 | pass | none | Wrote crates/loopd/src/llama/chat.rs (`chat`, with the head wait in a separate `wait_for_head`) and registered `pub mod chat;`. `chat` builds the body (build error -> Protocol), opens and POSTs, then `wait_for_head` loops `read_head` at `poll_ms`: a Timeout is classified Idle/Busy/Unavailable by `received_any` then a `slots()` poll, emits `Waiting { slot_busy }` on every poll, keeps a per-state `since` that resets on state change, and returns `WaitTimeout`/`LoadTimeout`/`Stalled` at the right limits; 200 streams via `Events`+`Assembler` mapping `Timeout->Stalled`, `Truncated->StreamClosedEarly`, else `Protocol`, then `finish(false)`; non-200 returns `Http { status, error_text }`. All 13 chat tests pass five runs in a row. Table-to-test map: state (table 1) Busy -> a_busy_slot_is_waited_out / a_slot_that_stays_busy_is_a_wait_timeout, Idle-not-processing -> only_the_requests_own_slot_counts_as_busy, Unavailable -> an_unavailable_server_is_a_load_timeout, Idle-received_any -> a_slow_but_steady_stream_is_not_a_stall (turn1 head is 738 B, pieces are 3140/8=392 B, so the head-wait times out with a partial head); thresholds (table 2) -> a_slot_that_stays_busy_is_a_wait_timeout / an_unavailable_server_is_a_load_timeout / only_the_requests_own_slot_counts_as_busy; stream (table 3) Data/Done/None -> the recorded completion and trickle tests, Timeout -> silence_in_mid_stream_is_a_stall, Truncated -> a_stream_that_is_cut_is_closed_early_wherever_the_cut_falls, other -> garbage_in_the_stream_is_a_protocol_error; clock-restart -> the_wait_clocks_restart_when_the_state_changes. One path fix: info and request live under crate::llama, not crate::, so the imports use crate::llama::{info::..., request::...}. | ? |
## Reviews ## Reviews