From 014b7b141a21ab01aa6bb10a9a160c7ce94ef3ad Mon Sep 17 00:00:00 2001 From: Mallikh Kaula Date: Mon, 21 Sep 2026 18:23:13 -0400 Subject: [PATCH] Make proxy upstream response-header timeout configurable The 120 s ResponseHeaderTimeout on the upstream transport is now overridable: --response-header-timeout flag first, then the NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT environment variable, then the 120 s default. A missing, unparseable, or non-positive value logs a warning and keeps the default, so a bad setting can never silently disable the timeout. firstBodyTimeout tracks the same resolved value because the two bound the same wait: how long an engine may take to start its work. Ported onto the unified nvpair-proxy after the engine proxy unification; the per-proxy copies are gone, so the flag, the resolver, and the test exist exactly once. Tests: TestResolveResponseHeaderTimeout (flag > env > default precedence, invalid/zero/negative fall back), and TestProxyTransportUsesConfiguredHeaderTimeout (the configured value reaches transports built after startup). Signed-off-by: Mallikh Kaula --- README.md | 2 + docs/proxy-response-header-timeout.mdx | 69 ++++++++++++++++++++ docs/troubleshooting.mdx | 13 ++++ services/nvpair-proxy/README.md | 1 + services/nvpair-proxy/header_timeout_test.go | 45 +++++++++++++ services/nvpair-proxy/main.go | 9 +++ services/nvpair-proxy/proxy.go | 53 +++++++++++++-- services/nvpair-proxy/spec.md | 10 +-- 8 files changed, 191 insertions(+), 11 deletions(-) create mode 100644 docs/proxy-response-header-timeout.mdx create mode 100644 services/nvpair-proxy/header_timeout_test.go diff --git a/README.md b/README.md index 757c3f39..893820ea 100644 --- a/README.md +++ b/README.md @@ -242,6 +242,8 @@ Each entry assumes the ones before it. 9. **[Developer guide](docs/developing.mdx)** — read this before contributing: where the code lives, how a change travels through the layers, and the conventions the project enforces. +10. **[Proxy response-header timeout](docs/proxy-response-header-timeout.mdx)** — + the 120 s upstream header deadline, when it trips, and how to configure it. Component references, for when you already know what you are looking for: diff --git a/docs/proxy-response-header-timeout.mdx b/docs/proxy-response-header-timeout.mdx new file mode 100644 index 00000000..3ed5dfb2 --- /dev/null +++ b/docs/proxy-response-header-timeout.mdx @@ -0,0 +1,69 @@ +{/* +SPDX-FileCopyrightText: Copyright (c) 2026 NVIDIA CORPORATION & AFFILIATES. All rights reserved. +SPDX-License-Identifier: Apache-2.0 +*/} + +# Proxy response-header timeout + +The unified inference proxy (`nvpair-proxy`) caps how long it +wait for the upstream engine to send response headers: `ResponseHeaderTimeout` +on the upstream transport. The default is 120 s, and it is now configurable. + +## Why the timeout exists, and why 120 s is not always enough + +An engine sends no response headers until generation starts. Two normal +situations delay that past 120 s: + +- **Queueing.** Ollama serves one request at a time by default + (`OLLAMA_NUM_PARALLEL=1`). Twenty concurrent requests at ~11 s each means + the last one waits ~220 s for its turn — every request past the 120 s mark + fails through PAIR with a 502 while succeeding direct. +- **Cold model loads.** The first request after a model change waits on the + load before any header is sent. + +When the timeout trips, the proxy closes the upstream connection (which also +cancels the engine's queued work) and answers +`502 {"error":"upstream error: net/http: timeout awaiting response headers"}`. + +```mermaid +sequenceDiagram + participant App + participant Proxy + participant Engine + + App->>Proxy: POST /v1/chat/completions + Proxy->>Engine: forward (ResponseHeaderTimeout = T) + alt headers within T + Engine-->>Proxy: headers, then stream + Proxy-->>App: 200 stream + else no headers within T + Note over Proxy: close upstream,
cancel engine work + Proxy-->>App: 502 timeout awaiting response headers + end +``` + +## Configuring it + +Precedence is flag, then environment, then the 120 s default: + +```bash +nvpair-proxy --response-header-timeout 10m +NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT=10m nvpair-proxy +``` + +The value is a Go duration (`30s`, `5m`, `1h30m`). The broker spawns the +proxy as a child process, so the environment variable set on the broker (or +the desktop app / headless launcher) is inherited — no broker change is +needed. A missing, unparseable, or non-positive value logs a warning and +falls back to 120 s, so a bad setting can never silently disable the timeout. + +The effective value is logged at proxy startup (`response_header_timeout`) +for post-mortem analysis. + +## Choosing a value + +Match it to the worst case you want to survive: queue depth × per-request +time, or the slowest cold load on your hardware. There is no correctness cost +to a generous value — it only bounds how long a request waits on an engine +that never answers. Keep it shorter than any client-side timeout above PAIR +so failures still surface where you expect them. diff --git a/docs/troubleshooting.mdx b/docs/troubleshooting.mdx index e4d8822c..fbe0d57f 100644 --- a/docs/troubleshooting.mdx +++ b/docs/troubleshooting.mdx @@ -116,6 +116,19 @@ PAIR's port, expand **Engine settings > Ports** on the node's card in PAIR's port is usually easier and leaves the other application alone. Refer to [Changing a Port](getting-started.mdx#changing-a-port). +## Inference Requests Fail with 502 After 120 Seconds + +`502 {"error":"upstream error: net/http: timeout awaiting response headers"}` +means the engine did not send response headers within the proxy's upstream +response-header timeout (default 120 s). Engines send no headers until +generation starts, so this trips on requests queued behind other work +(Ollama serves one request at a time by default) or on slow model loads — +while the same request sent directly to the engine succeeds. Raise the +timeout with the `--response-header-timeout` flag (a Go duration, e.g. `5m`) +or the `NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT` environment variable on +`nvpair-proxy`. Refer to +[Proxy response-header timeout](proxy-response-header-timeout.mdx). + ## Requests Work but PAIR Shows No Jobs If inference succeeds and yet **Jobs** stays empty, and the machine you sent the diff --git a/services/nvpair-proxy/README.md b/services/nvpair-proxy/README.md index c36fb0c2..d19cf8b1 100644 --- a/services/nvpair-proxy/README.md +++ b/services/nvpair-proxy/README.md @@ -67,6 +67,7 @@ parameter, because one flag cannot carry two engines' plans. | `--ipc` | *(empty — use stdio)* | Path to a Unix domain socket or Windows named pipe for IPC | | `--cluster-dir` | *(empty)* | Cluster trust directory (`node.crt`/`node.key` plus trusted pins). Enables the LAN mTLS inference ingress while this node is a cluster member; empty means no ingress and no peer candidates. | | `--log-level` | *(`$NVPAIR_LOG_LEVEL`, else `info`)* | Initial log level: `debug`, `info`, `warn`, or `error`. Changeable at runtime with `log/set-level`. | +| `--response-header-timeout` | *(`$NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT`, else `120s`)* | Upstream response-header timeout (Go duration, e.g. `5m`). A request whose engine has not sent response headers within this long fails with 502. Raise it for deep engine queues or slow model loads. | | `--version` | | Print version and exit | ### `facade/enable` parameters diff --git a/services/nvpair-proxy/header_timeout_test.go b/services/nvpair-proxy/header_timeout_test.go new file mode 100644 index 00000000..0b38bfcb --- /dev/null +++ b/services/nvpair-proxy/header_timeout_test.go @@ -0,0 +1,45 @@ +// SPDX-FileCopyrightText: Copyright (c) 2026 NVIDIA CORPORATION & AFFILIATES. All rights reserved. +// SPDX-License-Identifier: Apache-2.0 + +package main + +import ( + "testing" + "time" +) + +func TestResolveResponseHeaderTimeout(t *testing.T) { + cases := []struct { + name string + flag string + env string + want time.Duration + }{ + {"default", "", "", 120 * time.Second}, + {"env", "", "5m", 5 * time.Minute}, + {"flag beats env", "30s", "5m", 30 * time.Second}, + {"invalid env falls back", "", "bogus", 120 * time.Second}, + {"zero env falls back", "", "0", 120 * time.Second}, + {"negative flag falls back", "-1s", "", 120 * time.Second}, + } + for _, tc := range cases { + t.Run(tc.name, func(t *testing.T) { + t.Setenv(responseHeaderTimeoutEnv, tc.env) + if got := resolveResponseHeaderTimeout(tc.flag); got != tc.want { + t.Fatalf("resolveResponseHeaderTimeout(%q) = %s, want %s", tc.flag, got, tc.want) + } + }) + } +} + +// The configured timeout must reach the upstream transports built after +// startup. +func TestProxyTransportUsesConfiguredHeaderTimeout(t *testing.T) { + old := proxyResponseTimeout + defer func() { proxyResponseTimeout = old }() + proxyResponseTimeout = 10 * time.Minute + tr := newProxyTransport(nil) + if tr.ResponseHeaderTimeout != 10*time.Minute { + t.Fatalf("ResponseHeaderTimeout = %s, want 10m", tr.ResponseHeaderTimeout) + } +} diff --git a/services/nvpair-proxy/main.go b/services/nvpair-proxy/main.go index ebfa902d..406fc35b 100644 --- a/services/nvpair-proxy/main.go +++ b/services/nvpair-proxy/main.go @@ -22,10 +22,19 @@ import ( func main() { ipcPath := flag.String("ipc", "", "IPC endpoint: Unix domain socket path or Windows named pipe (default: stdin/stdout)") clusterDir := flag.String("cluster-dir", "", "cluster trust directory (node.crt/key + trusted pins); enables the LAN mTLS inference ingress when this node is clustered") + responseHeaderTimeout := flag.String("response-header-timeout", "", "upstream response header timeout (Go duration, e.g. 5m); default: $NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT or 120s") showVersion := flag.Bool("version", false, "print version and exit") resolveLevel := applog.RegisterFlag(nil, slog.LevelInfo) flag.Parse() + // Resolve the upstream response-header timeout before any transport is + // built: transports are constructed lazily via newProxyTransport, so + // assigning ahead of serving is sufficient. firstBodyTimeout tracks the + // same budget (see proxy.go) because the two bound the same wait — how + // long we allow an engine to start its work. + proxyResponseTimeout = resolveResponseHeaderTimeout(*responseHeaderTimeout) + firstBodyTimeout = proxyResponseTimeout + if *showVersion { fmt.Println(Version) os.Exit(0) diff --git a/services/nvpair-proxy/proxy.go b/services/nvpair-proxy/proxy.go index 929c3d67..408cbf7c 100644 --- a/services/nvpair-proxy/proxy.go +++ b/services/nvpair-proxy/proxy.go @@ -19,6 +19,7 @@ import ( "net/http" "net/http/httputil" "net/url" + "os" "runtime/debug" "sort" "strconv" @@ -726,11 +727,16 @@ func awaitFirstBody(body io.ReadCloser, budget time.Duration) (io.ReadCloser, er // Timeouts for upstream connections. Logged at startup so they're always // present in any captured log for post-mortem analysis. const ( - proxyDialTimeout = 10 * time.Second - proxyKeepAlive = 30 * time.Second - proxyResponseTimeout = 120 * time.Second - proxyMaxIdleConns = 50 - proxyIdleConnTimeout = 90 * time.Second + proxyDialTimeout = 10 * time.Second + proxyKeepAlive = 30 * time.Second + // defaultProxyResponseTimeout is the upstream response-header timeout + // unless --response-header-timeout (or NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT) + // overrides it. Engines send no headers until generation starts, so a + // request queued behind other work, or waiting on a slow model load, + // needs longer than this to survive the proxy. + defaultProxyResponseTimeout = 120 * time.Second + proxyMaxIdleConns = 50 + proxyIdleConnTimeout = 90 * time.Second // Inbound http.Server limits — keep IdleTimeout aligned with client // IdleConnTimeout so idle keep-alives are reaped on both sides. proxyReadHeaderTimeout = 10 * time.Second @@ -738,6 +744,38 @@ const ( maxModelListBytes = 16 << 20 ) +// responseHeaderTimeoutEnv carries the upstream response-header timeout when +// the --response-header-timeout flag is empty. The broker spawns the proxy as +// a child process, so the variable set on the broker (or desktop) is inherited +// without any broker change. +const responseHeaderTimeoutEnv = "NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT" + +// proxyResponseTimeout is the effective upstream response-header timeout, +// resolved at startup: --response-header-timeout flag, then +// NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT, then the 120 s default. Upstream +// transports are built lazily via newProxyTransport, so assigning it before +// serving is sufficient. +var proxyResponseTimeout = defaultProxyResponseTimeout + +// resolveResponseHeaderTimeout applies the flag > env > default precedence. A +// missing, unparseable, or non-positive value falls back to the default, so a +// bad setting can never silently disable the timeout. +func resolveResponseHeaderTimeout(flagVal string) time.Duration { + raw := flagVal + if raw == "" { + raw = os.Getenv(responseHeaderTimeoutEnv) + } + if raw == "" { + return defaultProxyResponseTimeout + } + d, err := time.ParseDuration(raw) + if err != nil || d <= 0 { + log.Printf("invalid response-header timeout %q, using default %s", raw, defaultProxyResponseTimeout) + return defaultProxyResponseTimeout + } + return d +} + // idleClientWriteTimeout bounds how long a single write of streamed response // bytes to the client may block. A killed client can leave a half-open socket // whose kernel send buffer fills and never drains; without this deadline the @@ -760,8 +798,9 @@ var idleClientWriteTimeout = 30 * time.Second // work rather than a stall, and which cannot be told apart from a queue wait // from outside the engine. // -// It is a var (not a const) only so a test can shorten it; production never -// reassigns it. +// It is a var (not a const) so a test can shorten it, and so main can set it +// from the resolved --response-header-timeout at startup; it always tracks +// proxyResponseTimeout. var firstBodyTimeout = proxyResponseTimeout var modelListClient = &http.Client{ diff --git a/services/nvpair-proxy/spec.md b/services/nvpair-proxy/spec.md index 18c59999..d518908b 100644 --- a/services/nvpair-proxy/spec.md +++ b/services/nvpair-proxy/spec.md @@ -184,7 +184,7 @@ never broadens to an excluded node. | --- | --- | --- | | `maxDispatchAttempts` | 5 | how many dispatches may fail | | `jobDeadline` | 10 minutes from request creation | how long new attempts may keep being started, including while waiting for an owner to exist | -| `firstBodyTimeout` | `proxyResponseTimeout` (120s) | one attempt's wait for first content, measured from the arrival of headers | +| `firstBodyTimeout` | `proxyResponseTimeout` (default 120s, `--response-header-timeout`) | one attempt's wait for first content, measured from the arrival of headers | The retry budget applies only to inference requests. Routes not classified in the engine's route table are still forwarded verbatim, and some perform @@ -201,9 +201,11 @@ not burn its budget while the node comes back. **Elapsed time per attempt is the sum of three budgets, not one.** They run in sequence: the dial (`proxyDialTimeout`, 10s), then headers -(`proxyResponseTimeout`, 120s, enforced by the transport), then first content -(`firstBodyTimeout`, 120s, which starts only once headers arrive). One attempt -can therefore occupy around 240s — the two 120s caps back to back, since a slow +(`proxyResponseTimeout`, default 120s via `--response-header-timeout`, +enforced by the transport), then first content +(`firstBodyTimeout`, which tracks the same configured value and starts only +once headers arrive). One attempt can therefore occupy around 240s at the +defaults — the two caps back to back, since a slow dial is a LAN rarity — and nothing caps their sum. Both bounds are checked before every dispatch and **never truncate an attempt