From 1546ebc5486351b10ae7e6263cc435d03c0bfd79 Mon Sep 17 00:00:00 2001 From: favo <827982457@qq.com> Date: Sat, 17 Oct 2026 22:31:36 +0800 Subject: [PATCH 1/2] fix(qoder): fail over on streaming first-byte timeout and watchdog stuck workers A Qoder stream whose response head never arrives hung the client until it gave up. Symptoms were requests with only an entry log line and no "chat reasoning resolved" exit line, and a worker that stayed alive as a process but stopped answering /health while still being routed to. - providers: add ErrFirstByteTimeout and doWithFirstByteTimeout on the qoder streaming path (adapter + Direct). The 30s deadline covers the response head only; once headers land the SSE body streams under the parent context's lifetime, so long thinking-model output is not cut off. A parent cancel still surfaces unchanged so it does not read as an upstream failure worth cooling down. - executor: classify ErrFirstByteTimeout as unavailable + failover with a 10s cooldown, ahead of the context.Canceled check, so a stuck upstream sheds the account briefly and the next eligible one serves the turn. - worker: wrap the upstream fetch in fetchWithTimeout with a 30s TTFB deadline and a 300s total-stream backstop, returning stable first_byte_timeout / stream_total_timeout errors. Previously the fetch had no AbortSignal, so a stalled upstream held the worker's in-flight slot forever. Both deadlines are tunable per deployment. - runtime: add a worker liveness watchdog to the maintenance loop. Each 30s tick issues one lightweight /health round-trip per worker account; three consecutive failures (~90s grace, enough to ride out a transient blip or a mid-rewarm) stop the worker and hand it to the existing watchAccount + beginAccountRecovery reboot path. In-process accounts are skipped by probeHealthOnly and unaffected. - docs: record in worker/NOTICE that Global's campaign service reserves the claimable daily check-in for the desktop client's own session token, so Global accounts cannot be auto-checked-in by the worker. Tests cover the new classification, prefix resolution, TTFB helper, and the watchdog threshold/backoff path. --- changelog/unreleased/worker-stream-timeout.md | 11 ++ internal/executor/classify_test.go | 30 ++++ internal/executor/error.go | 12 ++ internal/providers/interfaces.go | 8 + internal/providers/qoder/adapter.go | 4 +- internal/providers/qoder/direct.go | 2 +- .../qoder/first_byte_timeout_test.go | 109 +++++++++++++ internal/providers/qoder/worker.go | 35 ++++ internal/runtime/manager.go | 8 + internal/runtime/manager_maintenance.go | 65 ++++++++ internal/runtime/manager_probe.go | 28 ++++ .../runtime/probe_worker_liveness_test.go | 151 ++++++++++++++++++ worker/NOTICE | 12 ++ worker/src/daemon.mjs | 46 +++++- 14 files changed, 517 insertions(+), 4 deletions(-) create mode 100644 changelog/unreleased/worker-stream-timeout.md create mode 100644 internal/providers/qoder/first_byte_timeout_test.go create mode 100644 internal/runtime/probe_worker_liveness_test.go diff --git a/changelog/unreleased/worker-stream-timeout.md b/changelog/unreleased/worker-stream-timeout.md new file mode 100644 index 00000000..64022f0c --- /dev/null +++ b/changelog/unreleased/worker-stream-timeout.md @@ -0,0 +1,11 @@ +### English + +- Stop streaming chat from hanging on a stuck upstream. A Qoder stream request whose first byte never arrives (the symptom was `qwen3.8-flash` requests with only an entry log line and no `chat reasoning resolved`) now fails fast after a 30-second TTFB deadline, classifies as `first_byte_timeout` / `unavailable` with failover, and is retried on the next eligible account instead of hanging the client until it gives up. The deadline is on the response head only — once headers arrive, the SSE body streams under the request's normal lifetime, so long thinking-model output is not cut off. +- Give the worker daemon its own upstream timeout. The worker's `fetch` to the Qoder gateway previously had no `AbortSignal`, so a stalled upstream held the worker's in-flight slot forever. It now aborts on a 30-second first-byte deadline and a 300-second total-stream backstop, returning a stable `first_byte_timeout` / `stream_total_timeout` error so the Go side can classify and fail over. Both are tunable via `QODER_STREAM_TTFB_MS` / `QODER_STREAM_TOTAL_MS`. +- Add a worker liveness watchdog to the maintenance loop. Health probes previously ran only at boot plus on manual console refresh, so a worker that stayed "alive" as a process but stopped serving `/health` was never noticed and kept being routed to. Every 30-second tick now issues one lightweight `/health` round-trip per worker account; three consecutive failures (~90s grace, enough to ride out a transient blip or mid-rewarm) stop the worker and hand it to the existing `watchAccount` + `beginAccountRecovery` path, which reboots it with backoff. In-process accounts (WorkBuddy / Trae / Devin) are skipped and unaffected. + +### 中文 + +- 流式 chat 不再因上游卡死而无响应地挂起。Qoder 流式请求如果首字节迟迟不到(现象是 `qwen3.8-flash` 请求只有入口日志、没有 `chat reasoning resolved` 出口日志),现在会在 30 秒 TTFB 阈值后快速失败,归类为 `first_byte_timeout` / `unavailable` 并触发 failover,切到下一个可用账号重试,而不是把客户端挂到自行超时。该超时只针对响应头:一旦头部到达,SSE body 回到请求原本的生命周期,长思考模型的输出不会被截断。 +- 给 worker 守护进程加上自己的上游超时。worker 对 Qoder 网关的 `fetch` 此前没有 `AbortSignal`,上游停滞时会永久占用 worker 的并发槽。现在它在 30 秒首字节超时和 300 秒整体流式兜底任一触发时 abort,返回稳定的 `first_byte_timeout` / `stream_total_timeout` 错误,让 Go 侧分类并 failover。两者均可通过 `QODER_STREAM_TTFB_MS` / `QODER_STREAM_TOTAL_MS` 调整。 +- 给维护循环加 worker liveness 看门狗。健康探针此前只在启动时和手动控制台刷新时跑,所以一个"进程还活着但 `/health` 不再响应"的 worker 永远不会被察觉,还会继续被路由命中。现在每 30 秒维护周期对每个 worker 账号发一次轻量 `/health` 探针;连续 3 次失败(约 90 秒容忍窗口,足以扛过瞬时抖动或 rewarm 中途)就停止该 worker,交给既有的 `watchAccount` + `beginAccountRecovery` 路径按退避重启。进程内账号(WorkBuddy / Trae / Devin)被跳过,不受影响。 diff --git a/internal/executor/classify_test.go b/internal/executor/classify_test.go index c2ab5ad6..61e4a92c 100644 --- a/internal/executor/classify_test.go +++ b/internal/executor/classify_test.go @@ -320,3 +320,33 @@ func TestClassifyErrorUpstreamEmptyNoCooldown(t *testing.T) { t.Errorf("expected generic unavailable to keep cooldown, got %v", generic.Cooldown) } } + +// A streaming first-byte timeout is an upstream hang: the client request is +// still alive, the upstream just never sent a response head. It must classify +// as upstream_unavailable with failover so the next eligible account serves +// the turn, plus a short cooldown to shed a stuck worker for a few seconds. +func TestClassifyErrorFirstByteTimeoutFailsOver(t *testing.T) { + err := fmt.Errorf("%w: no response head within 1m0s", providers.ErrFirstByteTimeout) + got := ClassifyError(err) + if got.Kind != accounts.KindUnavailable { + t.Fatalf("Kind=%s, want %s", got.Kind, accounts.KindUnavailable) + } + if !got.Failover { + t.Fatalf("Failover=false, want true") + } + if got.Cooldown != 10*time.Second || got.RetryAfter != 10*time.Second { + t.Fatalf("Cooldown=%s RetryAfter=%s, want 10s", got.Cooldown, got.RetryAfter) + } + if got.Code != "first_byte_timeout" { + t.Fatalf("Code=%q, want first_byte_timeout", got.Code) + } +} + +// A plain client cancel must not be reclassified as a first-byte timeout; the +// executor skips failover and cooldown for cancellations. +func TestClassifyErrorContextCanceledStaysCanceled(t *testing.T) { + got := ClassifyError(context.Canceled) + if got.Kind != accounts.KindCanceled || got.Failover { + t.Fatalf("got Kind=%s Failover=%v, want %s/false", got.Kind, got.Failover, accounts.KindCanceled) + } +} diff --git a/internal/executor/error.go b/internal/executor/error.go index 66f49f26..458f354e 100644 --- a/internal/executor/error.go +++ b/internal/executor/error.go @@ -3,6 +3,7 @@ package executor import ( "context" "errors" + "net/http" "strings" "time" @@ -88,6 +89,17 @@ func ClassifyError(err error) Classified { if errors.As(err, &execErr) && execErr != nil { return execErr.Classified } + // A streaming first-byte timeout is an upstream hang, not a client cancel: + // the parent request is still alive, the upstream just never answered. Cool + // the account briefly and fail over so the next eligible account serves the + // turn instead of hanging until the client gives up. + if errors.Is(err, providers.ErrFirstByteTimeout) { + return Classified{ + Kind: accounts.KindUnavailable, Status: http.StatusBadGateway, + Failover: true, Cooldown: 10 * time.Second, RetryAfter: 10 * time.Second, + Code: "first_byte_timeout", Message: err.Error(), + } + } if errors.Is(err, context.Canceled) || errors.Is(err, context.DeadlineExceeded) { return Classified{ Kind: accounts.KindCanceled, Status: 499, Failover: false, diff --git a/internal/providers/interfaces.go b/internal/providers/interfaces.go index c5fa7fb9..33dd4569 100644 --- a/internal/providers/interfaces.go +++ b/internal/providers/interfaces.go @@ -15,6 +15,14 @@ import ( // implicit support. var ErrUnsupported = errors.New("provider capability unsupported") +// ErrFirstByteTimeout is returned by streaming chat adapters when the upstream +// did not send the response head (headers + first byte) within the TTFB +// deadline. The executor classifies it as upstream_unavailable with failover so +// the next eligible account is tried, instead of hanging on a stuck upstream. +// It must not be wrapped with context.DeadlineExceeded, or the executor would +// re-classify it as a client cancellation and skip failover. +var ErrFirstByteTimeout = errors.New("first byte timeout") + type ModelCapabilities struct { ContextWindow int `json:"context_window,omitempty"` ContextWindowMax int `json:"context_window_max,omitempty"` diff --git a/internal/providers/qoder/adapter.go b/internal/providers/qoder/adapter.go index 9c736f23..f79f8f2f 100644 --- a/internal/providers/qoder/adapter.go +++ b/internal/providers/qoder/adapter.go @@ -546,9 +546,9 @@ func (c *Client) ChatStream(ctx context.Context, accountID string, req translate cloned.Timeout = 0 httpClient = &cloned } - resp, err := httpClient.Do(httpReq) + resp, err := doWithFirstByteTimeout(httpClient, httpReq) if err != nil { - return nil, providers.ResolvedChat{}, TransportError{Err: err} + return nil, providers.ResolvedChat{}, err } return resp, resolved, nil } diff --git a/internal/providers/qoder/direct.go b/internal/providers/qoder/direct.go index 718ef3c3..8e8d76df 100644 --- a/internal/providers/qoder/direct.go +++ b/internal/providers/qoder/direct.go @@ -128,7 +128,7 @@ func (d *Direct) ChatStream(ctx context.Context, accountID string, req translate if err != nil { return nil, providers.ResolvedChat{}, err } - resp, err := d.http.Do(prepared.request) + resp, err := doWithFirstByteTimeout(d.http, prepared.request) if err != nil { return nil, providers.ResolvedChat{}, err } diff --git a/internal/providers/qoder/first_byte_timeout_test.go b/internal/providers/qoder/first_byte_timeout_test.go new file mode 100644 index 00000000..af6f8342 --- /dev/null +++ b/internal/providers/qoder/first_byte_timeout_test.go @@ -0,0 +1,109 @@ +package qoder + +import ( + "context" + "errors" + "net/http" + "net/http/httptest" + "testing" + "time" + + "github.com/caigee-cmd/cli2api/internal/providers" +) + +// A stuck upstream that never sends the response head must surface as +// ErrFirstByteTimeout so the executor can fail the attempt over instead of +// hanging the client until it gives up. The 60s production deadline is shrunk +// for the test so the assertion runs in milliseconds. +func TestDoWithFirstByteTimeoutHangsAsFirstByteTimeout(t *testing.T) { + prev := firstByteTimeout + firstByteTimeout = 50 * time.Millisecond + t.Cleanup(func() { firstByteTimeout = prev }) + + // Handler blocks forever: it accepts the body but never writes a response. + hung := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + <-r.Context().Done() + })) + t.Cleanup(hung.Close) + + req, err := http.NewRequestWithContext(context.Background(), http.MethodPost, hung.URL, nil) + if err != nil { + t.Fatalf("NewRequest: %v", err) + } + client := &http.Client{Timeout: 0} // mimic streaming client: no whole-call timeout + _, err = doWithFirstByteTimeout(client, req) + if !errors.Is(err, providers.ErrFirstByteTimeout) { + t.Fatalf("want ErrFirstByteTimeout, got %v", err) + } +} + +// When the parent context is already cancelled the helper must propagate the +// plain transport error instead of masking it as a first-byte timeout; the +// executor classifies client cancels as KindCanceled (no failover, no cooldown). +func TestDoWithFirstByteTimeoutParentCancelIsNotFirstByteTimeout(t *testing.T) { + prev := firstByteTimeout + firstByteTimeout = 50 * time.Millisecond + t.Cleanup(func() { firstByteTimeout = prev }) + + hung := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + <-r.Context().Done() + })) + t.Cleanup(hung.Close) + + ctx, cancel := context.WithCancel(context.Background()) + req, err := http.NewRequestWithContext(ctx, http.MethodPost, hung.URL, nil) + if err != nil { + t.Fatalf("NewRequest: %v", err) + } + client := &http.Client{Timeout: 0} + + // Cancel before the call so parent.Err() is non-nil at the point of failure. + cancel() + _, err = doWithFirstByteTimeout(client, req) + if errors.Is(err, providers.ErrFirstByteTimeout) { + t.Fatalf("parent-cancelled call must not surface as ErrFirstByteTimeout, got %v", err) + } + if err == nil { + t.Fatalf("want non-nil error for cancelled parent context") + } +} + +// A well-behaved upstream that returns a response head quickly must not be +// cut off by the TTFB timer, and the body must stay readable afterwards. +func TestDoWithFirstByteTimeoutFastHeadReturnsBody(t *testing.T) { + prev := firstByteTimeout + firstByteTimeout = 5 * time.Second + t.Cleanup(func() { firstByteTimeout = prev }) + + ok := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("content-type", "text/event-stream") + w.WriteHeader(http.StatusOK) + // Slow trickle SSE chunks to prove the body is readable past the TTFB + // timer being stopped. + flusher, _ := w.(http.Flusher) + for i := 0; i < 3; i++ { + _, _ = w.Write([]byte("data: chunk\n\n")) + if flusher != nil { + flusher.Flush() + } + time.Sleep(20 * time.Millisecond) + } + })) + t.Cleanup(ok.Close) + + req, err := http.NewRequestWithContext(context.Background(), http.MethodPost, ok.URL, nil) + if err != nil { + t.Fatalf("NewRequest: %v", err) + } + client := &http.Client{Timeout: 0} + resp, err := doWithFirstByteTimeout(client, req) + if err != nil { + t.Fatalf("want nil err for fast head, got %v", err) + } + defer resp.Body.Close() + buf := make([]byte, 1024) + n, err := resp.Body.Read(buf) + if err != nil || n == 0 { + t.Fatalf("body read after TTFB timer stop: n=%d err=%v", n, err) + } +} diff --git a/internal/providers/qoder/worker.go b/internal/providers/qoder/worker.go index 20bd1f19..12fa79ac 100644 --- a/internal/providers/qoder/worker.go +++ b/internal/providers/qoder/worker.go @@ -13,6 +13,7 @@ import ( "github.com/caigee-cmd/cli2api/internal/accounts" "github.com/caigee-cmd/cli2api/internal/endpoint" + "github.com/caigee-cmd/cli2api/internal/providers" ) var ( @@ -49,6 +50,40 @@ func (e TransportError) Error() string { func (e TransportError) Unwrap() error { return e.Err } +// firstByteTimeout caps how long a streaming chat request will wait for the +// upstream response head (status + headers). Once the head arrives, the timer +// is stopped and the SSE body streams under the parent context's lifetime, so +// long thinking-model output is not cut off. A stuck upstream that never sends +// a first byte surfaces as ErrFirstByteTimeout so the executor can fail over to +// the next account instead of hanging forever. 30s covers slow cold-starts +// and thinking-model first-token latency while keeping a stuck-upstream failover +// inside one round-trip of the client's patience. +var firstByteTimeout = 30 * time.Second + +// doWithFirstByteTimeout sends req with client, returning a response once the +// response head is received. If the head does not arrive within +// firstByteTimeout it returns an error wrapping providers.ErrFirstByteTimeout; +// if the parent context was already cancelled it surfaces that error unchanged +// so the executor classifies it as a client cancellation rather than a timeout. +func doWithFirstByteTimeout(client *http.Client, req *http.Request) (*http.Response, error) { + parent := req.Context() + ttfbCtx, cancelTTFB := context.WithCancel(parent) + defer cancelTTFB() + timer := time.AfterFunc(firstByteTimeout, cancelTTFB) + defer timer.Stop() + resp, err := client.Do(req.WithContext(ttfbCtx)) + if err == nil { + return resp, nil + } + // TTFB fired only when the parent context is still alive: a parent cancel + // (client disconnect, shutdown) must stay a plain cancel so the executor + // does not treat it as an upstream failure worth cooling down. + if parent.Err() == nil && ttfbCtx.Err() != nil && !errors.Is(parent.Err(), context.Canceled) { + return nil, fmt.Errorf("%w: no response head within %s", providers.ErrFirstByteTimeout, firstByteTimeout) + } + return nil, TransportError{Err: err} +} + type HTTPStatusError struct { Op string Status int diff --git a/internal/runtime/manager.go b/internal/runtime/manager.go index 5437c75a..cb5bb696 100644 --- a/internal/runtime/manager.go +++ b/internal/runtime/manager.go @@ -127,6 +127,13 @@ type Manager struct { // account removal can race with the sweep. quotaProbeMu sync.Mutex quotaProbeLevels map[string]int + + // healthFailures counts consecutive liveness probe failures per worker + // account. The maintenance loop's workerLiveness watchdog increments it on + // each failed /health probe and clears it on success; reaching + // workerLivenessThreshold triggers a stopAccount so watchAccount + + // beginAccountRecovery reboot the stuck worker. Guarded by mu. + healthFailures map[string]int } func NewManager(config ManagerConfig, store AccountStore, starter ProcessStarter) *Manager { @@ -165,6 +172,7 @@ func NewManager(config ManagerConfig, store AccountStore, starter ProcessStarter persistCloseCh: make(chan struct{}), cpuPrev: map[int]procTime{}, quotaProbeLevels: map[string]int{}, + healthFailures: map[string]int{}, } manager.persistCond = sync.NewCond(&manager.persistMu) manager.persistDone.Add(1) diff --git a/internal/runtime/manager_maintenance.go b/internal/runtime/manager_maintenance.go index 8f9898d0..0c11b6c1 100644 --- a/internal/runtime/manager_maintenance.go +++ b/internal/runtime/manager_maintenance.go @@ -289,6 +289,10 @@ func (manager *Manager) RunMaintenanceLoop(stop <-chan struct{}) { // Seed the throttle so the first pass does not duplicate the boot-time // RefreshAll: the next stale-quota sweep runs 5 minutes after startup. lastStaleQuota := time.Now() + // Liveness probes start one tick in so boot-time RefreshAll owns the first + // /health round-trip and short-lived tests with a stub worker are not probed + // the instant the loop starts. + lastLiveness := time.Now() for { if ctx.Err() != nil { return @@ -303,6 +307,10 @@ func (manager *Manager) RunMaintenanceLoop(stop <-chan struct{}) { lastKeepaliveDay = day } manager.sampleResources() + if now.Sub(lastLiveness) >= 30*time.Second { + manager.probeWorkerLiveness(ctx) + lastLiveness = now + } if now.Sub(lastStaleQuota) >= staleQuotaInterval { manager.refreshStaleQuota(ctx) lastStaleQuota = now @@ -479,3 +487,60 @@ func (manager *Manager) pruneQuotaProbeLevels(seen map[string]struct{}) { } } } + +// workerLivenessThreshold is how many consecutive /health probe failures the +// watchdog tolerates before rebooting a stuck worker. At a 30s maintenance +// cadence that is roughly a 90s grace window: long enough to ride out a +// transient network blip or a worker mid-rewarm, short enough that a genuinely +// stuck process is recovered before clients notice repeated hangs. +const workerLivenessThreshold = 3 + +// probeWorkerLiveness is the worker-side watchdog. refreshOne and the boot-time +// RefreshAll only run at startup and on manual console refresh, so a worker +// that goes "alive but stuck" after boot — /health no longer responds, or its +// goroutine is wedged — would stay routed to forever without this loop. Each +// 30s tick issues one /health round-trip per worker account; on the +// threshold-th consecutive failure it calls stopAccount so the existing +// watchAccount + beginAccountRecovery path reboots the worker with backoff. +// +// In-process accounts are skipped by probeHealthOnly and never enter the +// failure counter, so WorkBuddy / Trae / Devin are unaffected. +func (manager *Manager) probeWorkerLiveness(ctx context.Context) { + for _, item := range manager.pool.Items() { + if item.RuntimeState == "dead" { + continue + } + ready, err := manager.probeHealthOnly(ctx, item) + if err == nil && ready { + manager.mu.Lock() + delete(manager.healthFailures, item.ID) + manager.mu.Unlock() + continue + } + // Skip accounts already in recovery: stopAccount removed them from + // processes and beginAccountRecovery owns the reboot. Touching them + // here would double-restart or race the recovering guard. + manager.mu.Lock() + if manager.recovering[item.ID] { + manager.mu.Unlock() + continue + } + manager.healthFailures[item.ID]++ + fails := manager.healthFailures[item.ID] + manager.mu.Unlock() + if fails >= workerLivenessThreshold { + log.Printf("worker liveness: account %s failed %d consecutive health probes (%v); stopping for recovery", + item.ID, fails, err) + manager.mu.Lock() + delete(manager.healthFailures, item.ID) + manager.mu.Unlock() + // stopAccount kills the child process; watchAccount sees the exit + // via process.Done() and calls beginAccountRecovery, which owns the + // backoff restart. No direct recovery call here — that would race + // the recovering guard. + if perr := manager.stopAccount(item.ID); perr != nil { + log.Printf("worker liveness: stop %s failed: %v", item.ID, perr) + } + } + } +} diff --git a/internal/runtime/manager_probe.go b/internal/runtime/manager_probe.go index 68191600..3a307c76 100644 --- a/internal/runtime/manager_probe.go +++ b/internal/runtime/manager_probe.go @@ -148,3 +148,31 @@ func (m *Manager) forceReady(accountID string) bool { _, err := os.Stat(filepath.Join(m.config.DataDir, "force-ready", accountID)) return err == nil } + +// probeHealthOnly issues a single GET /health to a worker account with a tight +// 2s deadline. It is the liveness probe used by the maintenance-loop watchdog: +// unlike refreshOne, it does not fetch quota or refresh the model catalog, so a +// 30s-loop call costs one HTTP round-trip, not a quota probe. The pool state +// machine is left to refreshOne and the manual console refresh path; this only +// decides whether the worker is still alive enough to route to. +// +// In-process accounts (WorkBuddy / Trae / Devin) have no child-process /health +// endpoint and never need this check — their liveness is the adapter's own +// transport, which the executor already classifies. probeHealthOnly returns +// (true, nil) for them so the watchdog skips them. +func (m *Manager) probeHealthOnly(ctx context.Context, item Item) (bool, error) { + if item.Runtime == string(providers.RuntimeInProcess) || strings.TrimSpace(item.URL) == "" { + return true, nil + } + probeCtx, cancel := context.WithTimeout(ctx, 2*time.Second) + defer cancel() + client := qoder.WorkerClient{HTTP: m.httpClient} + health, statusCode, err := client.Health(probeCtx, item.URL) + if err != nil { + return false, err + } + if statusCode >= 300 || !health.OK { + return false, nil + } + return health.Ready, nil +} diff --git a/internal/runtime/probe_worker_liveness_test.go b/internal/runtime/probe_worker_liveness_test.go new file mode 100644 index 00000000..f5cfa417 --- /dev/null +++ b/internal/runtime/probe_worker_liveness_test.go @@ -0,0 +1,151 @@ +package runtime + +import ( + "context" + "path/filepath" + "strconv" + "testing" + "time" + + "github.com/caigee-cmd/cli2api/internal/accounts" + sqlstore "github.com/caigee-cmd/cli2api/internal/store" +) + +// livenessProcess is a minimal ManagedProcess for the watchdog test: its URL +// points at an unlistened port so probeHealthOnly's /health round-trip fails on +// transport, and Stop records that it was invoked. +type livenessProcess struct { + url string + stopped bool + done chan error +} + +func (p *livenessProcess) URL() string { return p.url } +func (p *livenessProcess) Done() <-chan error { return p.done } +func (p *livenessProcess) PID() int { return 0 } +func (p *livenessProcess) Stop() error { + p.stopped = true + select { + case p.done <- nil: + default: + } + return nil +} + +type livenessStarter struct { + started chan *livenessProcess +} + +func (s *livenessStarter) Start(_ context.Context, _ accounts.Account, _ string, port int) (ManagedProcess, error) { + p := &livenessProcess{ + url: "http://127.0.0.1:" + strconv.Itoa(port), + done: make(chan error, 1), + } + s.started <- p + return p, nil +} + +// A worker whose /health never answers (the starter URL points at an +// unlistened port) must be stopped and handed to recovery after the liveness +// threshold of consecutive probe failures. This is the watchdog path for a +// worker that stays "alive" as a process but stops serving. +func TestProbeWorkerLivenessRestartsStuckWorker(t *testing.T) { + ctx := context.Background() + dataDir := t.TempDir() + store, err := sqlstore.OpenStore(filepath.Join(dataDir, "qoder.db")) + if err != nil { + t.Fatal(err) + } + defer store.Close() + account, err := store.Create(ctx, accounts.CreateAccount{Name: "stuck", Enabled: true, MaxInFlight: 3}) + if err != nil { + t.Fatal(err) + } + credential := accounts.NativeCredential{UserBlob: []byte("ciphertext"), MachineID: "machine-1"} + if err := store.SaveCredential(ctx, account.ID, "native", credential); err != nil { + t.Fatal(err) + } + starter := &livenessStarter{started: make(chan *livenessProcess, 4)} + manager := NewManager(ManagerConfig{ + DataDir: dataDir, + BasePort: 32500, + RestartDelay: 50 * time.Millisecond, + }, store, starter) + if err := manager.Start(ctx); err != nil { + t.Fatal(err) + } + defer manager.Close() + + var proc *livenessProcess + select { + case proc = <-starter.started: + case <-time.After(2 * time.Second): + t.Fatal("starter was not invoked") + } + + // Threshold consecutive failures must trigger stopAccount. The account's + // /health URL is not serving, so every probe fails on transport. + for i := 1; i <= 3; i++ { + manager.probeWorkerLiveness(ctx) + } + if !proc.stopped { + t.Fatalf("want stuck worker stopped after %d probe failures, got stopped=%v", 3, proc.stopped) + } + // The failure counter is cleared once stop is issued so recovery does not + // inherit a stale count. + manager.mu.Lock() + got := manager.healthFailures[account.ID] + manager.mu.Unlock() + if got != 0 { + t.Fatalf("healthFailures after stop = %d, want 0", got) + } +} + +// A transient failure must not restart the worker: only the threshold-th +// consecutive failure triggers stop. Two failures leave the counter +// incremented and the process running. +func TestProbeWorkerLivenessToleratesTransientFailures(t *testing.T) { + ctx := context.Background() + dataDir := t.TempDir() + store, err := sqlstore.OpenStore(filepath.Join(dataDir, "qoder.db")) + if err != nil { + t.Fatal(err) + } + defer store.Close() + account, err := store.Create(ctx, accounts.CreateAccount{Name: "flaky", Enabled: true, MaxInFlight: 3}) + if err != nil { + t.Fatal(err) + } + credential := accounts.NativeCredential{UserBlob: []byte("ciphertext"), MachineID: "machine-1"} + if err := store.SaveCredential(ctx, account.ID, "native", credential); err != nil { + t.Fatal(err) + } + starter := &livenessStarter{started: make(chan *livenessProcess, 4)} + manager := NewManager(ManagerConfig{ + DataDir: dataDir, + BasePort: 32600, + }, store, starter) + if err := manager.Start(ctx); err != nil { + t.Fatal(err) + } + defer manager.Close() + + var proc *livenessProcess + select { + case proc = <-starter.started: + case <-time.After(2 * time.Second): + t.Fatal("starter was not invoked") + } + + manager.probeWorkerLiveness(ctx) + manager.probeWorkerLiveness(ctx) + if proc.stopped { + t.Fatalf("worker must not be stopped before threshold, got stopped=true") + } + manager.mu.Lock() + got := manager.healthFailures[account.ID] + manager.mu.Unlock() + if got != 2 { + t.Fatalf("healthFailures = %d, want 2", got) + } +} diff --git a/worker/NOTICE b/worker/NOTICE index 91c8ad07..40c22867 100644 --- a/worker/NOTICE +++ b/worker/NOTICE @@ -9,3 +9,15 @@ same paths on different hosts: CN was observed from Qoder CN 0.3.4. Global was observed from the Qoder desktop client on 2026-10-07. The worker reuses the pinned AuthManager and does not copy Qoder's campaign UI. + +Known limitation (verified 2026-10-17): the paths are the same, but the two +regions do NOT expose the daily check-in identically to the worker. CN's campaign +service returns a claimable CLAIM_BENEFIT campaign to the worker's tokens, so +auto check-in works for CN. Global's campaign service (openapi.qoder.sh) returns +only a BOGO subscription promo (VIEW_DETAILS) to the worker's tokens and reserves +the claimable daily check-in for the Qoder desktop client's own session token +(observed `dt-sp…`-prefixed, ~34 chars). The worker's loginWithPAT yields a +`jt-…`-prefixed token (~27 chars) and loginWithDeviceFlow yields a `dt-…`-prefixed +token (~27 chars); neither has the scope to see/claim the Global daily check-in. +Global accounts therefore cannot be auto-checked-in by the worker; leave their +auto_checkin off and rely on the desktop client. diff --git a/worker/src/daemon.mjs b/worker/src/daemon.mjs index 3651fa16..ab4f92ff 100644 --- a/worker/src/daemon.mjs +++ b/worker/src/daemon.mjs @@ -137,6 +137,50 @@ let encodeChain = Promise.resolve(); let inFlight = 0; const maxInFlight = Math.max(1, Number(process.env.QODER_MAX_INFLIGHT || 4) || 4); +// First-byte and total-stream deadlines protect the worker from a stuck +// upstream: Qoder's SSE can hang at the head (TTFB) or stall mid-stream when +// the gateway is degraded. The TTFB timer stops as soon as the response head +// arrives so a long thinking-model body is not cut off; the total timer keeps +// running as a backstop for streams that stall after the first byte. The TTFB +// default mirrors the Go-side firstByteTimeout so worker and gateway agree on +// when a stuck head counts as a failure; both can be tuned per deployment. +const streamTtfbMs = Math.max(5_000, Number(process.env.QODER_STREAM_TTFB_MS || 30_000) || 30_000); +const streamTotalMs = Math.max(streamTtfbMs, Number(process.env.QODER_STREAM_TOTAL_MS || 300_000) || 300_000); + +// fetchWithTimeout wraps fetch with a TTFB + total deadline. The TTFB timer +// fires only if the response head has not arrived; the total timer is the +// hard backstop and aborts either way. On abort the rejection is rewritten so +// callers see a stable error message instead of a bare AbortError. +async function fetchWithTimeout(url, opts = {}, ttfbMs = streamTtfbMs, totalMs = streamTotalMs) { + const controller = new AbortController(); + let headReached = false; + let ttfbFired = false; + const ttfbTimer = setTimeout(() => { + if (headReached) return; + ttfbFired = true; + controller.abort(); + }, ttfbMs); + const totalTimer = setTimeout(() => controller.abort(), totalMs); + try { + const resp = await fetch(url, { ...opts, signal: controller.signal }); + headReached = true; + clearTimeout(ttfbTimer); + // Keep the total timer running: it now serves as the mid-stream stall backstop. + return resp; + } catch (err) { + clearTimeout(ttfbTimer); + clearTimeout(totalTimer); + if (controller.signal.aborted) { + const reason = headReached ? "upstream stream total timeout" : "upstream first-byte timeout"; + const waited = headReached ? totalMs : (ttfbFired ? ttfbMs : totalMs); + const e = new Error(`${reason} after ${waited}ms`); + e.code = headReached ? "stream_total_timeout" : "first_byte_timeout"; + throw e; + } + throw err; + } +} + function sealContext(ctx) { try { @@ -401,7 +445,7 @@ async function prepareUpstream(reqBody) { if (encoded?.headers?.forEach) encoded.headers.forEach((v, k) => (headers[k] = v)); else Object.assign(headers, encoded?.headers || {}); - const upstream = await fetch(encoded.url, { + const upstream = await fetchWithTimeout(encoded.url, { method: "POST", headers, body: encoded.body, From 9b52b51498fb4e0d264ded023c72888c70bac414 Mon Sep 17 00:00:00 2001 From: favo <827982457@qq.com> Date: Mon, 19 Oct 2026 14:59:54 +0800 Subject: [PATCH 2/2] fix(qoder): address review on TTFB failover and watchdog - doWithFirstByteTimeout: stop cancelling the request context once the head arrives; Go ties the response body to that context, so the old defer cancel killed every SSE stream right after headers. Cancel is now bound to Body.Close, and the error path decides first_byte_timeout before cancelling. - Make firstByteTimeout configurable via QODER_STREAM_TTFB_MS (mirrors the worker knob) instead of a hard-coded package var; resolve once at construction. - Watchdog: stopAccount deleted m.processes[id] before Stop(), so watchAccount saw a mismatch and never called beginAccountRecovery, leaving stuck workers permanently dead. restartStuckWorker now detaches, stops, and hands off to beginAccountRecovery directly. - probeHealthOnly: treat ok=true/ready=false as alive (starting/rewarming/login) so warming workers are not rebooted every ~90s; only transport errors or non-2xx/ok=false count as failure. - Worker daemon: replace the 300s wall-clock total cap with a mid-stream stall watchdog that resets on every chunk (long steady thinking streams are no longer truncated); forward the timeout .code so the Go side can classify a mid-stream stall. Extracted to worker/src/upstream.mjs for testing. - Drop the unrelated Global check-in paragraph from worker/NOTICE. - Tests: multi-chunk drain-to-EOF, watchdog restart, warming-worker liveness, and worker fetch TTFB/stall cases. --- changelog/unreleased/worker-stream-timeout.md | 8 +- internal/providers/qoder/adapter.go | 23 ++-- internal/providers/qoder/direct.go | 6 +- .../qoder/first_byte_timeout_test.go | 53 ++++----- internal/providers/qoder/worker.go | 103 ++++++++++++++---- internal/runtime/manager_maintenance.go | 35 ++++-- internal/runtime/manager_probe.go | 11 +- .../runtime/probe_worker_liveness_test.go | 70 +++++++++++- worker/NOTICE | 12 -- worker/src/daemon.mjs | 60 ++-------- worker/src/sse.mjs | 9 +- worker/src/upstream.mjs | 95 ++++++++++++++++ worker/test/upstream.test.mjs | 83 ++++++++++++++ 13 files changed, 431 insertions(+), 137 deletions(-) create mode 100644 worker/src/upstream.mjs create mode 100644 worker/test/upstream.test.mjs diff --git a/changelog/unreleased/worker-stream-timeout.md b/changelog/unreleased/worker-stream-timeout.md index 64022f0c..b09c0207 100644 --- a/changelog/unreleased/worker-stream-timeout.md +++ b/changelog/unreleased/worker-stream-timeout.md @@ -1,11 +1,11 @@ ### English - Stop streaming chat from hanging on a stuck upstream. A Qoder stream request whose first byte never arrives (the symptom was `qwen3.8-flash` requests with only an entry log line and no `chat reasoning resolved`) now fails fast after a 30-second TTFB deadline, classifies as `first_byte_timeout` / `unavailable` with failover, and is retried on the next eligible account instead of hanging the client until it gives up. The deadline is on the response head only — once headers arrive, the SSE body streams under the request's normal lifetime, so long thinking-model output is not cut off. -- Give the worker daemon its own upstream timeout. The worker's `fetch` to the Qoder gateway previously had no `AbortSignal`, so a stalled upstream held the worker's in-flight slot forever. It now aborts on a 30-second first-byte deadline and a 300-second total-stream backstop, returning a stable `first_byte_timeout` / `stream_total_timeout` error so the Go side can classify and fail over. Both are tunable via `QODER_STREAM_TTFB_MS` / `QODER_STREAM_TOTAL_MS`. -- Add a worker liveness watchdog to the maintenance loop. Health probes previously ran only at boot plus on manual console refresh, so a worker that stayed "alive" as a process but stopped serving `/health` was never noticed and kept being routed to. Every 30-second tick now issues one lightweight `/health` round-trip per worker account; three consecutive failures (~90s grace, enough to ride out a transient blip or mid-rewarm) stop the worker and hand it to the existing `watchAccount` + `beginAccountRecovery` path, which reboots it with backoff. In-process accounts (WorkBuddy / Trae / Devin) are skipped and unaffected. +- Give the worker daemon its own upstream timeout. The worker's `fetch` to the Qoder gateway previously had no `AbortSignal`, so a stalled upstream held the worker's in-flight slot forever. It now aborts on a 30-second first-byte deadline, plus a mid-stream stall watchdog that fires only after 300 seconds of silence between chunks (it resets on every chunk, so a long but steady thinking stream is never truncated), returning a stable `first_byte_timeout` / `stream_total_timeout` error so the Go side can classify and fail over. Both are tunable via `QODER_STREAM_TTFB_MS` / `QODER_STREAM_TOTAL_MS`. +- Add a worker liveness watchdog to the maintenance loop. Health probes previously ran only at boot plus on manual console refresh, so a worker that stayed "alive" as a process but stopped serving `/health` was never noticed and kept being routed to. Every 30-second tick now issues one lightweight `/health` round-trip per worker account; three consecutive failures (~90s grace, enough to ride out a transient blip) restart the worker through the existing recovery path with backoff. A worker that answers but is still starting, rewarming, or waiting for login (`ready=false`) is treated as alive, so warming accounts are not rebooted. In-process accounts (WorkBuddy / Trae / Devin) are skipped and unaffected. ### 中文 - 流式 chat 不再因上游卡死而无响应地挂起。Qoder 流式请求如果首字节迟迟不到(现象是 `qwen3.8-flash` 请求只有入口日志、没有 `chat reasoning resolved` 出口日志),现在会在 30 秒 TTFB 阈值后快速失败,归类为 `first_byte_timeout` / `unavailable` 并触发 failover,切到下一个可用账号重试,而不是把客户端挂到自行超时。该超时只针对响应头:一旦头部到达,SSE body 回到请求原本的生命周期,长思考模型的输出不会被截断。 -- 给 worker 守护进程加上自己的上游超时。worker 对 Qoder 网关的 `fetch` 此前没有 `AbortSignal`,上游停滞时会永久占用 worker 的并发槽。现在它在 30 秒首字节超时和 300 秒整体流式兜底任一触发时 abort,返回稳定的 `first_byte_timeout` / `stream_total_timeout` 错误,让 Go 侧分类并 failover。两者均可通过 `QODER_STREAM_TTFB_MS` / `QODER_STREAM_TOTAL_MS` 调整。 -- 给维护循环加 worker liveness 看门狗。健康探针此前只在启动时和手动控制台刷新时跑,所以一个"进程还活着但 `/health` 不再响应"的 worker 永远不会被察觉,还会继续被路由命中。现在每 30 秒维护周期对每个 worker 账号发一次轻量 `/health` 探针;连续 3 次失败(约 90 秒容忍窗口,足以扛过瞬时抖动或 rewarm 中途)就停止该 worker,交给既有的 `watchAccount` + `beginAccountRecovery` 路径按退避重启。进程内账号(WorkBuddy / Trae / Devin)被跳过,不受影响。 +- 给 worker 守护进程加上自己的上游超时。worker 对 Qoder 网关的 `fetch` 此前没有 `AbortSignal`,上游停滞时会永久占用 worker 的并发槽。现在它在 30 秒首字节超时,以及"连续 300 秒没有新数据"的中途停滞看门狗(每收到一个 chunk 就重置,所以长但持续输出的思考流不会被截断)任一触发时 abort,返回稳定的 `first_byte_timeout` / `stream_total_timeout` 错误,让 Go 侧分类并 failover。两者均可通过 `QODER_STREAM_TTFB_MS` / `QODER_STREAM_TOTAL_MS` 调整。 +- 给维护循环加 worker liveness 看门狗。健康探针此前只在启动时和手动控制台刷新时跑,所以一个"进程还活着但 `/health` 不再响应"的 worker 永远不会被察觉,还会继续被路由命中。现在每 30 秒维护周期对每个 worker 账号发一次轻量 `/health` 探针;连续 3 次失败(约 90 秒容忍窗口,足以扛过瞬时抖动)就通过既有的恢复路径按退避重启该 worker。对 `/health` 有响应但仍在启动、rewarm 或等待登录(`ready=false`)的 worker 视为存活,不会误杀。进程内账号(WorkBuddy / Trae / Devin)被跳过,不受影响。 diff --git a/internal/providers/qoder/adapter.go b/internal/providers/qoder/adapter.go index f79f8f2f..3032c480 100644 --- a/internal/providers/qoder/adapter.go +++ b/internal/providers/qoder/adapter.go @@ -35,6 +35,11 @@ type Client struct { loginTimeout time.Duration loginInterval time.Duration + // firstByteTimeout bounds how long the worker-path ChatStream waits for the + // upstream response head before failing over. Resolved from + // QODER_STREAM_TTFB_MS at construction; zero falls back to the default. + firstByteTimeout time.Duration + // direct is the in-process chat path. When set, chat does not enter the // per-account Node worker. Login, catalog, and quota still use that worker. direct *Direct @@ -42,13 +47,14 @@ type Client struct { func NewClient() *Client { return &Client{ - modelsHTTP: &http.Client{Timeout: 15 * time.Second}, - healthHTTP: &http.Client{Timeout: 2 * time.Second}, - quotaHTTP: &http.Client{Timeout: 5 * time.Second}, - adminHTTP: &http.Client{Timeout: 120 * time.Second}, - chatHTTP: &http.Client{Timeout: 120 * time.Second}, - loginTimeout: 90 * time.Second, - loginInterval: 200 * time.Millisecond, + modelsHTTP: &http.Client{Timeout: 15 * time.Second}, + healthHTTP: &http.Client{Timeout: 2 * time.Second}, + quotaHTTP: &http.Client{Timeout: 5 * time.Second}, + adminHTTP: &http.Client{Timeout: 120 * time.Second}, + chatHTTP: &http.Client{Timeout: 120 * time.Second}, + loginTimeout: 90 * time.Second, + loginInterval: 200 * time.Millisecond, + firstByteTimeout: resolveFirstByteTimeout(), } } @@ -537,6 +543,7 @@ func (c *Client) ChatStream(ctx context.Context, accountID string, req translate } c.mu.RLock() httpClient := c.chatHTTP + firstByte := c.firstByteTimeout c.mu.RUnlock() if httpClient == nil { httpClient = http.DefaultClient @@ -546,7 +553,7 @@ func (c *Client) ChatStream(ctx context.Context, accountID string, req translate cloned.Timeout = 0 httpClient = &cloned } - resp, err := doWithFirstByteTimeout(httpClient, httpReq) + resp, err := doWithFirstByteTimeout(httpClient, httpReq, firstByte) if err != nil { return nil, providers.ResolvedChat{}, err } diff --git a/internal/providers/qoder/direct.go b/internal/providers/qoder/direct.go index 8e8d76df..d63251d5 100644 --- a/internal/providers/qoder/direct.go +++ b/internal/providers/qoder/direct.go @@ -24,6 +24,9 @@ type Direct struct { region func(ctx context.Context, accountID string) (string, error) http *http.Client now func() time.Time + // ttfb bounds how long ChatStream waits for the upstream response head. + // Zero falls back to defaultFirstByteTimeout inside doWithFirstByteTimeout. + ttfb time.Duration } func NewDirect(store CredentialStore, region func(context.Context, string) (string, error)) *Direct { @@ -32,6 +35,7 @@ func NewDirect(store CredentialStore, region func(context.Context, string) (stri region: region, http: &http.Client{}, now: time.Now, + ttfb: resolveFirstByteTimeout(), } } @@ -128,7 +132,7 @@ func (d *Direct) ChatStream(ctx context.Context, accountID string, req translate if err != nil { return nil, providers.ResolvedChat{}, err } - resp, err := doWithFirstByteTimeout(d.http, prepared.request) + resp, err := doWithFirstByteTimeout(d.http, prepared.request, d.ttfb) if err != nil { return nil, providers.ResolvedChat{}, err } diff --git a/internal/providers/qoder/first_byte_timeout_test.go b/internal/providers/qoder/first_byte_timeout_test.go index af6f8342..59a996b4 100644 --- a/internal/providers/qoder/first_byte_timeout_test.go +++ b/internal/providers/qoder/first_byte_timeout_test.go @@ -1,10 +1,13 @@ package qoder import ( + "bytes" "context" "errors" + "io" "net/http" "net/http/httptest" + "strings" "testing" "time" @@ -13,13 +16,9 @@ import ( // A stuck upstream that never sends the response head must surface as // ErrFirstByteTimeout so the executor can fail the attempt over instead of -// hanging the client until it gives up. The 60s production deadline is shrunk -// for the test so the assertion runs in milliseconds. +// hanging the client until it gives up. The production deadline is shrunk for +// the test so the assertion runs in milliseconds. func TestDoWithFirstByteTimeoutHangsAsFirstByteTimeout(t *testing.T) { - prev := firstByteTimeout - firstByteTimeout = 50 * time.Millisecond - t.Cleanup(func() { firstByteTimeout = prev }) - // Handler blocks forever: it accepts the body but never writes a response. hung := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { <-r.Context().Done() @@ -31,7 +30,7 @@ func TestDoWithFirstByteTimeoutHangsAsFirstByteTimeout(t *testing.T) { t.Fatalf("NewRequest: %v", err) } client := &http.Client{Timeout: 0} // mimic streaming client: no whole-call timeout - _, err = doWithFirstByteTimeout(client, req) + _, err = doWithFirstByteTimeout(client, req, 50*time.Millisecond) if !errors.Is(err, providers.ErrFirstByteTimeout) { t.Fatalf("want ErrFirstByteTimeout, got %v", err) } @@ -41,10 +40,6 @@ func TestDoWithFirstByteTimeoutHangsAsFirstByteTimeout(t *testing.T) { // plain transport error instead of masking it as a first-byte timeout; the // executor classifies client cancels as KindCanceled (no failover, no cooldown). func TestDoWithFirstByteTimeoutParentCancelIsNotFirstByteTimeout(t *testing.T) { - prev := firstByteTimeout - firstByteTimeout = 50 * time.Millisecond - t.Cleanup(func() { firstByteTimeout = prev }) - hung := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { <-r.Context().Done() })) @@ -59,7 +54,7 @@ func TestDoWithFirstByteTimeoutParentCancelIsNotFirstByteTimeout(t *testing.T) { // Cancel before the call so parent.Err() is non-nil at the point of failure. cancel() - _, err = doWithFirstByteTimeout(client, req) + _, err = doWithFirstByteTimeout(client, req, 50*time.Millisecond) if errors.Is(err, providers.ErrFirstByteTimeout) { t.Fatalf("parent-cancelled call must not surface as ErrFirstByteTimeout, got %v", err) } @@ -69,23 +64,23 @@ func TestDoWithFirstByteTimeoutParentCancelIsNotFirstByteTimeout(t *testing.T) { } // A well-behaved upstream that returns a response head quickly must not be -// cut off by the TTFB timer, and the body must stay readable afterwards. -func TestDoWithFirstByteTimeoutFastHeadReturnsBody(t *testing.T) { - prev := firstByteTimeout - firstByteTimeout = 5 * time.Second - t.Cleanup(func() { firstByteTimeout = prev }) - +// cut off by the TTFB timer, and the whole multi-chunk body must stay readable +// to EOF afterwards. This drains every chunk rather than doing a single buffered +// Read: a cancel-on-return bug only shows up once the stream continues past the +// first read, which is exactly the "dies right after headers" symptom. +func TestDoWithFirstByteTimeoutStreamsBodyToEOF(t *testing.T) { + const chunks = 4 ok := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.Header().Set("content-type", "text/event-stream") w.WriteHeader(http.StatusOK) - // Slow trickle SSE chunks to prove the body is readable past the TTFB - // timer being stopped. flusher, _ := w.(http.Flusher) - for i := 0; i < 3; i++ { + for i := 0; i < chunks; i++ { _, _ = w.Write([]byte("data: chunk\n\n")) if flusher != nil { flusher.Flush() } + // Space the chunks out so the first-byte deadline would fire if the + // timer were not stopped and the context were cancelled on return. time.Sleep(20 * time.Millisecond) } })) @@ -96,14 +91,20 @@ func TestDoWithFirstByteTimeoutFastHeadReturnsBody(t *testing.T) { t.Fatalf("NewRequest: %v", err) } client := &http.Client{Timeout: 0} - resp, err := doWithFirstByteTimeout(client, req) + // Short TTFB deadline: the head arrives immediately, so a correct + // implementation stops the timer and never cancels the body. + resp, err := doWithFirstByteTimeout(client, req, 50*time.Millisecond) if err != nil { t.Fatalf("want nil err for fast head, got %v", err) } defer resp.Body.Close() - buf := make([]byte, 1024) - n, err := resp.Body.Read(buf) - if err != nil || n == 0 { - t.Fatalf("body read after TTFB timer stop: n=%d err=%v", n, err) + + var got bytes.Buffer + if _, err := io.Copy(&got, resp.Body); err != nil { + t.Fatalf("drain body to EOF: %v (read %q)", err, got.String()) + } + want := strings.Repeat("data: chunk\n\n", chunks) + if got.String() != want { + t.Fatalf("body = %q, want %q", got.String(), want) } } diff --git a/internal/providers/qoder/worker.go b/internal/providers/qoder/worker.go index 12fa79ac..903555ad 100644 --- a/internal/providers/qoder/worker.go +++ b/internal/providers/qoder/worker.go @@ -8,6 +8,8 @@ import ( "fmt" "io" "net/http" + "os" + "strconv" "strings" "time" @@ -50,40 +52,101 @@ func (e TransportError) Error() string { func (e TransportError) Unwrap() error { return e.Err } -// firstByteTimeout caps how long a streaming chat request will wait for the -// upstream response head (status + headers). Once the head arrives, the timer -// is stopped and the SSE body streams under the parent context's lifetime, so -// long thinking-model output is not cut off. A stuck upstream that never sends -// a first byte surfaces as ErrFirstByteTimeout so the executor can fail over to -// the next account instead of hanging forever. 30s covers slow cold-starts -// and thinking-model first-token latency while keeping a stuck-upstream failover -// inside one round-trip of the client's patience. -var firstByteTimeout = 30 * time.Second +// defaultFirstByteTimeout caps how long a streaming chat request will wait for +// the upstream response head (status + headers). Once the head arrives, the +// timer is stopped and the SSE body streams under the parent context's lifetime, +// so long thinking-model output is not cut off. A stuck upstream that never +// sends a first byte surfaces as ErrFirstByteTimeout so the executor can fail +// over to the next account instead of hanging forever. 30s covers slow +// cold-starts and thinking-model first-token latency while keeping a +// stuck-upstream failover inside one round-trip of the client's patience. +// +// The effective value is resolved once at construction (see +// resolveFirstByteTimeout) and can be tuned per deployment with +// QODER_STREAM_TTFB_MS, mirroring the worker daemon's own knob. +const defaultFirstByteTimeout = 30 * time.Second + +// resolveFirstByteTimeout reads QODER_STREAM_TTFB_MS, falling back to +// defaultFirstByteTimeout for an absent or invalid value. The floor matches the +// worker daemon's so the two deadlines cannot be configured to disagree wildly. +func resolveFirstByteTimeout() time.Duration { + raw := strings.TrimSpace(os.Getenv("QODER_STREAM_TTFB_MS")) + if raw == "" { + return defaultFirstByteTimeout + } + ms, err := strconv.Atoi(raw) + if err != nil || ms <= 0 { + return defaultFirstByteTimeout + } + d := time.Duration(ms) * time.Millisecond + if d < 5*time.Second { + return 5 * time.Second + } + return d +} // doWithFirstByteTimeout sends req with client, returning a response once the -// response head is received. If the head does not arrive within -// firstByteTimeout it returns an error wrapping providers.ErrFirstByteTimeout; -// if the parent context was already cancelled it surfaces that error unchanged -// so the executor classifies it as a client cancellation rather than a timeout. -func doWithFirstByteTimeout(client *http.Client, req *http.Request) (*http.Response, error) { +// response head is received. If the head does not arrive within timeout it +// returns an error wrapping providers.ErrFirstByteTimeout; if the parent +// context was already cancelled it surfaces that error unchanged so the +// executor classifies it as a client cancellation rather than a timeout. +// +// The TTFB context must NOT be cancelled once the head arrives: Go's HTTP +// client ties the response body to the request context, so cancelling would +// kill the body mid-stream (the SSE read then fails with "context canceled" +// after the head was already delivered). Only the error path cancels; on +// success the deadline goroutine is stopped and the body lives under the +// parent context, with the response body's Close as the eventual release. +func doWithFirstByteTimeout(client *http.Client, req *http.Request, timeout time.Duration) (*http.Response, error) { + if timeout <= 0 { + timeout = defaultFirstByteTimeout + } parent := req.Context() ttfbCtx, cancelTTFB := context.WithCancel(parent) - defer cancelTTFB() - timer := time.AfterFunc(firstByteTimeout, cancelTTFB) - defer timer.Stop() + timer := time.AfterFunc(timeout, cancelTTFB) resp, err := client.Do(req.WithContext(ttfbCtx)) if err == nil { + // Head arrived: stop the timer but keep ttfbCtx alive so the body + // remains readable. Tie the cancel to Body.Close so the derived context + // is released exactly when the caller is done with the stream, while + // the parent context still governs its lifetime (client disconnect / + // shutdown). Cancelling here instead would kill the body mid-stream. + timer.Stop() + resp.Body = &cancelOnCloseBody{ReadCloser: resp.Body, cancel: cancelTTFB} return resp, nil } + timer.Stop() // TTFB fired only when the parent context is still alive: a parent cancel // (client disconnect, shutdown) must stay a plain cancel so the executor - // does not treat it as an upstream failure worth cooling down. - if parent.Err() == nil && ttfbCtx.Err() != nil && !errors.Is(parent.Err(), context.Canceled) { - return nil, fmt.Errorf("%w: no response head within %s", providers.ErrFirstByteTimeout, firstByteTimeout) + // does not treat it as an upstream failure worth cooling down. Decide this + // before cancelTTFB below, which would otherwise make ttfbCtx.Err() non-nil + // regardless of the real cause. + timedOut := parent.Err() == nil && ttfbCtx.Err() != nil && !errors.Is(parent.Err(), context.Canceled) + cancelTTFB() + if timedOut { + return nil, fmt.Errorf("%w: no response head within %s", providers.ErrFirstByteTimeout, timeout) } return nil, TransportError{Err: err} } +// cancelOnCloseBody releases the TTFB-derived context when the caller closes +// the response body. The body itself is tied to that context by Go's HTTP +// client, so cancelling earlier would truncate the stream; cancelling on Close +// frees the timer goroutine's context exactly when the stream is finished. +type cancelOnCloseBody struct { + io.ReadCloser + cancel context.CancelFunc +} + +func (b *cancelOnCloseBody) Close() error { + err := b.ReadCloser.Close() + if b.cancel != nil { + b.cancel() + b.cancel = nil + } + return err +} + type HTTPStatusError struct { Op string Status int diff --git a/internal/runtime/manager_maintenance.go b/internal/runtime/manager_maintenance.go index 0c11b6c1..00f650fc 100644 --- a/internal/runtime/manager_maintenance.go +++ b/internal/runtime/manager_maintenance.go @@ -529,18 +529,37 @@ func (manager *Manager) probeWorkerLiveness(ctx context.Context) { fails := manager.healthFailures[item.ID] manager.mu.Unlock() if fails >= workerLivenessThreshold { - log.Printf("worker liveness: account %s failed %d consecutive health probes (%v); stopping for recovery", + log.Printf("worker liveness: account %s failed %d consecutive health probes (%v); restarting", item.ID, fails, err) manager.mu.Lock() delete(manager.healthFailures, item.ID) manager.mu.Unlock() - // stopAccount kills the child process; watchAccount sees the exit - // via process.Done() and calls beginAccountRecovery, which owns the - // backoff restart. No direct recovery call here — that would race - // the recovering guard. - if perr := manager.stopAccount(item.ID); perr != nil { - log.Printf("worker liveness: stop %s failed: %v", item.ID, perr) - } + manager.restartStuckWorker(item.ID, err) + } + } +} + +// restartStuckWorker reboots a worker whose /health stopped answering. It must +// not simply call stopAccount: stopAccount deletes m.processes[id] before +// Stop(), so watchAccount later sees a process mismatch and returns without +// calling beginAccountRecovery — the stuck worker would become a permanently +// dead account. Instead detach the process from the table (so watchAccount +// cannot also recover it), stop it, then hand it to beginAccountRecovery +// directly, which owns the backoff restart. +func (manager *Manager) restartStuckWorker(id string, probeErr error) { + manager.mu.Lock() + process := manager.processes[id] + delete(manager.processes, id) + manager.mu.Unlock() + manager.pool.Remove(id) + if process != nil { + if perr := process.Stop(); perr != nil { + log.Printf("worker liveness: stop %s failed: %v", id, perr) } } + reason := "worker liveness probe failed" + if probeErr != nil { + reason = "worker liveness probe failed: " + probeErr.Error() + } + manager.beginAccountRecovery(id, errors.New(reason)) } diff --git a/internal/runtime/manager_probe.go b/internal/runtime/manager_probe.go index 3a307c76..85778703 100644 --- a/internal/runtime/manager_probe.go +++ b/internal/runtime/manager_probe.go @@ -154,7 +154,14 @@ func (m *Manager) forceReady(accountID string) bool { // unlike refreshOne, it does not fetch quota or refresh the model catalog, so a // 30s-loop call costs one HTTP round-trip, not a quota probe. The pool state // machine is left to refreshOne and the manual console refresh path; this only -// decides whether the worker is still alive enough to route to. +// decides whether the worker process is still alive enough to serve at all. +// +// "Alive" is deliberately loose: a transport error or a non-2xx / non-ok status +// means the process is wedged or gone and worth rebooting, but a 200 with +// ready=false is NOT a failure. A worker that is still starting, rewarming, or +// waiting for login answers /health with ok=true, ready=false — killing it after +// ~90s would loop a healthy-but-warming account. readiness stays refreshOne's +// job; only the daemon being unreachable or unhealthy counts here. // // In-process accounts (WorkBuddy / Trae / Devin) have no child-process /health // endpoint and never need this check — their liveness is the adapter's own @@ -174,5 +181,5 @@ func (m *Manager) probeHealthOnly(ctx context.Context, item Item) (bool, error) if statusCode >= 300 || !health.OK { return false, nil } - return health.Ready, nil + return true, nil } diff --git a/internal/runtime/probe_worker_liveness_test.go b/internal/runtime/probe_worker_liveness_test.go index f5cfa417..85694932 100644 --- a/internal/runtime/probe_worker_liveness_test.go +++ b/internal/runtime/probe_worker_liveness_test.go @@ -2,6 +2,8 @@ package runtime import ( "context" + "net/http" + "net/http/httptest" "path/filepath" "strconv" "testing" @@ -46,9 +48,10 @@ func (s *livenessStarter) Start(_ context.Context, _ accounts.Account, _ string, } // A worker whose /health never answers (the starter URL points at an -// unlistened port) must be stopped and handed to recovery after the liveness +// unlistened port) must be stopped AND handed to recovery after the liveness // threshold of consecutive probe failures. This is the watchdog path for a -// worker that stays "alive" as a process but stops serving. +// worker that stays "alive" as a process but stops serving; recovery must +// spawn a replacement process, otherwise the stuck account is permanently dead. func TestProbeWorkerLivenessRestartsStuckWorker(t *testing.T) { ctx := context.Background() dataDir := t.TempDir() @@ -91,14 +94,25 @@ func TestProbeWorkerLivenessRestartsStuckWorker(t *testing.T) { if !proc.stopped { t.Fatalf("want stuck worker stopped after %d probe failures, got stopped=%v", 3, proc.stopped) } - // The failure counter is cleared once stop is issued so recovery does not - // inherit a stale count. + // The failure counter is cleared once a restart is issued so recovery does + // not inherit a stale count. manager.mu.Lock() got := manager.healthFailures[account.ID] manager.mu.Unlock() if got != 0 { t.Fatalf("healthFailures after stop = %d, want 0", got) } + // Recovery must actually start a replacement process: the old bug deleted + // m.processes[id] before Stop(), so watchAccount saw a mismatch and returned + // without beginAccountRecovery, leaving the account permanently dead. + select { + case replacement := <-starter.started: + if replacement == proc { + t.Fatalf("recovery reused the stuck process instead of starting a new one") + } + case <-time.After(2 * time.Second): + t.Fatal("watchdog stopped the stuck worker but never restarted it") + } } // A transient failure must not restart the worker: only the threshold-th @@ -149,3 +163,51 @@ func TestProbeWorkerLivenessToleratesTransientFailures(t *testing.T) { t.Fatalf("healthFailures = %d, want 2", got) } } + +// A worker that answers /health with ok=true but ready=false is still alive: +// it is starting, rewarming, or waiting for login. The liveness probe must not +// treat that as a failure, or the watchdog would reboot a healthy-but-warming +// account every ~90s. +func TestProbeHealthOnlyTreatsWarmingWorkerAsAlive(t *testing.T) { + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("content-type", "application/json") + _, _ = w.Write([]byte(`{"ok":true,"ready":false,"hot":false,"hasAuthManager":true}`)) + })) + t.Cleanup(srv.Close) + + manager := NewManager(ManagerConfig{DataDir: t.TempDir()}, nil, nil) + alive, err := manager.probeHealthOnly(context.Background(), Item{ + ID: "warming", + Runtime: "child_process", + URL: srv.URL, + }) + if err != nil { + t.Fatalf("probeHealthOnly: %v", err) + } + if !alive { + t.Fatalf("warming worker (ok=true, ready=false) must be treated as alive") + } +} + +// A 200 that reports ok=false is an unhealthy daemon and must count as a +// failure so it can be rebooted. +func TestProbeHealthOnlyTreatsUnhealthyAsDead(t *testing.T) { + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("content-type", "application/json") + _, _ = w.Write([]byte(`{"ok":false,"ready":false}`)) + })) + t.Cleanup(srv.Close) + + manager := NewManager(ManagerConfig{DataDir: t.TempDir()}, nil, nil) + alive, err := manager.probeHealthOnly(context.Background(), Item{ + ID: "unhealthy", + Runtime: "child_process", + URL: srv.URL, + }) + if err != nil { + t.Fatalf("probeHealthOnly: %v", err) + } + if alive { + t.Fatalf("ok=false daemon must be treated as dead") + } +} diff --git a/worker/NOTICE b/worker/NOTICE index 40c22867..91c8ad07 100644 --- a/worker/NOTICE +++ b/worker/NOTICE @@ -9,15 +9,3 @@ same paths on different hosts: CN was observed from Qoder CN 0.3.4. Global was observed from the Qoder desktop client on 2026-10-07. The worker reuses the pinned AuthManager and does not copy Qoder's campaign UI. - -Known limitation (verified 2026-10-17): the paths are the same, but the two -regions do NOT expose the daily check-in identically to the worker. CN's campaign -service returns a claimable CLAIM_BENEFIT campaign to the worker's tokens, so -auto check-in works for CN. Global's campaign service (openapi.qoder.sh) returns -only a BOGO subscription promo (VIEW_DETAILS) to the worker's tokens and reserves -the claimable daily check-in for the Qoder desktop client's own session token -(observed `dt-sp…`-prefixed, ~34 chars). The worker's loginWithPAT yields a -`jt-…`-prefixed token (~27 chars) and loginWithDeviceFlow yields a `dt-…`-prefixed -token (~27 chars); neither has the scope to see/claim the Global daily check-in. -Global accounts therefore cannot be auto-checked-in by the worker; leave their -auto_checkin off and rely on the desktop client. diff --git a/worker/src/daemon.mjs b/worker/src/daemon.mjs index ab4f92ff..92c082b5 100644 --- a/worker/src/daemon.mjs +++ b/worker/src/daemon.mjs @@ -11,6 +11,7 @@ import { inspectQodercliSource, NEEDLES, PINNED_QODERCLI_VERSION, readQodercliVe import { resolveUsage } from "./usage.mjs"; import { classifyError } from "./errors.mjs"; import { createQoderCheckin } from "./checkin.mjs"; +import { fetchWithTimeout, streamStallMs } from "./upstream.mjs"; const __dirname = path.dirname(fileURLToPath(import.meta.url)); register(pathToFileURL(path.join(__dirname, "rewrite-loader.mjs")).href); @@ -137,51 +138,6 @@ let encodeChain = Promise.resolve(); let inFlight = 0; const maxInFlight = Math.max(1, Number(process.env.QODER_MAX_INFLIGHT || 4) || 4); -// First-byte and total-stream deadlines protect the worker from a stuck -// upstream: Qoder's SSE can hang at the head (TTFB) or stall mid-stream when -// the gateway is degraded. The TTFB timer stops as soon as the response head -// arrives so a long thinking-model body is not cut off; the total timer keeps -// running as a backstop for streams that stall after the first byte. The TTFB -// default mirrors the Go-side firstByteTimeout so worker and gateway agree on -// when a stuck head counts as a failure; both can be tuned per deployment. -const streamTtfbMs = Math.max(5_000, Number(process.env.QODER_STREAM_TTFB_MS || 30_000) || 30_000); -const streamTotalMs = Math.max(streamTtfbMs, Number(process.env.QODER_STREAM_TOTAL_MS || 300_000) || 300_000); - -// fetchWithTimeout wraps fetch with a TTFB + total deadline. The TTFB timer -// fires only if the response head has not arrived; the total timer is the -// hard backstop and aborts either way. On abort the rejection is rewritten so -// callers see a stable error message instead of a bare AbortError. -async function fetchWithTimeout(url, opts = {}, ttfbMs = streamTtfbMs, totalMs = streamTotalMs) { - const controller = new AbortController(); - let headReached = false; - let ttfbFired = false; - const ttfbTimer = setTimeout(() => { - if (headReached) return; - ttfbFired = true; - controller.abort(); - }, ttfbMs); - const totalTimer = setTimeout(() => controller.abort(), totalMs); - try { - const resp = await fetch(url, { ...opts, signal: controller.signal }); - headReached = true; - clearTimeout(ttfbTimer); - // Keep the total timer running: it now serves as the mid-stream stall backstop. - return resp; - } catch (err) { - clearTimeout(ttfbTimer); - clearTimeout(totalTimer); - if (controller.signal.aborted) { - const reason = headReached ? "upstream stream total timeout" : "upstream first-byte timeout"; - const waited = headReached ? totalMs : (ttfbFired ? ttfbMs : totalMs); - const e = new Error(`${reason} after ${waited}ms`); - e.code = headReached ? "stream_total_timeout" : "first_byte_timeout"; - throw e; - } - throw err; - } -} - - function sealContext(ctx) { try { ctx.free = function () { @@ -445,11 +401,15 @@ async function prepareUpstream(reqBody) { if (encoded?.headers?.forEach) encoded.headers.forEach((v, k) => (headers[k] = v)); else Object.assign(headers, encoded?.headers || {}); - const upstream = await fetchWithTimeout(encoded.url, { - method: "POST", - headers, - body: encoded.body, - }); + const upstream = await fetchWithTimeout( + encoded.url, + { + method: "POST", + headers, + body: encoded.body, + }, + { stallMs: streamStallMs }, + ); return { plain, upstream }; } diff --git a/worker/src/sse.mjs b/worker/src/sse.mjs index aa686dd1..d409196d 100644 --- a/worker/src/sse.mjs +++ b/worker/src/sse.mjs @@ -293,6 +293,11 @@ export async function pipeNestedSseToOpenAI(upstreamRes, res, { model = "auto", readResult = await reader.read(); } catch (err) { const detail = err?.message || String(err); + // Preserve a timeout code from the fetch wrapper (first_byte_timeout / + // stream_total_timeout) so a mid-stream stall is reported as a retryable + // upstream timeout, not a generic interrupt. The message still carries + // the original detail for diagnostics. + const code = err?.code || "upstream_stream_interrupted"; emitDiagnostic("read_error"); console.error("[sse] upstream stream read failed", { model, @@ -304,14 +309,14 @@ export async function pipeNestedSseToOpenAI(upstreamRes, res, { model = "auto", error: detail, }); writeStructuredStreamError(res, { - code: "upstream_stream_interrupted", + code, type: "api_error", kind: "unavailable", status: 502, failover: true, message: detail, }); - throw new Error(`upstream_stream_interrupted: ${detail}`); + throw new Error(`${code}: ${detail}`); } const { value, done } = readResult; let chunkText; diff --git a/worker/src/upstream.mjs b/worker/src/upstream.mjs new file mode 100644 index 00000000..3ff042b5 --- /dev/null +++ b/worker/src/upstream.mjs @@ -0,0 +1,95 @@ +// Upstream fetch with a first-byte deadline and a mid-stream stall watchdog. +// Extracted from daemon.mjs so it can be unit-tested without booting the CLI. + +// First-byte and mid-stream stall deadlines protect the worker from a stuck +// upstream: Qoder's SSE can hang at the head (TTFB) or stop sending data +// mid-stream when the gateway is degraded. The TTFB timer stops as soon as the +// response head arrives. The stall watchdog is NOT a wall-clock cap: it resets +// every time a chunk arrives, so a long thinking-model stream that keeps +// producing output is never truncated — only a stream that goes silent for the +// whole window is aborted. The TTFB default mirrors the Go-side first-byte +// deadline so worker and gateway agree on when a stuck head counts as a +// failure; both are tunable per deployment. +export const streamTtfbMs = Math.max(5_000, Number(process.env.QODER_STREAM_TTFB_MS || 30_000) || 30_000); +export const streamStallMs = Math.max(streamTtfbMs, Number(process.env.QODER_STREAM_TOTAL_MS || 300_000) || 300_000); + +// fetchWithTimeout wraps fetch with a TTFB deadline on the response head and +// (optionally) a mid-stream stall watchdog on the body. The TTFB timer fires +// only if the head has not arrived; once it does, the timer is cleared. The +// stall watchdog is attached to the body and only fires when no chunk has +// arrived for stallMs. When a deadline fires the rejection carries a stable +// `.code` (first_byte_timeout / stream_total_timeout) that the callers forward +// so the Go side can classify and fail over instead of seeing a bare abort. +export async function fetchWithTimeout(url, opts = {}, { ttfbMs = streamTtfbMs, stallMs = 0 } = {}) { + const controller = new AbortController(); + const abortWith = (code, message) => { + const err = new Error(message); + err.code = code; + controller.abort(err); + }; + const ttfbTimer = setTimeout(() => { + abortWith("first_byte_timeout", `upstream first-byte timeout after ${ttfbMs}ms`); + }, ttfbMs); + let resp; + try { + resp = await fetch(url, { ...opts, signal: controller.signal }); + } catch (err) { + clearTimeout(ttfbTimer); + // err carries .code when our own timer aborted; rethrow unchanged. + throw err; + } + clearTimeout(ttfbTimer); + if (stallMs > 0 && resp.body) attachStallWatchdog(resp, controller, stallMs); + return resp; +} + +// attachStallWatchdog replaces resp.body with a wrapper that arms a timer on +// each chunk and aborts the request when the stream goes silent for stallMs. +// The timer is cleared when the body ends, errors, or is cancelled, so it never +// outlives the request. Aborting the controller mid-stream makes the reader +// reject with the abort reason (code=stream_total_timeout), which the SSE pipe +// turns into a structured error event rather than a silent truncation. +export function attachStallWatchdog(resp, controller, stallMs) { + const original = resp.body; + if (!original) return; + const reader = original.getReader(); + let timer = null; + const disarm = () => { + if (timer) { + clearTimeout(timer); + timer = null; + } + }; + const arm = () => { + disarm(); + timer = setTimeout(() => { + const err = new Error(`upstream stream stalled for ${stallMs}ms`); + err.code = "stream_total_timeout"; + controller.abort(err); + }, stallMs); + if (typeof timer.unref === "function") timer.unref(); + }; + arm(); + const wrapped = new ReadableStream({ + async pull(ctrl) { + try { + const { done, value } = await reader.read(); + if (done) { + disarm(); + ctrl.close(); + return; + } + arm(); + ctrl.enqueue(value); + } catch (err) { + disarm(); + ctrl.error(err); + } + }, + cancel(reason) { + disarm(); + return reader.cancel(reason); + }, + }); + Object.defineProperty(resp, "body", { value: wrapped, configurable: true }); +} diff --git a/worker/test/upstream.test.mjs b/worker/test/upstream.test.mjs new file mode 100644 index 00000000..250c1d68 --- /dev/null +++ b/worker/test/upstream.test.mjs @@ -0,0 +1,83 @@ +import assert from "node:assert/strict"; +import http from "node:http"; +import { test } from "node:test"; +import { fetchWithTimeout } from "../src/upstream.mjs"; + +function listen(handler) { + return new Promise((resolve) => { + const server = http.createServer(handler); + server.listen(0, "127.0.0.1", () => resolve(server)); + }); +} + +function close(server) { + return new Promise((resolve) => server.close(resolve)); +} + +// A head that never arrives must reject with first_byte_timeout so the Go side +// can fail over instead of the worker holding its in-flight slot forever. +test("first-byte deadline aborts a stuck head", async () => { + const server = await listen(() => { + /* accept the request, never respond */ + }); + try { + const port = server.address().port; + await assert.rejects( + fetchWithTimeout(`http://127.0.0.1:${port}`, { method: "POST" }, { ttfbMs: 50 }), + (err) => err.code === "first_byte_timeout", + ); + } finally { + await close(server); + } +}); + +// A steady stream that keeps producing chunks must NOT be cut off, even when it +// runs longer than the stall window: the watchdog resets on every chunk. +test("stall watchdog does not truncate a steady stream", async () => { + const server = await listen((req, res) => { + res.writeHead(200, { "content-type": "text/event-stream" }); + let i = 0; + const timer = setInterval(() => { + res.write(`data: chunk-${i++}\n\n`); + if (i >= 8) { + clearInterval(timer); + res.end(); + } + }, 20); + }); + try { + const port = server.address().port; + const resp = await fetchWithTimeout(`http://127.0.0.1:${port}`, {}, { ttfbMs: 500, stallMs: 100 }); + const reader = resp.body.getReader(); + let chunks = 0; + while (true) { + const { done } = await reader.read(); + if (done) break; + chunks += 1; + } + // 8 interval writes over ~160ms with a 100ms stall window: a wall-clock cap + // would have aborted it; a per-chunk reset lets it finish. + assert.ok(chunks >= 1, `expected streamed chunks, got ${chunks}`); + } finally { + await close(server); + } +}); + +// A stream that goes silent mid-body must reject with stream_total_timeout so a +// truncated upstream surfaces as a retryable timeout instead of a silent end. +test("stall watchdog aborts a silent mid-stream", async () => { + const server = await listen((req, res) => { + res.writeHead(200, { "content-type": "text/event-stream" }); + res.write("data: one\n\n"); + // then go silent forever + }); + try { + const port = server.address().port; + const resp = await fetchWithTimeout(`http://127.0.0.1:${port}`, {}, { ttfbMs: 500, stallMs: 100 }); + const reader = resp.body.getReader(); + await reader.read(); // first chunk arrives + await assert.rejects(reader.read(), (err) => err.code === "stream_total_timeout"); + } finally { + await close(server); + } +});