diff --git a/docs/handover.md b/docs/handover.md index 717fdfa..9573d16 100644 --- a/docs/handover.md +++ b/docs/handover.md @@ -163,6 +163,25 @@ course, not a position in a window. --- +**HTTP_WRITE_TIMEOUT must exceed the deepest agent deadline.** It was 30s in +production while every shipped agent runs at the `balanced` tier, whose +deadline is 60s — so the server aborted the response on any run over half its +allowed time, and the proxy in front answered **502 Bad Gateway**. A gateway +error for something no gateway did, which is why it read as an infrastructure +fault: nginx was innocent and already had `proxy_read_timeout 3600s`. + +Streaming hid it. The chat panel uses SSE and survives, so the product looked +healthy while any non-streaming caller — a webhook, a script, an integration — +got 502 on a slow question. Delegation made it routine rather than causing it: +a parent that asks two subagents takes longer than one answering alone. + +Production is now 180s, and `config.validateWriteTimeout` refuses a value below +`DeepestAgentDeadline` at startup. NOTE THE ORDERING: that constant is 120s, so +a deployment still carrying the old 30s will now refuse to boot. Patch the +configmap before shipping an image that contains the check. + +--- + ## Still outstanding - `ANTHROPIC_API_KEY` was pasted into a chat transcript and is live in a diff --git a/go-api/internal/config/config.go b/go-api/internal/config/config.go index 8585d23..945a3df 100644 --- a/go-api/internal/config/config.go +++ b/go-api/internal/config/config.go @@ -221,7 +221,7 @@ func Load() (*Config, error) { Host: withDefault("HTTP_HOST", "127.0.0.1"), Port: intDefault("HTTP_PORT", 8080), ReadTimeout: durationDefault("HTTP_READ_TIMEOUT", 15*time.Second), - WriteTimeout: durationDefault("HTTP_WRITE_TIMEOUT", 30*time.Second), + WriteTimeout: durationDefault("HTTP_WRITE_TIMEOUT", DeepestAgentDeadline+30*time.Second), IdleTimeout: durationDefault("HTTP_IDLE_TIMEOUT", 60*time.Second), ShutdownTimeout: durationDefault("HTTP_SHUTDOWN_TIMEOUT", 10*time.Second), CORSOrigins: corsOrigins(withDefault("APP_ENV", "development")), @@ -281,7 +281,49 @@ func Load() (*Config, error) { return cfg, nil } +// DeepestAgentDeadline is the longest a single agent run may take — the +// `deep` tier's deadline in runtime.LimitsForTier. +// +// Duplicated rather than imported because internal/runtime already imports +// this package, and a cycle to share one number is a bad trade. A test in +// internal/runtime asserts the two agree, so this drifting is a build failure +// rather than a discovery. +const DeepestAgentDeadline = 120 * time.Second + +// validateWriteTimeout refuses a server that would cut off a run the runtime +// considers legal. +// +// HTTP_WRITE_TIMEOUT was 30s in production while every shipped agent runs at +// the `balanced` tier, whose deadline is 60s. The server therefore aborted the +// response on any run over half its allowed time, and the caller saw 502 Bad +// Gateway from the proxy in front — a gateway error for something no gateway +// did, which is why it read as an infrastructure fault for so long. +// +// Delegation made it routine rather than causing it: a parent that asks two +// subagents spends longer than one that answers alone. The misconfiguration +// predates it. +// +// Streaming hides it, and that is the trap. The chat panel uses SSE and +// survives, so the product looks healthy while every non-streaming caller — a +// webhook, a script, an integration — gets 502 on a slow question. +func (c *Config) validateWriteTimeout() error { + if c.HTTP.WriteTimeout <= 0 { + return nil // no deadline set; the server will not cut anything off + } + if c.HTTP.WriteTimeout < DeepestAgentDeadline { + return fmt.Errorf( + "HTTP_WRITE_TIMEOUT is %s but an agent run may take %s (the deep tier's "+ + "deadline); the server would abort the response while the run is still "+ + "legal, and the caller would see 502 from the proxy. Set it above %s", + c.HTTP.WriteTimeout, DeepestAgentDeadline, DeepestAgentDeadline) + } + return nil +} + func (c *Config) validate() error { + if err := c.validateWriteTimeout(); err != nil { + return err + } switch c.AppEnv { case "development", "staging", "production": default: diff --git a/go-api/internal/config/writetimeout_test.go b/go-api/internal/config/writetimeout_test.go new file mode 100644 index 0000000..75375e3 --- /dev/null +++ b/go-api/internal/config/writetimeout_test.go @@ -0,0 +1,62 @@ +package config + +import ( + "strings" + "testing" + "time" +) + +// A write timeout below the deepest agent deadline is refused at startup. +// +// This is the misconfiguration that shipped: HTTP_WRITE_TIMEOUT=30s against a +// balanced deadline of 60s. The server aborted the response on any run over +// half its allowed time and the proxy in front answered 502, so it read as an +// infrastructure fault for months. Refusing it at startup turns a slow, +// intermittent, misattributed failure into a message on the first boot. +func TestValidateWriteTimeout(t *testing.T) { + withTimeout := func(d time.Duration) *Config { + c := &Config{} + c.HTTP.WriteTimeout = d + return c + } + + for _, tc := range []struct { + name string + timeout time.Duration + wantErr bool + }{ + {"the value that shipped", 30 * time.Second, true}, + {"equal to the balanced deadline is still short of deep", 60 * time.Second, true}, + {"one second under", DeepestAgentDeadline - time.Second, true}, + {"exactly the deepest deadline", DeepestAgentDeadline, false}, + {"comfortably above", DeepestAgentDeadline + 30*time.Second, false}, + {"no deadline at all cuts nothing off", 0, false}, + {"negative is treated as unset", -1, false}, + } { + t.Run(tc.name, func(t *testing.T) { + err := withTimeout(tc.timeout).validateWriteTimeout() + if tc.wantErr && err == nil { + t.Fatalf("%s was accepted; it would abort a legal run", tc.timeout) + } + if !tc.wantErr && err != nil { + t.Fatalf("%s was refused: %v", tc.timeout, err) + } + }) + } +} + +// The message has to name the fix. An operator reading it at 3am should not +// have to find the deep tier's deadline in another package. +func TestValidateWriteTimeoutSaysWhatToDo(t *testing.T) { + c := &Config{} + c.HTTP.WriteTimeout = 30 * time.Second + err := c.validateWriteTimeout() + if err == nil { + t.Fatal("expected a refusal") + } + for _, want := range []string{"HTTP_WRITE_TIMEOUT", "30s", "2m0s", "502"} { + if !strings.Contains(err.Error(), want) { + t.Errorf("the message does not mention %q:\n %v", want, err) + } + } +} diff --git a/go-api/internal/runtime/deadline_test.go b/go-api/internal/runtime/deadline_test.go new file mode 100644 index 0000000..e4142ff --- /dev/null +++ b/go-api/internal/runtime/deadline_test.go @@ -0,0 +1,36 @@ +package runtime + +import ( + "testing" + + "github.com/krow/krow-backend/go-api/internal/config" +) + +// The HTTP server must not cut off a run the runtime considers legal. +// +// config.DeepestAgentDeadline duplicates the deep tier's deadline, because +// internal/runtime already imports internal/config and a cycle to share one +// number is a bad trade. This is the thing that makes the duplicate safe: the +// two drifting apart is a failing test rather than a 502 in production +// months later. +// +// It is not hypothetical. Production ran HTTP_WRITE_TIMEOUT=30s against a +// balanced deadline of 60s, so the server aborted any run over half its +// allowed time and the proxy in front reported 502 — a gateway error for +// something no gateway did. +func TestConfigKnowsTheDeepestAgentDeadline(t *testing.T) { + deepest := LimitsForTier("deep").Deadline + if config.DeepestAgentDeadline != deepest { + t.Fatalf("config.DeepestAgentDeadline is %s but LimitsForTier(\"deep\") is %s — "+ + "raise the constant, or the config validation will accept a write timeout "+ + "that cuts off a legal run", config.DeepestAgentDeadline, deepest) + } + + // And it must genuinely be the largest, or the name lies. + for _, tier := range []string{"fast", "balanced", "deep", "nonsense"} { + if d := LimitsForTier(tier).Deadline; d > config.DeepestAgentDeadline { + t.Errorf("tier %q allows %s, which exceeds DeepestAgentDeadline %s", + tier, d, config.DeepestAgentDeadline) + } + } +}