diff --git a/docs/troubleshooting.mdx b/docs/troubleshooting.mdx index 3a2bb817..c073784a 100644 --- a/docs/troubleshooting.mdx +++ b/docs/troubleshooting.mdx @@ -150,6 +150,21 @@ Routing confirmation happens on **Overview**: Send several independent requests to observe multi-node routing. One request runs on one selected node. +## Requests Fail After Two Minutes + +A request that fails with `502` and `upstream error: net/http: timeout awaiting +response headers` after about 120 seconds waited longer than PAIR allows for an +engine to start answering. An engine sends nothing until generation starts, so a +request queued behind other work, or waiting for a large model to load, can hit +this while the engine is healthy. + +Raise the limit with the `NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT` environment +variable, a Go duration such as `10m`, and restart PAIR. On macOS, set it for +apps opened from the Finder with +`launchctl setenv NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT 10m`. Every node that +serves requests applies its own limit, so raise it on each. A longer limit also +means a node that has stopped responding is given up on later. + ## Where the Logs Are Everything you need is on **Settings > Service**: diff --git a/services/lmstudio-proxy/README.md b/services/lmstudio-proxy/README.md index 83ab51e8..24fb0ddd 100644 --- a/services/lmstudio-proxy/README.md +++ b/services/lmstudio-proxy/README.md @@ -35,6 +35,7 @@ lmstudio-proxy [flags] | `--port` | `1234` | HTTP listen port for request forwarding | | `--ignore-persisted-port` | `false` | Use `--port` even when a prior runtime port was saved | | `--ipc` | *(empty — use stdio)* | Path to a Unix domain socket or Windows named pipe for IPC | +| `--response-header-timeout` | `$NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT`, else `120s` | How long to wait for an upstream engine to start answering (Go duration, e.g. `10m`). An engine sends no headers until generation starts, so raise it when requests queue behind long jobs or wait on slow model loads. An invalid or non-positive value keeps the default | | `--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`. | | `--version` | | Print version and exit | diff --git a/services/lmstudio-proxy/main.go b/services/lmstudio-proxy/main.go index e3dcb2a4..06fee887 100644 --- a/services/lmstudio-proxy/main.go +++ b/services/lmstudio-proxy/main.go @@ -25,11 +25,13 @@ import ( func main() { port := flag.Int("port", defaultProxyPort, "HTTP listen port") ignorePersistedPort := flag.Bool("ignore-persisted-port", false, "use --port even when a persisted port exists") + responseHeaderTimeout := flag.String("response-header-timeout", "", "upstream response-header timeout (Go duration, e.g. 10m); default: $NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT or 120s") 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") showVersion := flag.Bool("version", false, "print version and exit") resolveLevel := applog.RegisterFlag(nil, slog.LevelInfo) flag.Parse() + proxyResponseTimeout = resolveResponseHeaderTimeout(*responseHeaderTimeout) if *showVersion { fmt.Println(Version) diff --git a/services/lmstudio-proxy/proxy.go b/services/lmstudio-proxy/proxy.go index 8ea829b1..95d4a9f4 100644 --- a/services/lmstudio-proxy/proxy.go +++ b/services/lmstudio-proxy/proxy.go @@ -19,6 +19,7 @@ import ( "net/http" "net/http/httputil" "net/url" + "os" "sort" "strconv" "sync" @@ -560,11 +561,16 @@ func (p *Proxy) Run(ctx context.Context) error { // 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. An engine sends 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 @@ -572,6 +578,37 @@ 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 a value set in the broker's (or the desktop app's) +// environment is inherited; on macOS, `launchctl setenv` reaches an app opened +// from the Finder. +const responseHeaderTimeoutEnv = "NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT" + +// proxyResponseTimeout is the effective upstream response-header timeout, +// resolved at startup: the flag, then the environment, then the default. +// Transports are built lazily, so assigning it before serving is sufficient. +var proxyResponseTimeout = defaultProxyResponseTimeout + +// resolveResponseHeaderTimeout applies the flag > env > default precedence. A +// missing, unparseable or non-positive value keeps the default, so a bad +// setting can never 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 diff --git a/services/lmstudio-proxy/response_timeout_test.go b/services/lmstudio-proxy/response_timeout_test.go new file mode 100644 index 00000000..7d5b8557 --- /dev/null +++ b/services/lmstudio-proxy/response_timeout_test.go @@ -0,0 +1,40 @@ +// 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) { + for _, tc := range []struct { + name, flag, env string + want time.Duration + }{ + {"default", "", "", defaultProxyResponseTimeout}, + {"environment", "", "10m", 10 * time.Minute}, + {"flag beats environment", "5m", "10m", 5 * time.Minute}, + {"unparseable keeps the default", "soon", "", defaultProxyResponseTimeout}, + {"zero keeps the default", "0s", "", defaultProxyResponseTimeout}, + {"negative keeps the default", "", "-1m", defaultProxyResponseTimeout}, + } { + 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) with env %q = %s, want %s", tc.flag, tc.env, got, tc.want) + } + }) + } +} + +// Transports are built after main resolves the timeout, so they carry it. +func TestTransportsUseTheResolvedTimeout(t *testing.T) { + old := proxyResponseTimeout + t.Cleanup(func() { proxyResponseTimeout = old }) + proxyResponseTimeout = 7 * time.Minute + if got := newProxyTransport(nil).ResponseHeaderTimeout; got != 7*time.Minute { + t.Fatalf("ResponseHeaderTimeout = %s, want 7m", got) + } +} diff --git a/services/nvpair-engine-manager/README.md b/services/nvpair-engine-manager/README.md index d3fd4fbb..0e4fa564 100644 --- a/services/nvpair-engine-manager/README.md +++ b/services/nvpair-engine-manager/README.md @@ -179,7 +179,7 @@ Requests (caller → service): | `engine:stop` | `{ engine }` | `EngineStatus` | | `engine:restart` | `{ engine }` | `EngineStatus` | | `engine:set-port` | `{ engine, port }` | `EngineStatus` (after rebind) | -| `engine:action` | `{ engine, action, params }` | the engine's raw response. `action:"pull_model"` is streamed: it emits live `engine:pull-progress` notifications and returns the pull's terminal result (see below). An action whose manifest declares `restart_after` (LM Studio's `delete_model`) restarts a running engine before replying, so the response also means the engine is back and healthy | +| `engine:action` | `{ engine, action, params }` | the engine's raw response. `action:"pull_model"` is streamed: it emits live `engine:pull-progress` notifications and returns the pull's terminal result (see below). An action whose manifest declares `restart_after` (LM Studio's `delete_model`) restarts a running engine before replying, so the response also means the engine is back and healthy. An HTTP action waits 30 s for the engine's response headers unless its manifest declares `timeout_s` (seconds); Ollama's `run_model`, oMLX's `load_model` and `chat`, and LM Studio's `chat` declare 600, because a cold model load or a long prefill sends nothing until it finishes | | `engine:logs` | `{ engine }` | `{ lines: [LogLine] }` | | `engine:errors` | — | `{ errors: [ServiceError] }` | | `engine:models` | — | `{ models: [string], modelsByEngine: { : [string] }, loadedByEngine: { : [string] } }` — the flat de-duplicated union of every running engine's models, the per-engine breakdown keyed by engine name, and the per-engine set of models currently **loaded in memory** (all normalized from each engine's `list_models` / `loaded_models` action `result` spec). `modelsByEngine` carries a key for every running engine whose inventory was successfully queried, including an empty list = "running, no models available"; a missing key means not running / not queryable / invalid response. `loadedByEngine` uses the same known-empty distinction for residency and also omits engines with no loaded endpoint. The `/v1/models` HTTP surface returns the same shape. | diff --git a/services/nvpair-engine-manager/actions.go b/services/nvpair-engine-manager/actions.go index 0ac97b7f..1efe5d94 100644 --- a/services/nvpair-engine-manager/actions.go +++ b/services/nvpair-engine-manager/actions.go @@ -145,11 +145,7 @@ func (e *Executor) dispatchAction(ctx context.Context, st *engineState, engine, req.Header.Set("Authorization", "Bearer "+key) } } - client := e.client - if ((engine == "ollama" && action == "run_model") || action == "load_model") && e.ollamaLoadClient != nil { - client = e.ollamaLoadClient - } - resp, err := client.Do(req) + resp, err := e.actionClient(act.TimeoutS).Do(req) if err != nil { return nil, fmt.Errorf("action %q: %w", action, err) } diff --git a/services/nvpair-engine-manager/executor.go b/services/nvpair-engine-manager/executor.go index 5180001e..6f831b7d 100644 --- a/services/nvpair-engine-manager/executor.go +++ b/services/nvpair-engine-manager/executor.go @@ -19,10 +19,10 @@ import ( var winEnvRe = regexp.MustCompile(`%([^%]+)%`) -const ( - engineResponseHeaderTimeout = 30 * time.Second - ollamaLoadResponseHeaderTimeout = 10 * time.Minute -) +// engineResponseHeaderTimeout bounds how long a loopback action, download or +// probe waits for response headers before treating the engine as hung. It is +// also the default for an HTTP action that declares no timeout_s. +const engineResponseHeaderTimeout = 30 * time.Second // EngineStatus is the snapshot returned by engine:status and // engine:get-installed. @@ -74,13 +74,17 @@ type engineState struct { // layer runs the long ones (install, start) in goroutines so the read // loop stays responsive. type Executor struct { - reg *Registry - tools toolEnv - toolInstallMu sync.Mutex // serialize tool installs and recheck detection after waiting - reporter *Reporter - emit func(method string, params any) - client *http.Client - ollamaLoadClient *http.Client + reg *Registry + tools toolEnv + toolInstallMu sync.Mutex // serialize tool installs and recheck detection after waiting + reporter *Reporter + emit func(method string, params any) + client *http.Client + // actionClients caches one client per non-default response-header + // timeout an action declares in timeout_s, so a manifest value is + // honored without building a client per call. + actionClientsMu sync.Mutex + actionClients map[time.Duration]*http.Client // progress fans install/pull progress to transient subscribers (the ec // streaming handlers) in addition to the local engine:install-progress // notification path. See progress.go. @@ -127,7 +131,7 @@ func NewExecutor(reg *Registry, reporter *Reporter, emit func(string, any), base reporter: reporter, emit: emit, client: newEngineHTTPClient(engineResponseHeaderTimeout), - ollamaLoadClient: newEngineHTTPClient(ollamaLoadResponseHeaderTimeout), + actionClients: make(map[time.Duration]*http.Client), progress: newProgressHub(), baseDir: baseDir, desired: newDesiredStateStore(baseDir), @@ -307,3 +311,26 @@ func startFailedID(engine string) string { return "engine-manager:start-failed:" func unhealthyID(engine string) string { return "engine-manager:unhealthy:" + engine } func exitedID(engine string) string { return "engine-manager:exited:" + engine } + +// actionClient returns the client for an action's declared response-header +// timeout: the shared client when the action declares none, otherwise a cached +// client built for the declared value. The timeout is a property of the action +// in the manifest, not of the engine's name, so any engine can declare a slow +// action. The whole call stays bounded by the executor's action timeout. +func (e *Executor) actionClient(timeoutS int) *http.Client { + d := time.Duration(timeoutS) * time.Second + if d <= 0 || d == engineResponseHeaderTimeout { + return e.client + } + e.actionClientsMu.Lock() + defer e.actionClientsMu.Unlock() + if c, ok := e.actionClients[d]; ok { + return c + } + if e.actionClients == nil { + e.actionClients = make(map[time.Duration]*http.Client) + } + c := newEngineHTTPClient(d) + e.actionClients[d] = c + return c +} diff --git a/services/nvpair-engine-manager/executor_test.go b/services/nvpair-engine-manager/executor_test.go index a8e735b5..319fb8ce 100644 --- a/services/nvpair-engine-manager/executor_test.go +++ b/services/nvpair-engine-manager/executor_test.go @@ -73,12 +73,21 @@ func TestEngineHTTPClientsBoundResponseHeaders(t *testing.T) { if got := responseHeaderTimeout(t, ex.client); got != engineResponseHeaderTimeout { t.Fatalf("ordinary response-header timeout = %s, want %s", got, engineResponseHeaderTimeout) } - if got := responseHeaderTimeout(t, ex.ollamaLoadClient); got != ollamaLoadResponseHeaderTimeout { - t.Fatalf("Ollama load response-header timeout = %s, want %s", got, ollamaLoadResponseHeaderTimeout) + if got := responseHeaderTimeout(t, ex.actionClient(600)); got != 10*time.Minute { + t.Fatalf("declared response-header timeout = %s, want 10m", got) + } + if ex.actionClient(600) != ex.actionClient(600) { + t.Fatal("a declared timeout should reuse one cached client") + } + if ex.actionClient(0) != ex.client { + t.Fatal("an action that declares no timeout should use the shared client") } } -func TestOnlyOllamaRunModelUsesSlowResponseHeaderBudget(t *testing.T) { +// The response-header budget is a property of the action in the manifest, +// not of the engine's name: any engine's action can declare a slow wait, and +// an action that declares none keeps the short default. +func TestActionDeclaredTimeoutBoundsResponseHeaders(t *testing.T) { srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { time.Sleep(100 * time.Millisecond) w.Header().Set("Content-Type", "application/json") @@ -89,48 +98,58 @@ func TestOnlyOllamaRunModelUsesSlowResponseHeaderBudget(t *testing.T) { port, _ := strconv.Atoi(u.Port()) m := testEngineManifest(fakeEngineBin) - m.Engine = "ollama" + m.Engine = "other" platform := m.Platforms[runtime.GOOS+"/"+runtime.GOARCH] platform.Runtime.Port = port m.Platforms[runtime.GOOS+"/"+runtime.GOARCH] = platform m.Actions = map[string]Action{ - "run_model": {HTTP: &ActionHTTP{Method: "POST", Path: "/api/generate"}}, + "chat": {HTTP: &ActionHTTP{Method: "POST", Path: "/v1/chat/completions"}, TimeoutS: 1}, "delete_model": {HTTP: &ActionHTTP{Method: "DELETE", Path: "/api/delete"}}, } ex := newTestExecutor(t, m) ex.client = newEngineHTTPClient(20 * time.Millisecond) - ex.ollamaLoadClient = newEngineHTTPClient(500 * time.Millisecond) - st, err := ex.state("ollama") + st, err := ex.state("other") if err != nil { t.Fatal(err) } st.running = true - if _, err := ex.Action(context.Background(), "ollama", "run_model", json.RawMessage(`{"model":"tiny"}`)); err != nil { - t.Fatalf("Ollama load was cut off by the ordinary response-header budget: %v", err) + if _, err := ex.Action(context.Background(), "other", "chat", json.RawMessage(`{"model":"tiny"}`)); err != nil { + t.Fatalf("an action declaring timeout_s was cut off by the default budget: %v", err) } - if _, err := ex.Action(context.Background(), "ollama", "delete_model", json.RawMessage(`{"name":"tiny"}`)); err == nil || !strings.Contains(err.Error(), "timeout awaiting response headers") { + if _, err := ex.Action(context.Background(), "other", "delete_model", json.RawMessage(`{"name":"tiny"}`)); err == nil || !strings.Contains(err.Error(), "timeout awaiting response headers") { t.Fatalf("ordinary action error = %v, want bounded response-header timeout", err) } +} - other := testEngineManifest(fakeEngineBin) - other.Engine = "other" - otherPlatform := other.Platforms[runtime.GOOS+"/"+runtime.GOARCH] - otherPlatform.Runtime.Port = port - other.Platforms[runtime.GOOS+"/"+runtime.GOARCH] = otherPlatform - other.Actions = map[string]Action{ - "run_model": {HTTP: &ActionHTTP{Method: "POST", Path: "/api/generate"}}, - } - otherEx := newTestExecutor(t, other) - otherEx.client = newEngineHTTPClient(20 * time.Millisecond) - otherEx.ollamaLoadClient = newEngineHTTPClient(500 * time.Millisecond) - otherState, err := otherEx.state("other") - if err != nil { +// The bundled slow actions keep the long wait the old engine-name rule gave +// them, and the chat actions gain it. +func TestBundledSlowActionsDeclareALongWait(t *testing.T) { + reg := NewRegistry() + if err := reg.LoadFS(bundledManifests, "manifests"); err != nil { t.Fatal(err) } - otherState.running = true - if _, err := otherEx.Action(context.Background(), "other", "run_model", json.RawMessage(`{"model":"tiny"}`)); err == nil || !strings.Contains(err.Error(), "timeout awaiting response headers") { - t.Fatalf("non-Ollama run_model error = %v, want ordinary response-header timeout", err) + for _, c := range []struct{ engine, action string }{ + {"ollama", "run_model"}, {"omlx", "load_model"}, {"omlx", "chat"}, {"lmstudio", "chat"}, + } { + m, ok := reg.Get(c.engine) + if !ok { + t.Fatalf("no bundled %s manifest", c.engine) + } + if got := m.Actions[c.action].TimeoutS; got != 600 { + t.Errorf("%s %s timeout_s = %d, want 600", c.engine, c.action, got) + } + } +} + +func TestActionTimeoutValidation(t *testing.T) { + for name, a := range map[string]Action{ + "negative": {HTTP: &ActionHTTP{Method: "GET", Path: "/x"}, TimeoutS: -1}, + "on a cmd": {Cmd: []string{"true"}, TimeoutS: 5}, + } { + if err := a.validate(name); err == nil { + t.Errorf("%s: timeout_s accepted", name) + } } } diff --git a/services/nvpair-engine-manager/manifests/lmstudio.json b/services/nvpair-engine-manager/manifests/lmstudio.json index b15d1c19..50f67e9f 100644 --- a/services/nvpair-engine-manager/manifests/lmstudio.json +++ b/services/nvpair-engine-manager/manifests/lmstudio.json @@ -82,6 +82,7 @@ "cmd": ["{cli}", "ls"] }, "chat": { + "timeout_s": 600, "description": "OpenAI-compatible chat completion (params: {\"model\": \"\", \"messages\": [...]}).", "http": { "method": "POST", "path": "/v1/chat/completions", "body_schema": { "model": "string", "messages": "array" } } }, diff --git a/services/nvpair-engine-manager/manifests/ollama.json b/services/nvpair-engine-manager/manifests/ollama.json index 31c1b423..d338fd92 100644 --- a/services/nvpair-engine-manager/manifests/ollama.json +++ b/services/nvpair-engine-manager/manifests/ollama.json @@ -99,6 +99,7 @@ "http": { "method": "POST", "path": "/api/pull", "body_schema": { "name": "string" } } }, "run_model": { + "timeout_s": 600, "description": "Run a one-shot generation (params: {\"model\": \"\", \"prompt\": \"\", \"stream\": false}).", "http": { "method": "POST", "path": "/api/generate", "body_schema": { "model": "string", "prompt": "string", "stream": "bool" } } }, diff --git a/services/nvpair-engine-manager/manifests/omlx.json b/services/nvpair-engine-manager/manifests/omlx.json index 9ea14567..c3f978f5 100644 --- a/services/nvpair-engine-manager/manifests/omlx.json +++ b/services/nvpair-engine-manager/manifests/omlx.json @@ -37,10 +37,12 @@ "result": { "array": "models", "field": "id", "match": { "field": "loaded", "true": true } } }, "chat": { + "timeout_s": 600, "description": "OpenAI-compatible chat completions.", "http": { "method": "POST", "path": "/v1/chat/completions", "body_schema": { "model": "string", "messages": "array" } } }, "load_model": { + "timeout_s": 600, "description": "Load a downloaded model into memory (params: {\"model\": \"\"}).", "http": { "method": "POST", "path": "/v1/models/{model}/load" } }, diff --git a/services/nvpair-engine-manager/registry.go b/services/nvpair-engine-manager/registry.go index 6c5d1764..d5bf1c09 100644 --- a/services/nvpair-engine-manager/registry.go +++ b/services/nvpair-engine-manager/registry.go @@ -187,6 +187,11 @@ type Action struct { // - "lms-disk-path" on RemovePath actions: map logical ids to on-disk // files via `lms ls --json`. ModelResolution string `json:"model_resolution,omitempty"` + // TimeoutS, when > 0 on an HTTP action, bounds how long the runner waits + // for that action's response headers, in seconds; 0 means the 30 s + // default. An engine sends nothing until a cold model load or a long + // prefill finishes, so such an action declares a longer wait. + TimeoutS int `json:"timeout_s,omitempty"` // Result, when set, declares how to extract a normalized string list from // this action's JSON response — the top-level array field to iterate and the // string field to pull from each element. engine:models uses it to turn @@ -690,6 +695,12 @@ func (a *Action) validate(name string) error { if hasHTTP && (strings.TrimSpace(a.HTTP.Method) == "" || strings.TrimSpace(a.HTTP.Path) == "") { return fmt.Errorf("action %q: http.method and http.path are required", name) } + if a.TimeoutS < 0 { + return fmt.Errorf("action %q: timeout_s must be >= 0", name) + } + if a.TimeoutS > 0 && !hasHTTP { + return fmt.Errorf("action %q: timeout_s requires an http action (it bounds the response-header wait)", name) + } if a.Result != nil && (strings.TrimSpace(a.Result.Array) == "" || strings.TrimSpace(a.Result.Field) == "") { return fmt.Errorf("action %q: result.array and result.field are required when result is set", name) } diff --git a/services/nvpair-engine-manager/remoteclient.go b/services/nvpair-engine-manager/remoteclient.go index 681b0d31..cf1ccd3a 100644 --- a/services/nvpair-engine-manager/remoteclient.go +++ b/services/nvpair-engine-manager/remoteclient.go @@ -42,27 +42,26 @@ func (e *remoteFrameError) Error() string { return e.Msg } type remoteClient struct { http *http.Client // readyHTTP serves endpoints whose peer may withhold response headers during - // engine readiness or Ollama model loading. See waitsForEngineReadiness. + // engine readiness or model loading. See waitsForEngineReadiness. readyHTTP *http.Client base string // https://: forget func() } // waitsForEngineReadiness reports whether a peer may only answer after an -// engine is healthy or an Ollama model is loaded, which the ordinary 30s -// response-header budget cannot cover. +// engine is healthy or a model is loaded, which the ordinary 30s +// response-header budget cannot cover. Every engine's load can wait on a cold +// model: the bundled load actions declare a 600 s header wait (timeout_s), and +// the peer's own action timeout still bounds the call. // // Cutting such a call off is worse than slow. The initiator's cancellation // propagates into the peer's in-flight handler, so bringUpCommand tears the // engine back down — for a delete that means the files are gone, the engine is // left stopped, and the caller is told the delete failed. -func waitsForEngineReadiness(path, engine string) bool { +func waitsForEngineReadiness(path string) bool { // controlDeletePath: LM Studio's delete_model declares restart_after, so the // peer replies only after the post-delete restart is ready. - if path == controlLoadPath { - return engine == "ollama" - } - return path == controlStartPath || path == controlDeletePath + return path == controlLoadPath || path == controlStartPath || path == controlDeletePath } func newRemoteHTTPClient(base *http.Transport, responseHeaderTimeout time.Duration) *http.Client { @@ -146,7 +145,7 @@ func (c *remoteClient) postJSON(ctx context.Context, path, engine string, body a } req.Header.Set("Content-Type", "application/json") client := c.http - if waitsForEngineReadiness(path, engine) && c.readyHTTP != nil { + if waitsForEngineReadiness(path) && c.readyHTTP != nil { client = c.readyHTTP } resp, err := client.Do(req) diff --git a/services/nvpair-engine-manager/remoteclient_test.go b/services/nvpair-engine-manager/remoteclient_test.go index c4d16e67..9d8de788 100644 --- a/services/nvpair-engine-manager/remoteclient_test.go +++ b/services/nvpair-engine-manager/remoteclient_test.go @@ -35,9 +35,10 @@ func TestRemoteStartUsesReadinessHeaderBudget(t *testing.T) { } } -// A remote Ollama load can withhold headers while a cold model loads. A remote -// LM Studio delete can likewise restart the peer's engine before it replies. -// Both need the longer response-header budget; other model calls remain bounded. +// A remote load on any engine can withhold headers while a cold model loads. A +// remote LM Studio delete can likewise restart the peer's engine before it +// replies. Both need the longer response-header budget; other model calls +// remain bounded. func TestRemoteSlowModelOperationsUseReadinessHeaderBudget(t *testing.T) { srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { time.Sleep(100 * time.Millisecond) @@ -60,9 +61,11 @@ func TestRemoteSlowModelOperationsUseReadinessHeaderBudget(t *testing.T) { if _, err := c.postJSON(context.Background(), controlDeletePath, "lmstudio", lmstudio); err != nil { t.Fatalf("remote delete was cut off by the ordinary response-header budget: %v", err) } - if _, err := c.postJSON(context.Background(), controlLoadPath, "lmstudio", lmstudio); err == nil || - !strings.Contains(err.Error(), "timeout awaiting response headers") { - t.Fatalf("remote LM Studio load error = %v, want the ordinary bounded response-header timeout", err) + for _, engine := range []string{"lmstudio", "omlx"} { + load := modelActionRequest{Engine: engine, Model: "qwen2.5"} + if _, err := c.postJSON(context.Background(), controlLoadPath, engine, load); err != nil { + t.Fatalf("remote %s load was cut off by the ordinary response-header budget: %v", engine, err) + } } if _, err := c.postJSON(context.Background(), controlUnloadPath, "ollama", ollama); err == nil || !strings.Contains(err.Error(), "timeout awaiting response headers") { @@ -75,22 +78,16 @@ func TestRemoteReadinessBudgetCoversEngineStartupAllowance(t *testing.T) { t.Fatalf("readiness budget %s must exceed the ordinary budget %s", remoteReadyResponseHeaderTimeout, remoteResponseHeaderTimeout) } - cases := []struct { - path string - engine string - want bool - }{ - {controlStartPath, "ollama", true}, - {controlDeletePath, "lmstudio", true}, - {controlLoadPath, "ollama", true}, - {controlLoadPath, "lmstudio", false}, - {controlStopPath, "ollama", false}, - {controlUnloadPath, "ollama", false}, - {controlEnginesPath, "", false}, - } - for _, tc := range cases { - if got := waitsForEngineReadiness(tc.path, tc.engine); got != tc.want { - t.Errorf("waitsForEngineReadiness(%q, %q) = %v, want %v", tc.path, tc.engine, got, tc.want) + for path, want := range map[string]bool{ + controlStartPath: true, + controlDeletePath: true, + controlLoadPath: true, + controlStopPath: false, + controlUnloadPath: false, + controlEnginesPath: false, + } { + if got := waitsForEngineReadiness(path); got != want { + t.Errorf("waitsForEngineReadiness(%q) = %v, want %v", path, got, want) } } } diff --git a/services/ollama-proxy/README.md b/services/ollama-proxy/README.md index 21b7eb09..998e2f17 100644 --- a/services/ollama-proxy/README.md +++ b/services/ollama-proxy/README.md @@ -34,6 +34,7 @@ ollama-proxy [flags] | `--alias-address` | *(empty)* | Optional secondary `host:port` for the same routing handler. Repeat the flag to reserve both loopback families for `localhost`. Only literal loopback addresses are accepted; the broker uses this for a safe inherited local `OLLAMA_HOST`, and the aliases are not advertised to peers. | | `--ignore-persisted-port` | `false` | Use `--port` even when `proxy-port.json` contains a saved port (used by broker-managed startup) | | `--ipc` | *(empty — use stdio)* | Path to a Unix domain socket or Windows named pipe for IPC | +| `--response-header-timeout` | `$NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT`, else `120s` | How long to wait for an upstream engine to start answering (Go duration, e.g. `10m`). An engine sends no headers until generation starts, so raise it when requests queue behind long jobs or wait on slow model loads. An invalid or non-positive value keeps the default | | `--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`. | | `--version` | | Print version and exit | diff --git a/services/ollama-proxy/main.go b/services/ollama-proxy/main.go index c8b6870f..3415ac7c 100644 --- a/services/ollama-proxy/main.go +++ b/services/ollama-proxy/main.go @@ -36,11 +36,13 @@ func main() { var aliasAddresses aliasAddressFlags flag.Var(&aliasAddresses, "alias-address", "optional loopback-only HTTP alias address (repeat for another loopback family)") ignorePersistedPort := flag.Bool("ignore-persisted-port", false, "use --port even when a persisted port exists") + responseHeaderTimeout := flag.String("response-header-timeout", "", "upstream response-header timeout (Go duration, e.g. 10m); default: $NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT or 120s") 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") showVersion := flag.Bool("version", false, "print version and exit") resolveLevel := applog.RegisterFlag(nil, slog.LevelInfo) flag.Parse() + proxyResponseTimeout = resolveResponseHeaderTimeout(*responseHeaderTimeout) if *showVersion { fmt.Println(Version) diff --git a/services/ollama-proxy/proxy.go b/services/ollama-proxy/proxy.go index 48046fdc..11f5f4be 100644 --- a/services/ollama-proxy/proxy.go +++ b/services/ollama-proxy/proxy.go @@ -19,6 +19,7 @@ import ( "net/http" "net/http/httputil" "net/url" + "os" "sort" "strconv" "strings" @@ -577,11 +578,16 @@ func (p *Proxy) Run(ctx context.Context) error { // 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. An engine sends 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 @@ -589,6 +595,37 @@ 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 a value set in the broker's (or the desktop app's) +// environment is inherited; on macOS, `launchctl setenv` reaches an app opened +// from the Finder. +const responseHeaderTimeoutEnv = "NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT" + +// proxyResponseTimeout is the effective upstream response-header timeout, +// resolved at startup: the flag, then the environment, then the default. +// Transports are built lazily, so assigning it before serving is sufficient. +var proxyResponseTimeout = defaultProxyResponseTimeout + +// resolveResponseHeaderTimeout applies the flag > env > default precedence. A +// missing, unparseable or non-positive value keeps the default, so a bad +// setting can never 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 diff --git a/services/ollama-proxy/response_timeout_test.go b/services/ollama-proxy/response_timeout_test.go new file mode 100644 index 00000000..7d5b8557 --- /dev/null +++ b/services/ollama-proxy/response_timeout_test.go @@ -0,0 +1,40 @@ +// 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) { + for _, tc := range []struct { + name, flag, env string + want time.Duration + }{ + {"default", "", "", defaultProxyResponseTimeout}, + {"environment", "", "10m", 10 * time.Minute}, + {"flag beats environment", "5m", "10m", 5 * time.Minute}, + {"unparseable keeps the default", "soon", "", defaultProxyResponseTimeout}, + {"zero keeps the default", "0s", "", defaultProxyResponseTimeout}, + {"negative keeps the default", "", "-1m", defaultProxyResponseTimeout}, + } { + 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) with env %q = %s, want %s", tc.flag, tc.env, got, tc.want) + } + }) + } +} + +// Transports are built after main resolves the timeout, so they carry it. +func TestTransportsUseTheResolvedTimeout(t *testing.T) { + old := proxyResponseTimeout + t.Cleanup(func() { proxyResponseTimeout = old }) + proxyResponseTimeout = 7 * time.Minute + if got := newProxyTransport(nil).ResponseHeaderTimeout; got != 7*time.Minute { + t.Fatalf("ResponseHeaderTimeout = %s, want 7m", got) + } +} diff --git a/services/omlx-proxy/README.md b/services/omlx-proxy/README.md index d53e7bd1..ca168474 100644 --- a/services/omlx-proxy/README.md +++ b/services/omlx-proxy/README.md @@ -35,6 +35,7 @@ omlx-proxy [flags] | `--port` | `1234` | HTTP listen port for request forwarding | | `--ignore-persisted-port` | `false` | Use `--port` even when a prior runtime port was saved | | `--ipc` | *(empty — use stdio)* | Path to a Unix domain socket or Windows named pipe for IPC | +| `--response-header-timeout` | `$NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT`, else `120s` | How long to wait for an upstream engine to start answering (Go duration, e.g. `10m`). An engine sends no headers until generation starts, so raise it when requests queue behind long jobs or wait on slow model loads. An invalid or non-positive value keeps the default | | `--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`. | | `--version` | | Print version and exit | diff --git a/services/omlx-proxy/main.go b/services/omlx-proxy/main.go index 8155a8c6..9554f20d 100644 --- a/services/omlx-proxy/main.go +++ b/services/omlx-proxy/main.go @@ -25,11 +25,13 @@ import ( func main() { port := flag.Int("port", defaultProxyPort, "HTTP listen port") ignorePersistedPort := flag.Bool("ignore-persisted-port", false, "use --port even when a persisted port exists") + responseHeaderTimeout := flag.String("response-header-timeout", "", "upstream response-header timeout (Go duration, e.g. 10m); default: $NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT or 120s") 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") showVersion := flag.Bool("version", false, "print version and exit") resolveLevel := applog.RegisterFlag(nil, slog.LevelInfo) flag.Parse() + proxyResponseTimeout = resolveResponseHeaderTimeout(*responseHeaderTimeout) if *showVersion { fmt.Println(Version) diff --git a/services/omlx-proxy/proxy.go b/services/omlx-proxy/proxy.go index d7d3f92b..306dd495 100644 --- a/services/omlx-proxy/proxy.go +++ b/services/omlx-proxy/proxy.go @@ -607,11 +607,16 @@ func (p *Proxy) Run(ctx context.Context) error { // 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. An engine sends 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 @@ -619,6 +624,37 @@ 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 a value set in the broker's (or the desktop app's) +// environment is inherited; on macOS, `launchctl setenv` reaches an app opened +// from the Finder. +const responseHeaderTimeoutEnv = "NVPAIR_PROXY_RESPONSE_HEADER_TIMEOUT" + +// proxyResponseTimeout is the effective upstream response-header timeout, +// resolved at startup: the flag, then the environment, then the default. +// Transports are built lazily, so assigning it before serving is sufficient. +var proxyResponseTimeout = defaultProxyResponseTimeout + +// resolveResponseHeaderTimeout applies the flag > env > default precedence. A +// missing, unparseable or non-positive value keeps the default, so a bad +// setting can never 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 diff --git a/services/omlx-proxy/response_timeout_test.go b/services/omlx-proxy/response_timeout_test.go new file mode 100644 index 00000000..7d5b8557 --- /dev/null +++ b/services/omlx-proxy/response_timeout_test.go @@ -0,0 +1,40 @@ +// 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) { + for _, tc := range []struct { + name, flag, env string + want time.Duration + }{ + {"default", "", "", defaultProxyResponseTimeout}, + {"environment", "", "10m", 10 * time.Minute}, + {"flag beats environment", "5m", "10m", 5 * time.Minute}, + {"unparseable keeps the default", "soon", "", defaultProxyResponseTimeout}, + {"zero keeps the default", "0s", "", defaultProxyResponseTimeout}, + {"negative keeps the default", "", "-1m", defaultProxyResponseTimeout}, + } { + 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) with env %q = %s, want %s", tc.flag, tc.env, got, tc.want) + } + }) + } +} + +// Transports are built after main resolves the timeout, so they carry it. +func TestTransportsUseTheResolvedTimeout(t *testing.T) { + old := proxyResponseTimeout + t.Cleanup(func() { proxyResponseTimeout = old }) + proxyResponseTimeout = 7 * time.Minute + if got := newProxyTransport(nil).ResponseHeaderTimeout; got != 7*time.Minute { + t.Fatalf("ResponseHeaderTimeout = %s, want 7m", got) + } +}