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) + } +}