From 496b7ffce648e12380b913f92753cd0c6792ce76 Mon Sep 17 00:00:00 2001 From: nguyenha935 Date: Wed, 29 Jul 2026 05:00:29 +0700 Subject: [PATCH] fix(providers): raise ResponseHeaderTimeout so reasoning models can answer (#1483) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A reasoning model emits nothing at all while thinking, so the wait for the response's FIRST byte — not any streaming timeout — decides whether its answer is reachable. At 180s a large-prompt reasoning request routinely lost that race: the gateway reported "http2: timeout awaiting response headers" while the router's own usage log showed the same request completing normally moments later (promptTokens=77194 -> completionTokens=2789). The request was healthy; only the deadline was short. Raise it to 300s. The value is deliberately modest rather than generous because it is multiplied twice downstream: RetryDo wraps every provider call with Attempts: 3, and a workflow step requeues up to MaxTaskDispatches times on top of that, so 300s is already ~45min of worst-case wall clock per step. Removing the timeout entirely was considered and rejected. Agent run contexts come from scheduler queue.go via context.WithCancel, so they carry no deadline — this transport timeout is the only thing bounding a request that never answers. Without it a silently dead connection would hold its scheduler lane until the OS TCP keepalive expired, and workflow requeue could not rescue it because requeue only fires when a run ends. The doc comment claiming the design could "rely on ctx deadlines" was wrong and is corrected here. Tests lock the sizing from both sides (must exceed the latency that failed, must not exceed the ceiling the retry math was sized against) and assert the retry multiplier itself has not drifted. Co-authored-by: nguyenha935 --- internal/providers/defaults.go | 33 ++++++++++-- internal/providers/defaults_timeout_test.go | 59 +++++++++++++++++++++ 2 files changed, 88 insertions(+), 4 deletions(-) create mode 100644 internal/providers/defaults_timeout_test.go diff --git a/internal/providers/defaults.go b/internal/providers/defaults.go index 13a4420b..de098ca8 100644 --- a/internal/providers/defaults.go +++ b/internal/providers/defaults.go @@ -23,12 +23,37 @@ const ( // NewDefaultTransport returns an http.Transport with per-stage timeouts but no // overall deadline. The absence of Client.Timeout allows LLM streaming responses -// (extended thinking, long completions) to run indefinitely while ctx cancellation -// still terminates the request promptly via CtxBody. +// (extended thinking, long completions) to run indefinitely once the response has +// STARTED, while ctx cancellation still terminates the request promptly via +// CtxBody. +// +// Note that ctx cancellation is a user/caller signal here, not a time bound: +// agent runs get their context from scheduler queue.go via context.WithCancel, +// so no deadline is attached. The stage timeouts below are therefore the only +// thing bounding a request that never answers. func NewDefaultTransport() *http.Transport { return &http.Transport{ - Proxy: http.ProxyFromEnvironment, - ResponseHeaderTimeout: 180 * time.Second, // wait for first byte of response (3min for slow providers) + Proxy: http.ProxyFromEnvironment, + // Wait for the first byte of the response. This bounds a SINGLE attempt; + // RetryDo wraps the call with Attempts: 3, so the worst case a caller + // observes is ~3x this value, and a workflow step that requeues 3 times + // multiplies it again. Keep it modest. + // + // Raised from 180s after live evidence 2026-07-28: a reasoning model + // (claude-opus-5-thinking) emits nothing at all while thinking, so with a + // ~110k-token prompt it routinely passed 3 minutes before its first byte. + // GoClaw killed the connection and reported "http2: timeout awaiting + // response headers" while 9router's own usage log showed the upstream + // answering fine moments later (promptTokens=77194 → completionTokens=2789). + // The request was healthy; only this deadline was too short. + // + // Deliberately NOT removed: nothing else bounds an LLM call. The scheduler + // builds run contexts with context.WithCancel, not WithTimeout, so there is + // no run-level deadline to fall back on — despite what this file's older + // comment claimed. Without this timeout a silently dead connection would + // hold its scheduler lane until the OS TCP keepalive gave up (~2h), and + // requeue could not rescue it because requeue only fires when a run ends. + ResponseHeaderTimeout: 300 * time.Second, IdleConnTimeout: 90 * time.Second, // close idle keep-alive connections TLSHandshakeTimeout: 10 * time.Second, ExpectContinueTimeout: 1 * time.Second, diff --git a/internal/providers/defaults_timeout_test.go b/internal/providers/defaults_timeout_test.go new file mode 100644 index 00000000..7c28b6ec --- /dev/null +++ b/internal/providers/defaults_timeout_test.go @@ -0,0 +1,59 @@ +package providers + +import ( + "testing" + "time" +) + +// A reasoning model emits nothing while thinking, so ResponseHeaderTimeout — +// not any streaming timeout — is what decides whether its answer is reachable. +// At 180s, claude-opus-5-thinking with a ~110k-token prompt routinely lost the +// race: GoClaw reported "http2: timeout awaiting response headers" while +// 9router's usage log showed the same request answering fine +// (promptTokens=77194 → completionTokens=2789). Live 2026-07-28. +func TestResponseHeaderTimeoutAccommodatesReasoningModels(t *testing.T) { + t.Parallel() + tr := NewDefaultTransport() + + // The observed first-byte latency that failed at 180s. The timeout must sit + // above it with room to spare. + const observedSlowFirstByte = 180 * time.Second + if tr.ResponseHeaderTimeout <= observedSlowFirstByte { + t.Errorf("ResponseHeaderTimeout = %v, must exceed the %v first-byte latency that failed live", + tr.ResponseHeaderTimeout, observedSlowFirstByte) + } + + // It must stay bounded. RetryDo multiplies it by Attempts, and a workflow + // step requeues up to MaxTaskDispatches times on top of that, so an + // over-generous value turns one slow provider into an hours-long workflow. + // 3 (retry) x 3 (requeue) x 300s = 45min worst case, which is the ceiling + // this value was chosen against. + const maxAcceptable = 300 * time.Second + if tr.ResponseHeaderTimeout > maxAcceptable { + t.Errorf("ResponseHeaderTimeout = %v, exceeds %v; retry x requeue multiplies this ~9x", + tr.ResponseHeaderTimeout, maxAcceptable) + } +} + +// Removing ResponseHeaderTimeout entirely was considered and rejected: agent run +// contexts come from scheduler queue.go via context.WithCancel, so they carry no +// deadline. With no header timeout, a silently dead connection would hold its +// scheduler lane until the OS TCP keepalive expired (~2h), and workflow requeue +// could not rescue it because requeue only fires when a run ENDS. This timeout is +// the only bound on a request that never answers — it must stay non-zero. +func TestResponseHeaderTimeoutIsSet(t *testing.T) { + t.Parallel() + if got := NewDefaultTransport().ResponseHeaderTimeout; got == 0 { + t.Fatal("ResponseHeaderTimeout is 0 (unbounded); nothing else bounds an LLM call, " + + "so a dead connection would wedge its scheduler lane indefinitely") + } +} + +// The retry multiplier this timeout is sized against must not drift silently. +func TestDefaultRetryAttemptsMatchTimeoutSizing(t *testing.T) { + t.Parallel() + if got := DefaultRetryConfig().Attempts; got != 3 { + t.Errorf("DefaultRetryConfig().Attempts = %d, want 3 — ResponseHeaderTimeout was sized "+ + "assuming a 3x retry multiplier; re-check that sizing if this changed", got) + } +}