fix(buzz-agent): classify read timeouts distinctly in LLM error messages - #4959
Open
wpfleger96 wants to merge 5 commits into
Open
fix(buzz-agent): classify read timeouts distinctly in LLM error messages#4959wpfleger96 wants to merge 5 commits into
wpfleger96 wants to merge 5 commits into
Conversation
reqwest's Display for a read_timeout fire is the opaque 'error sending request for url (...)' — identical to every other pre-response transport failure. An operator reading a log line like transport: error sending request for url (...) (cumulative 721s, 3 attempts) cannot tell whether the call hit a network fault or whether the LLM generation legitimately took longer than BUZZ_AGENT_LLM_TIMEOUT_SECS (default 240s). The latter is common on extended-thinking models (fable-5, opus-5) whose non-streaming turns can exceed 240s — confirmed by a live probe showing 370s wall time for a max-effort generation. Add classify_transport_error() and classify_body_read_error() that check reqwest::Error::is_timeout() and emit a message naming the actual cause and the config knob to raise (BUZZ_AGENT_LLM_TIMEOUT_SECS). Non-timeout errors fall through to the original format strings so no existing diagnostic text is lost. Add is_timeout field to retry warn! events for log-based filtering. Tests use real loopback sockets to produce genuine reqwest::Error values with is_timeout() == true/false. Co-authored-by: Will Pfleger <pfleger.will@gmail.com> Signed-off-by: Will Pfleger <pfleger.will@gmail.com>
…out guard
Read timeouts now emit factual messages — no cause speculation — and
connect timeouts are guarded with is_connect() so they produce
connect-flavored text instead of the read-timeout message.
Previously classify_transport_error said 'likely long generation/thinking'
for any is_timeout() error. Two defects:
- is_connect() && is_timeout() (connect-phase timeout) would produce the
read-timeout text with wrong guidance.
- A mid-flight network partition is indistinguishable from a slow
generation on the client side; asserting a cause is misleading.
New messages:
- connect timeout: 'no connection established within the configured connect timeout'
- read timeout: 'no response bytes received within the configured read timeout
(consider raising BUZZ_AGENT_LLM_TIMEOUT_SECS)'
- body-read timeout: 'no further response bytes received ...' (headers/partial
body already arrived — 'no response bytes' was wrong there too)
Tests: renamed timeout test to _read_timeout_, added is_connect precondition
assertion, added connect-timeout branch test, added no-speculation assertion.
Co-authored-by: Will Pfleger <pfleger.will@gmail.com>
Signed-off-by: Will Pfleger <pfleger.will@gmail.com>
wpfleger96
force-pushed
the
duncan/llm-timeout-classification
branch
from
August 5, 2026 21:13
8bcb980 to
216b898
Compare
…fier, body-read coverage Addresses four Thufir findings on #4959: 1. Duration now appears in every timeout message. A new pure function timeout_message(is_connect, llm_timeout, phase) takes the configured Duration explicitly and renders it verbatim. Connect-phase timeouts show LLM_CONNECT_TIMEOUT (10s); read-phase timeouts show the caller- supplied llm_timeout (BUZZ_AGENT_LLM_TIMEOUT_SECS, default 240s). Both post() and openrouter_post() now accept read_timeout: Duration and thread it to the classifiers; callers pass cfg.llm_timeout. LLM_CONNECT_TIMEOUT is now a named constant (was inline from_secs(10)). 2. Flag-precedence logic is now a pure function. timeout_message takes (is_connect: bool, llm_timeout, phase) rather than &reqwest::Error, so every branch (connect-timeout, transport read-timeout, body-read timeout) is directly testable without network I/O. Four pure #[test] cases cover all branches plus a hardcode-guard for the duration value. The TEST-NET-3 (203.0.113.1) egress test is deleted entirely. 3. Body-read timeout path now has a timeout test. A loopback server sends HTTP 200 with Content-Length:1024 but only 4 bytes of body, then holds the connection open; the client times out on the second chunk. Test asserts 'no further response bytes', the 100ms configured value, and the BUZZ_AGENT_LLM_TIMEOUT_SECS knob. 4. Doc comment corrected: 'at least one body chunk' -> 'headers and possibly body bytes arrived' (a chunk() timeout can fire before the first body chunk). Co-authored-by: Will Pfleger <pfleger.will@gmail.com> Signed-off-by: Will Pfleger <pfleger.will@gmail.com>
… loopback The non-timeout classifier test dialled 127.0.0.1:1 relying on the invariant that port 1 is never bound. A privileged or containerised process can bind port 1, making expect_err() host-dependent. Replace with bind-127.0.0.1:0, capture the ephemeral address, drop the listener, then dial the released port. The kernel produces a deterministic connection-refused with no fixed-port assumption and zero network egress beyond loopback. Co-authored-by: Will Pfleger <pfleger.will@gmail.com> Signed-off-by: Will Pfleger <pfleger.will@gmail.com>
bind-then-drop releases the ephemeral port before the dial, leaving a
TOCTOU window where any concurrent binder can claim it. Retain the
listener for the test's lifetime and spawn a task that accepts exactly
one connection and immediately drops the socket. The test holds exclusive
ownership of the address throughout, producing a deterministic
request-class error (not is_timeout()) with no released-port race.
Also strengthen the assertion from starts_with("transport: ") to exact
equality against format!("transport: {err}"), matching the test name's
promise of exact text preservation.
Co-authored-by: Will Pfleger <pfleger.will@gmail.com>
Signed-off-by: Will Pfleger <pfleger.will@gmail.com>
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Problem
When
buzz-agentexhausts retries on a stalled LLM call, the error message reads:That text is reqwest's generic pre-response failure string — identical whether the cause is a TLS abort, a reset connection, or a
read_timeoutfire. An operator reading the log cannot tell whether something broke or whether the LLM generation legitimately took longer than the configured timeout.Root cause (probe-confirmed)
A live probe against
goose-claude-fable-5with a 900s client timeout completed in 370s — well past the defaultBUZZ_AGENT_LLM_TIMEOUT_SECS=240. Extended-thinking models emit zero bytes on non-streaming calls until generation is complete, so reqwest'sread_timeoutfires on byte-silence regardless of whether the server is healthy. The 46× exact-721s stall signatures in production logs (3 × 240s + backoff) are deterministic self-inflicted timeouts, not network faults.Fix
Pure classifier over
{is_connect, llm_timeout, phase}A new
timeout_message(is_connect: bool, llm_timeout: Duration, phase: TimeoutPhase)pure function produces factual messages with the configured duration value embedded verbatim. Two thin wrappers (classify_transport_error,classify_body_read_error) extract the reqwest flags and delegate. The duration reaches the classifiers through a newread_timeout: Durationparameter onpost()andopenrouter_post(); callers passcfg.llm_timeout.Messages emitted
is_connect && is_timeout)connect timeout: no connection established within 10sread timeout: no response bytes received within 240s (consider raising BUZZ_AGENT_LLM_TIMEOUT_SECS)read timeout: no further response bytes received within 240s (consider raising BUZZ_AGENT_LLM_TIMEOUT_SECS)transport: {reqwest text}/body read: {reqwest text}(unchanged)LLM_CONNECT_TIMEOUTis now a namedconst(was inlinefrom_secs(10)).Out of scope by explicit decision: streaming support, changes to
MAX_RETRIESor backoff.Files changed
crates/buzz-agent/src/llm.rs—timeout_messagepure fn +TimeoutPhaseenum +LLM_CONNECT_TIMEOUTconst; two classifier wrappers updated;post()andopenrouter_post()gainread_timeoutparam; tests replaced.Tests
cargo test -p buzz-agent: 397 passed, 0 failed at294ce5897.Pure-function tests (no network):
timeout_message_connect_true_shows_connect_timeout—is_connect=true→ connect-flavored text with 10s value; both phases checkedtimeout_message_transport_phase_shows_read_timeout_and_duration— transport phase includes 240s and config knobtimeout_message_body_read_phase_says_no_further_bytes_and_duration— body phase says "no further", shows 300stimeout_message_duration_is_not_hardcoded— 600s supplied → 600s in output, not 240sLoopback reqwest integration tests:
classify_transport_error_read_timeout_is_loopback_verified— TCP connect succeeds, server sends no bytes; verifies reqwest setsis_timeout && !is_connectand message contains 50ms valueclassify_transport_error_non_timeout_preserves_reqwest_text— controlled accept-then-close on an owned loopback listener → non-timeout error; asserts exacttransport: {err}output equalityclassify_body_read_error_timeout_says_no_further_bytes— loopback server sends headers + 4 bytes of a declared-1024-byte body, then holds; verifiesis_timeout, "no further", 100ms value, config knobNo test performs egress beyond loopback (
127.0.0.1). The TEST-NET-3 dial is deleted.