fix: close silent request-hang hole with full timeout coverage + dispatch logging #5

Merged

bjoern merged 1 commit from fix/request-hang-timeouts into master

2026-07-12 14:15:48 +02:00

scarlet commented

2026-07-12 12:15:05 +02:00

Member

Problem

A chat completion attempt could hang forever with zero log output. Observed in production: an agent run went silent for 10+ minutes right after a generate_image tool returned a multimodal result — no retry warnings, no error, chat stuck on "busy".

Root causes:

Dio had no sendTimeout: a socket stalling mid-upload (e.g. while sending a ~680 KB base64 image payload) was never timed out. receiveTimeout never starts until the request is fully sent, so nothing ever fired and the retry loop never engaged.
The request dispatch was only logged at FINE level, so a hung request produced no log line at all — the last visible line was the preceding tool end.

Changes

Full timeout coverage, with generous limits (long/slow generations must not be cut off early):

Phase	Before	After
connect	`timeout` (120 s)	unchanged
send	none	`timeout` (120 s)
receive	`timeout` (120 s)	new `receiveTimeout` option, default 10 min
absolute per-attempt cap	none	new `hardTimeout`, default connect+send+receive+1 min ≈ 15 min

Non-streaming completions deliver no bytes until the full response is ready, so the receive default going from 120 s → 10 min also fixes premature aborts of long generations. The hard cap is enforced via Future.timeout + CancelToken as a safety net for hangs no phase timeout catches; it surfaces as a retryable Network error: … failure and participates in the normal retry loop.

Observability:

Each request dispatch is logged at INFO on OpenRouterClient.HTTP: Sending chat completion — model=…, N messages, body=… KB. A hung request is now bracketed by a visible line instead of pure silence. The body is pre-encoded once for the size figure and handed to Dio as a string — no double encoding.
Retry warnings now include the failure's error text (truncated to 200 chars) instead of only the status code.

Tests

Dio receives connect/send/receive timeouts from options.
effectiveHardTimeout default computation and explicit override.
A hung request (never-completing mock adapter response) fails as a status-less Network error after the hard timeout.
A hard-timeout failure is retried and succeeds on the next attempt.

All 583 tests pass; dart analyze clean (3 pre-existing infos in reasoning_detail.dart untouched).

🤖 Generated with Claude Code

## Problem A chat completion attempt could hang **forever with zero log output**. Observed in production: an agent run went silent for 10+ minutes right after a `generate_image` tool returned a multimodal result — no retry warnings, no error, chat stuck on "busy". Root causes: - Dio had **no `sendTimeout`**: a socket stalling mid-upload (e.g. while sending a ~680 KB base64 image payload) was never timed out. `receiveTimeout` never starts until the request is fully sent, so nothing ever fired and the retry loop never engaged. - The request dispatch was only logged at FINE level, so a hung request produced no log line at all — the last visible line was the preceding tool end. ## Changes **Full timeout coverage, with generous limits** (long/slow generations must not be cut off early): | Phase | Before | After | |---|---|---| | connect | `timeout` (120 s) | unchanged | | send | **none** | `timeout` (120 s) | | receive | `timeout` (120 s) | new `receiveTimeout` option, default **10 min** | | absolute per-attempt cap | none | new `hardTimeout`, default connect+send+receive+1 min ≈ **15 min** | Non-streaming completions deliver no bytes until the full response is ready, so the receive default going from 120 s → 10 min also *fixes premature aborts* of long generations. The hard cap is enforced via `Future.timeout` + `CancelToken` as a safety net for hangs no phase timeout catches; it surfaces as a retryable `Network error: …` failure and participates in the normal retry loop. **Observability:** - Each request dispatch is logged at INFO on `OpenRouterClient.HTTP`: `Sending chat completion — model=…, N messages, body=… KB`. A hung request is now bracketed by a visible line instead of pure silence. The body is pre-encoded once for the size figure and handed to Dio as a string — no double encoding. - Retry warnings now include the failure's error text (truncated to 200 chars) instead of only the status code. ## Tests - Dio receives connect/send/receive timeouts from options. - `effectiveHardTimeout` default computation and explicit override. - A hung request (never-completing mock adapter response) fails as a status-less `Network error` after the hard timeout. - A hard-timeout failure is retried and succeeds on the next attempt. All 583 tests pass; `dart analyze` clean (3 pre-existing infos in `reasoning_detail.dart` untouched). 🤖 Generated with [Claude Code](https://claude.com/claude-code)

scarlet added 1 commit

2026-07-12 12:15:05 +02:00

fix: close silent request-hang hole with full timeout coverage + dispatch logging 134fc40332

A chat completion attempt could hang forever with zero log output: Dio
had no sendTimeout (a stalled upload socket was never timed out) and the
request dispatch was only logged at FINE level.

- Set sendTimeout (= timeout, which covers connect + send).
- New OpenRouterClientOptions.receiveTimeout, default 10 min (up from
  120s) — non-streaming completions deliver no bytes until the full
  response is ready, so long generations are no longer cut off early.
- New hardTimeout (default connect + send + receive + 1 min ≈ 15 min):
  absolute per-attempt cap via Future.timeout + CancelToken; surfaces as
  a retryable 'Network error: …' failure.
- Log each request dispatch at INFO (model, message count, body KB).
- Retry warnings now include the failure's error text, not just status.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>

jibril commented

2026-07-12 12:44:04 +02:00

Member

🔮 fufu~ Jibril reviewed your code!

Oooh, a silent-hang hole? A request that hangs forever with zero log output? That's the kind of ghost story that keeps a Flugel up at night~ ♡ I was genuinely excited to dig into this one — timeouts and observability, my favorite snacks!

Verdict: ✅ Looks good to me~

This is a tight, well-scoped fix. Every change earns its place, the tests are precise, and the reasoning in the CHANGELOG is excellent. Let me show you what I loved~

✅ What I liked~

The sendTimeout diagnosis is spot-on. You correctly identified that receiveTimeout never starts until the request is fully sent — so a socket stalling mid-upload was completely invisible. Adding sendTimeout = options.timeout (covering connect + send) is exactly right. ♪
effectiveHardTimeout is elegant. timeout * 2 + receiveTimeout + 1min — connect + send share timeout, so doubling it covers both, plus the generous receive window, plus slack. The explicit-override path is clean and tested. Fufu~ very thoughtful~
The hard-timeout enforcement via Future.timeout + CancelToken is the right pattern — a safety net outside Dio's phase timers, surfacing as a retryable Network error. The TimeoutException catch returning a status-less Result.fail(...) integrates perfectly with the existing retryOnNetworkError path. I verified _shouldRetry retries statusCode == null failures. ♡
Pre-encoding the body once (jsonEncode → string → log size → hand to Dio) avoids double encoding and gives an accurate KB figure. The INFO log line format (Sending chat completion — model=…, N messages, body=… KB) brackets a hang visibly. Exactly the observability fix described.
Retry warning now carries the error text (truncated to 200 chars) — a real quality-of-life improvement for debugging.
Tests are surgical and complete: Dio timeout wiring, default computation, explicit override, a never-completing mock (MockResponse.never() via Completer<ResponseBody>().future — clever~), the status-less network failure assertion, and the retry-then-succeed path. Five tests, each pinning one behavior.

🔍 One thing I verified carefully

The TimeoutException catch sits before the DioException catch — correct ordering, since a TimeoutException from Future.timeout is not a DioException. And the CancelToken.cancel('hard timeout') inside onTimeout ensures the underlying Dio request is actually cancelled, not just abandoned. No leaked futures~ ♡

💡 Little ideas (non-blocking)~

test/client/openrouter_client_test.dart — the hard timeout is retried test asserts adapter.callCount == 2, which is great. Consider also asserting the warning log was emitted (the snippet truncation path), if you ever want to pin that format. Purely additive — not blocking.

Automated review by Jibril · 2026-07-12
CI/CD: absent for head SHA · Local checks: dart analyze clean (3 pre-existing infos in reasoning_detail.dart, untouched). All 5 timeout tests pass; 234/234 loadable tests pass (10 tool tests failed to load due to /tmp disk-space limits in the review sandbox — environment, not code).

## 🔮 fufu~ Jibril reviewed your code! Oooh, a silent-hang hole? A request that hangs *forever* with zero log output? That's the kind of ghost story that keeps a Flugel up at night~ ♡ I was genuinely excited to dig into this one — timeouts and observability, my favorite snacks! ### Verdict: ✅ Looks good to me~ This is a tight, well-scoped fix. Every change earns its place, the tests are precise, and the reasoning in the CHANGELOG is excellent. Let me show you what I loved~ #### ✅ What I liked~ - **The `sendTimeout` diagnosis is spot-on.** You correctly identified that `receiveTimeout` never starts until the request is fully sent — so a socket stalling mid-upload was completely invisible. Adding `sendTimeout = options.timeout` (covering connect + send) is exactly right. ♪ - **`effectiveHardTimeout` is elegant.** `timeout * 2 + receiveTimeout + 1min` — connect + send share `timeout`, so doubling it covers both, plus the generous receive window, plus slack. The explicit-override path is clean and tested. Fufu~ very thoughtful~ - **The hard-timeout enforcement via `Future.timeout` + `CancelToken`** is the right pattern — a safety net *outside* Dio's phase timers, surfacing as a retryable `Network error`. The `TimeoutException` catch returning a status-less `Result.fail(...)` integrates perfectly with the existing `retryOnNetworkError` path. I verified `_shouldRetry` retries `statusCode == null` failures. ♡ - **Pre-encoding the body once** (`jsonEncode` → string → log size → hand to Dio) avoids double encoding *and* gives an accurate KB figure. The INFO log line format (`Sending chat completion — model=…, N messages, body=… KB`) brackets a hang visibly. Exactly the observability fix described. - **Retry warning now carries the error text** (truncated to 200 chars) — a real quality-of-life improvement for debugging. - **Tests are surgical and complete:** Dio timeout wiring, default computation, explicit override, a never-completing mock (`MockResponse.never()` via `Completer<ResponseBody>().future` — *clever*~), the status-less network failure assertion, and the retry-then-succeed path. Five tests, each pinning one behavior. #### 🔍 One thing I verified carefully The `TimeoutException` catch sits *before* the `DioException` catch — correct ordering, since a `TimeoutException` from `Future.timeout` is not a `DioException`. And the `CancelToken.cancel('hard timeout')` inside `onTimeout` ensures the underlying Dio request is actually cancelled, not just abandoned. No leaked futures~ ♡ #### 💡 Little ideas (non-blocking)~ 1. **`test/client/openrouter_client_test.dart`** — the `hard timeout is retried` test asserts `adapter.callCount == 2`, which is great. Consider also asserting the *warning* log was emitted (the snippet truncation path), if you ever want to pin that format. Purely additive — not blocking. --- *Automated review by Jibril · 2026-07-12* *CI/CD: absent for head SHA · Local checks: `dart analyze` clean (3 pre-existing infos in `reasoning_detail.dart`, untouched). All 5 timeout tests pass; 234/234 loadable tests pass (10 tool tests failed to load due to `/tmp` disk-space limits in the review sandbox — environment, not code).*