diff --git a/limits.go b/limits.go index 2bff4c7..408ebd6 100644 --- a/limits.go +++ b/limits.go @@ -2,6 +2,7 @@ package traefikllmgateway import ( "context" + "errors" "fmt" "math" "net/http" @@ -503,9 +504,13 @@ type limiter struct { // time-to-first-byte path (a synchronous storeIncrMulti round trip // there would delay every first chunk by however long that write // takes). newLimiter always wires a production limiter's spawn to a - // real `go f()`; a test that needs recordProviderAttempt's write to - // have already landed by the time it reads a counter back overrides - // spawn to run f synchronously instead — the same dependency- + // BOUNDED goroutine — see spawnTokens below (FOLDED-1, v0.22 review + // round, round 2): unbounded `go f()` could pile up an unlimited + // number of in-flight writes against a slow-but-alive Redis, since + // nothing here backpressures request volume. A test that needs + // recordProviderAttempt's write to have already landed by the time it + // reads a counter back overrides spawn to run f synchronously + // instead, bypassing spawnTokens entirely — the same dependency- // injection idiom nowFn already uses on this struct, and waitFn uses // on retryPolicy (retry.go). A goroutine spawned this way outlives // the request that triggered it by design: a write still in flight at @@ -514,6 +519,24 @@ type limiter struct { // writes to are inherently approximate already (a counter reset at a // bucket boundary loses whatever was in the previous bucket too). spawn func(func()) + // spawnTokens is the buffered-channel semaphore the production spawn + // closure (newLimiter) acquires from non-blockingly before starting a + // goroutine, and releases when that goroutine finishes — FOLDED-1 + // (v0.22 review round, round 2): capped at providerAttemptSpawnCap + // in-flight writes per limiter. Acquiring a token that is not + // immediately available means the write is DROPPED, never queued or + // blocked — bounded AND lossy-under-pressure, by design: this is a + // telemetry counter family (recordProviderAttempt), not enforcement + // (checkAndCount/account never go through spawn at all), so losing an + // occasional attempt/failure increment under sustained store pressure + // is an accepted trade-off against the alternative, an unbounded + // goroutine pile-up that could itself become the outage. Per-limiter, + // not a package-level channel: this codebase's own test suite + // constructs many independent *limiter values in one process + // (including in parallel, via t.Parallel()), and a shared global + // semaphore would let one test's write volume starve an unrelated + // test's — see newLimiter's own construction of it. + spawnTokens chan struct{} // lastErrMsg is the message of the most recent store operation // failure, guarded by logMu alongside lastStoreFailure. It is never // cleared on a later success — "last store error" for the admin @@ -525,6 +548,16 @@ type limiter struct { failOpen bool // store-error policy: true falls back to fallback, false refuses the request } +// providerAttemptSpawnCap bounds how many concurrent recordProviderAttempt +// store writes one limiter's production spawn implementation will run at +// once (FOLDED-1, v0.22 review round, round 2) — see limiter.spawnTokens' +// own doc comment for the full rationale. 64 is generous headroom for +// this telemetry path specifically (every real deployment's traffic +// volume is expected to sit well under it in steady state) while still +// bounding the worst case against a store that has gone slow but not +// down. +const providerAttemptSpawnCap = 64 + // newLimiter returns a limiter. A nil store means every operation uses the // limiter's own in-process fallback memoryStore — the plugin still // enforces limits with no distributed backend configured, just without @@ -533,14 +566,27 @@ type limiter struct { // memoryStore for that operation, false refuses the request (see // storeIncrBy / storeGet). func newLimiter(store counterStore, failOpen bool) *limiter { - return &limiter{ - store: store, - fallback: newMemoryStore(), - nowFn: time.Now, - logf: func(string, ...any) {}, - failOpen: failOpen, - spawn: func(f func()) { go f() }, + l := &limiter{ + store: store, + fallback: newMemoryStore(), + nowFn: time.Now, + logf: func(string, ...any) {}, + failOpen: failOpen, + spawnTokens: make(chan struct{}, providerAttemptSpawnCap), } + l.spawn = func(f func()) { + select { + case l.spawnTokens <- struct{}{}: + go func() { + defer func() { <-l.spawnTokens }() + f() + }() + default: + // Dropped: spawnTokens is full — bounded, lossy-under-pressure + // by design (FOLDED-1, its own doc comment above). + } + } + return l } // now returns the limiter's current time, via nowFn. @@ -1204,43 +1250,50 @@ func providerModelScopeID(provider, model string) string { return provider + "/" + model } -// sentinelUnwrapper is the errors.Unwrap interface, matched bare (a comma-ok -// type assertion, never errors.Is/errors.As) — see matchesSentinel's own -// doc comment for why. -type sentinelUnwrapper interface { - Unwrap() error -} - -// matchesSentinel reports whether err IS, or wraps, sentinel — the exact -// semantics errors.Is applies for a plain sentinel comparison (neither -// context.DeadlineExceeded nor context.Canceled defines an Is(error) -// method, so there is no behavioral difference to preserve), implemented -// by hand-walking err's Unwrap chain instead of calling errors.Is itself. +// matchesSentinel reports whether err IS, or wraps (through any +// combination of single-%w and multi-%w Unwrap chains), sentinel — +// implemented with a real errors.Is call, NOT a hand-rolled Unwrap walk. // -// This is deliberate, not a style preference: providerHTTPError's own doc -// comment (providers.go) already documents that errors.As panics under -// Yaegi when checking whether an interpreted pointer type implements -// error, which is why handleAdapterError uses a bare type assertion -// instead. errors.Is walks the identical reflect-based machinery -// internally (both live in package errors and share its Is/As helper -// code) and carries the same risk — recordProviderAttempt is exercised -// under Yaegi too (tools/yaegi-check's harness drives a real chat -// completion through it), so this sidesteps the trap entirely: a bare -// `err.(sentinelUnwrapper)` comma-ok assertion is plain interface -// satisfaction, never reflection over a possibly-interpreted concrete -// type. +// This function used to hand-roll that walk instead, via two locally +// declared interfaces (single-error Unwrap() error, multi-error +// Unwrap() []error) matched with bare comma-ok type assertions — the +// documented-safe pattern providerHTTPError's own doc comment +// (providers.go) already established for a DIFFERENT direction: checking +// whether an INTERPRETED plugin-defined type (like providerHTTPError +// itself) satisfies the standard error interface, which is exactly what +// makes errors.As panic under Yaegi (it needs to synthesize interpreted +// type info for that check). That hand-rolled version was WRONG for +// THIS direction, and the SHOULD-A yaegi-check harness (v0.22 review +// round, round 2 — tools/yaegi-check/main.go's exerciseAttemptAccounting) +// caught it empirically: under the interpreter, `err.(multiUnwrapper)` +// — an INTERPRETED interface type (multiUnwrapper, declared in this +// file) asserted against a value whose concrete type is COMPILED +// (*fmt.wrapErrors, from a real fmt.Errorf call with more than one %w) — +// silently returned ok=false even though %T correctly reported +// *fmt.wrapErrors and that type genuinely implements Unwrap() []error in +// real, compiled Go. Yaegi's interface-satisfaction check apparently +// does not correctly match a compiled concrete type's method set against +// an interpreter-declared interface signature, at least for this shape — +// the reverse direction of the already-documented trap, not previously +// known to this codebase. +// +// errors.Is does not have this problem here: sentinel (context. +// DeadlineExceeded, context.Canceled — isDeadlineExceeded's only +// callers) and every err this function is ever called with (the network/ +// context error chain client.Do and fmt.Errorf produce) are BOTH always +// compiled-origin values — never an interpreted plugin type. errors.Is's +// own internal Unwrap-chain walk (including its Go 1.20+ multi-error +// support) therefore runs entirely within compiled code on compiled +// types, the same safe shape retry.go's isTransient already relies on +// for these identical two sentinels, proven correct under Yaegi across +// every prior review round. The risk this file's earlier version was +// trying to avoid — errors.As panicking on an INTERPRETED type — simply +// does not arise for a plain sentinel comparison against a compiled +// value. Verified directly: this replacement is what made SHOULD-A's +// timeout-driving harness pass under the real interpreter (round 2's +// hand-rolled fix, though it passed every compiled `go test`, did not). func matchesSentinel(err, sentinel error) bool { - for err != nil { - if err == sentinel { //nolint:errorlint // deliberate identity comparison; see doc comment above - return true - } - u, ok := err.(sentinelUnwrapper) - if !ok { - return false - } - err = u.Unwrap() - } - return false + return errors.Is(err, sentinel) } // isDeadlineExceeded reports whether err IS, or wraps, context. diff --git a/limits_test.go b/limits_test.go index 292404a..b1b56ed 100644 --- a/limits_test.go +++ b/limits_test.go @@ -1421,7 +1421,7 @@ func TestRecordProviderAttempt_ClassifiesUsingIsTransient(t *testing.T) { {name: "network error", err: errors.New("dial tcp: connection refused"), wantFail: true}, {name: "context canceled (not a provider fault)", err: context.Canceled, wantFail: false}, {name: "context deadline exceeded (hung upstream timed out — SHOULD-1)", err: context.DeadlineExceeded, wantFail: true}, - {name: "wrapped context deadline exceeded (proves the manual Unwrap walk)", err: fmt.Errorf("%w: dial timeout", context.DeadlineExceeded), wantFail: true}, + {name: "wrapped context deadline exceeded (proves errors.Is walks the chain)", err: fmt.Errorf("%w: dial timeout", context.DeadlineExceeded), wantFail: true}, {name: "wrapped context canceled stays non-failure too", err: fmt.Errorf("%w: client hung up", context.Canceled), wantFail: false}, } @@ -1494,14 +1494,63 @@ func TestRecordProviderAttempt_EmptyProvider_NoOp(t *testing.T) { l.recordProviderAttempt("", "some-model", &http.Response{StatusCode: http.StatusOK}, nil) // must not panic } -// TestIsDeadlineExceeded_YaegiSafeUnwrap exercises matchesSentinel's -// hand-rolled Unwrap walk directly (SHOULD-1, v0.22 review round): a bare -// context.DeadlineExceeded, one wrapped once, one wrapped twice (proving -// the loop actually loops, not just unwraps one level), a non-matching -// error that implements Unwrap (must walk to its end and report false, -// not stop after one failed comparison), and a plain error with no -// Unwrap method at all (the comma-ok assertion's negative case). -func TestIsDeadlineExceeded_YaegiSafeUnwrap(t *testing.T) { +// TestRecordProviderAttempt_ProductionSpawn_WriteEventuallyLandsAsync +// leaves limiter.spawn at its real production default (newLimiter's own +// bounded, goroutine-spawning closure) instead of overriding it to run +// synchronously like every other recordProviderAttempt test in this file +// — FOLDED-2 (v0.22 review round, round 2): every other test here proves +// the WRITE is correct, but only by bypassing the actual async code path +// (limiter.spawn's own doc comment) entirely; this is the one test that +// exercises it for real, closing a real -race async-path gap. Polls +// (waitUntil, registry_test.go) rather than sleeping a fixed duration — +// a fixed sleep is either flaky (too short, especially under `-race`, +// which distorts goroutine scheduling) or wastefully slow (too long); a +// deadline-bounded poll is neither. +func TestRecordProviderAttempt_ProductionSpawn_WriteEventuallyLandsAsync(t *testing.T) { + l := newLimiter(nil, true) // production default spawn — deliberately NOT newSyncLimiter + now := time.Date(2026, 8, 21, 12, 0, 0, 0, time.UTC) + l.nowFn = func() time.Time { return now } + + l.recordProviderAttempt("openai", "gpt-4o", &http.Response{StatusCode: http.StatusOK}, nil) + + waitUntil(t, time.Second, func() bool { + attempts, _ := l.getCounter(kindProvider, "openai", metricProvAttempt, windowDay, now) + return attempts == 1 + }) + fails, _ := l.getCounter(kindProvider, "openai", metricProvFail, windowDay, now) + if fails != 0 { + t.Errorf("fails/day = %d, want 0 (a 200 response is never a failure)", fails) + } +} + +// TestIsDeadlineExceeded_Classification exercises isDeadlineExceeded's +// observable classification across every wrap shape that matters: bare, +// wrapped once, wrapped twice, an unrelated sentinel (context.Canceled, +// which must never match), an unrelated wrapped error, a plain error +// with no Unwrap method — PLUS the prod-shape double-%w/triple-%w rows a +// review round-2 blocker demanded, byte-for-byte the exact format +// strings providers.go's three upstreamJSON/upstreamBytes call sites use. +// +// A load-bearing caveat this test's own name used to hide (it was +// TestIsDeadlineExceeded_YaegiSafeUnwrap): every case here runs COMPILED, +// under `go test`, and compiled-Go correctness is not the same claim as +// Yaegi-interpreted correctness. Round 2's original fix — a hand-rolled +// Unwrap walk against two locally declared interfaces, matched with bare +// comma-ok type assertions — passed every one of these exact rows +// (including the double-/triple-%w ones) under `go test`, while +// SHOULD-A's yaegi-check harness (tools/yaegi-check/main.go's +// exerciseAttemptAccounting) proved it silently returned false for the +// double-%w case under the REAL interpreter: an interpreted interface +// type does not correctly match a compiled concrete value's method set +// in Yaegi, the reverse direction of the already-documented errors.As- +// on-interpreted-types trap. matchesSentinel now calls real errors.Is +// instead (limits.go's own doc comment there has the full account of why +// that is safe here specifically, unlike errors.As on an interpreted +// type) — this table still pins the OBSERVABLE behavior, but +// tools/yaegi-check is what actually proves it under the interpreter; +// this table alone would not have caught the round-2 regression, and a +// future change here must keep running yaegi-check, not just `go test`. +func TestIsDeadlineExceeded_Classification(t *testing.T) { tests := []struct { err error name string @@ -1514,6 +1563,31 @@ func TestIsDeadlineExceeded_YaegiSafeUnwrap(t *testing.T) { {name: "unrelated sentinel (context.Canceled)", err: context.Canceled, want: false}, {name: "unrelated wrapped error", err: fmt.Errorf("dial: %w", errors.New("connection refused")), want: false}, {name: "plain error, no Unwrap method", err: errors.New("boom"), want: false}, + { + name: "double-%w, upstreamBytes' client.Do shape — the blocker's own reproduction", + err: fmt.Errorf("%w: %w", errUpstream, context.DeadlineExceeded), + want: true, + }, + { + name: "double-%w, upstreamJSON's encode-failure shape", + err: fmt.Errorf("%w: encode request body: %w", errUpstream, context.DeadlineExceeded), + want: true, + }, + { + name: "triple-%w, upstreamBytes' build-request shape", + err: fmt.Errorf("%w: %w: build request: %w", errUpstream, errRequestBuildFailed, context.DeadlineExceeded), + want: true, + }, + { + name: "double-%w wrapping context.Canceled must still NOT match — multi-wrap does not blur the two sentinels apart", + err: fmt.Errorf("%w: %w", errUpstream, context.Canceled), + want: false, + }, + { + name: "double-%w wrapping an unrelated error must still NOT match", + err: fmt.Errorf("%w: %w", errUpstream, errors.New("connection refused")), + want: false, + }, } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { diff --git a/routes_passthrough_test.go b/routes_passthrough_test.go index 79c6683..074ba9b 100644 --- a/routes_passthrough_test.go +++ b/routes_passthrough_test.go @@ -934,3 +934,56 @@ func TestHandlePassthrough_AnthropicClientAPIKeyStripped_ProviderKeyInjected(t * t.Errorf("x-api-key = %q, want the provider's own key injected", gotAPIKeyHeader) } } + +// TestHandlePassthrough_ContextDeadlineExceeded_RecordsProviderFailure is +// the passthrough half of the route-level regression the review's +// blocker demanded (v0.22, round 2) — a real context deadline against a +// real sleeping httptest upstream. Passthrough was NEVER actually broken +// by the multi-%w bug (proxyUpstream's client.Do error reaches +// attemptRecorderFromContext bare, never re-wrapped by upstreamBytes — +// see recordProviderAttempt's own call site here, routes_passthrough.go), +// but the review round proved that by observation, not a route-level +// assertion; this pins it so a future refactor cannot silently regress +// it the same way the unified route regressed. +func TestHandlePassthrough_ContextDeadlineExceeded_RecordsProviderFailure(t *testing.T) { + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + time.Sleep(600 * time.Millisecond) // well past the request's own 60ms deadline below + })) + defer srv.Close() + + cfg := CreateConfig() + cfg.Providers = map[string]*ProviderConfig{ + "openai": {Type: "openai", BaseURL: srv.URL, APIKey: "sk-up"}, + } + cfg.Groups = map[string]*GroupConfig{"default": {}} + cfg.Users = &UsersConfig{Inline: []*UserConfig{ + {Name: "alice", Group: "default", APIKey: "sk-alice", Limits: &LimitsConfig{}}, + }} + next := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {}) + h, err := New(context.Background(), next, cfg, "llmgw") + if err != nil { + t.Fatalf("New: %v", err) + } + gw, ok := h.(*Gateway) + if !ok { + t.Fatal("handler is not *Gateway") + } + gw.limiter.spawn = func(f func()) { f() } + + ctx, cancel := context.WithTimeout(context.Background(), 60*time.Millisecond) + defer cancel() + req := httptest.NewRequest(http.MethodPost, "/openai/v1/native-endpoint", strings.NewReader(`{}`)).WithContext(ctx) + req.Header.Set("Authorization", "Bearer sk-alice") + rec := httptest.NewRecorder() + h.ServeHTTP(rec, req) + + now := time.Now() + attempts, _ := gw.limiter.getCounter(kindProvider, "openai", metricProvAttempt, windowDay, now) + if attempts != 1 { + t.Errorf("provider attempts/day = %d, want 1", attempts) + } + fails, _ := gw.limiter.getCounter(kindProvider, "openai", metricProvFail, windowDay, now) + if fails != 1 { + t.Errorf("provider fails/day = %d, want 1 — a real context-deadline timeout must count as a provider-health failure (SHOULD-1)", fails) + } +} diff --git a/routes_unified_test.go b/routes_unified_test.go index be9a8f3..cb703ea 100644 --- a/routes_unified_test.go +++ b/routes_unified_test.go @@ -1830,3 +1830,67 @@ func TestUnifiedCostMicros(t *testing.T) { }) } } + +// TestHandleChat_ContextDeadlineExceeded_RecordsProviderFailure is the +// route-level regression test the review's blocker (v0.22, round 2) +// specifically demanded: TestIsDeadlineExceeded_YaegiSafeUnwrap's +// hand-built error shapes (limits_test.go) proved matchesSentinel's own +// unwrap logic works in isolation, but that alone is exactly what let the +// real bug ship — every hand-built shape there was single-%w, while the +// live chain through upstreamBytes' client.Do call is providers.go's +// own double-%w `fmt.Errorf("%w: %w", errUpstream, err)`, one layer +// short of what a table test alone would ever exercise. This drives a +// REAL request whose context deadline expires while a REAL httptest +// upstream is still sleeping — client.Do, *url.Error, and the wrap chain +// providers.go actually builds, all for real — and asserts the resulting +// provider counters directly, not a synthetic error value. +func TestHandleChat_ContextDeadlineExceeded_RecordsProviderFailure(t *testing.T) { + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + time.Sleep(600 * time.Millisecond) // well past the request's own 60ms deadline below + w.Header().Set("Content-Type", "application/json") + _, _ = w.Write([]byte(`{"id":"c1","object":"chat.completion","model":"gpt-test","choices":[],"usage":{}}`)) + })) + defer srv.Close() + + cfg := CreateConfig() + cfg.Providers = map[string]*ProviderConfig{ + "openai": {Type: "openai", BaseURL: srv.URL, APIKey: "sk-up", Models: []string{"gpt-test"}}, + } + cfg.Groups = map[string]*GroupConfig{"default": {}} + cfg.Users = &UsersConfig{Inline: []*UserConfig{ + {Name: "alice", Group: "default", APIKey: "sk-alice", Limits: &LimitsConfig{}}, + }} + next := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {}) + h, err := New(context.Background(), next, cfg, "llmgw") + if err != nil { + t.Fatalf("New: %v", err) + } + gw, ok := h.(*Gateway) + if !ok { + t.Fatal("handler is not *Gateway") + } + // SHOULD-5: run recordProviderAttempt's store write synchronously so + // the counter read below is deterministic (see limiter.spawn's own + // doc comment, limits.go). FOLDED-2's own test (limits_test.go) + // covers the production async default separately. + gw.limiter.spawn = func(f func()) { f() } + + ctx, cancel := context.WithTimeout(context.Background(), 60*time.Millisecond) + defer cancel() + req := httptest.NewRequest(http.MethodPost, "/v1/chat/completions", + strings.NewReader(`{"model":"gpt-test","messages":[{"role":"user","content":"hi"}]}`)).WithContext(ctx) + req.Header.Set("Authorization", "Bearer sk-alice") + req.Header.Set("Content-Type", "application/json") + rec := httptest.NewRecorder() + h.ServeHTTP(rec, req) + + now := time.Now() + attempts, _ := gw.limiter.getCounter(kindProvider, "openai", metricProvAttempt, windowDay, now) + if attempts != 1 { + t.Errorf("provider attempts/day = %d, want 1", attempts) + } + fails, _ := gw.limiter.getCounter(kindProvider, "openai", metricProvFail, windowDay, now) + if fails != 1 { + t.Errorf("provider fails/day = %d, want 1 — a real context-deadline timeout must count as a provider-health failure (SHOULD-1)", fails) + } +} diff --git a/tools/yaegi-check/main.go b/tools/yaegi-check/main.go index ec80498..1df550e 100644 --- a/tools/yaegi-check/main.go +++ b/tools/yaegi-check/main.go @@ -50,14 +50,44 @@ import ( // layers on top of testData (see its own override comment) — SHOULD-4 // (v0.22 review round): this harness proves recordProviderAttempt's // SHOULD-1 deadline/cancel classification (limits.go's matchesSentinel/ -// isDeadlineExceeded, a hand-rolled errors.Unwrap walk specifically -// because errors.Is/errors.As are unsafe under Yaegi — see their own doc -// comments) actually runs correctly INTERPRETED, not merely compiled: a -// bug there would not show up under `go test`, only here. +// isDeadlineExceeded) actually runs correctly INTERPRETED, not merely +// compiled: a bug there would not show up under `go test`, only here — +// which is exactly what happened in round 2 (see slowProviderName's own +// doc comment immediately below, and matchesSentinel's in limits.go, for +// the full account of the interpreter-only bug this harness caught). +// +// slowProviderName/slowProviderModel/slowUpstreamSleep/ +// slowRequestDeadline back exerciseAttemptAccounting's SECOND request +// (SHOULD-A, v0.22 review round, round 2): the FIRST version of this +// harness only ever drove an upstream that answers instantly, so +// isDeadlineExceeded never actually saw a non-nil error, interpreted or +// otherwise — a comment claiming to prove the interpreted deadline path +// while never exercising it. Once fixed to actually drive a timeout, it +// caught a real bug: round 2's original matchesSentinel (a hand-rolled +// Unwrap walk against two locally declared interfaces, comma-ok matched) +// passed every compiled `go test` row for a double-%w error shape but +// silently misclassified it under the real interpreter — an interpreted +// interface type failing to match a compiled concrete value's method +// set. matchesSentinel now calls real errors.Is instead (limits.go's own +// doc comment has the full account of why that is safe here +// specifically). The second request below: a second, DELIBERATELY slow +// provider, addressed by its own provider-prefixed model id +// (`slowProviderName+"/"+slowProviderModel`, routableModelId's own +// "provider/model" convention) so it can never collide with +// testDataWantModel's bare "gpt-test" on the "openai" provider, driven +// with a request context deadline shorter than the upstream's own +// sleep — the exact shape the route-level Go test regression (routes_ +// unified_test.go's TestHandleChat_ContextDeadlineExceeded_ +// RecordsProviderFailure) already proves compiled; this proves it +// interpreted. const ( testDataUserAPIKey = "test-user-key" testDataWantModel = "gpt-test" attemptAccountingAdminAPIKey = "sk-admin1" + slowProviderName = "slow" + slowProviderModel = "gpt-test" + slowUpstreamSleep = 600 * time.Millisecond + slowRequestDeadline = 60 * time.Millisecond ) // excludedTopLevelDirs lists repo-root directories the GOPATH copy must @@ -178,7 +208,20 @@ func run() error { _, _ = w.Write([]byte(`{"id":"c1","object":"chat.completion","model":"gpt-test","choices":[{"index":0,"message":{"role":"assistant","content":"hi"},"finish_reason":"stop"}],"usage":{"prompt_tokens":1,"completion_tokens":1}}`)) })) defer upstream.Close() - attemptAccountingOverride := `{"providers":{"openai":{"type":"openai","baseUrl":"` + upstream.URL + `","apiKey":"sk-up","models":["` + testDataWantModel + `"]}},"admin":{"enabled":true},"users":{"inline":[{"name":"tester","group":"default","apiKey":"` + testDataUserAPIKey + `"},{"name":"admin1","group":"default","apiKey":"` + attemptAccountingAdminAPIKey + `","admin":true}]}}` + + // slowUpstream never answers within slowRequestDeadline — see + // slowProviderName's own doc comment above (SHOULD-A) for why this + // second provider exists at all. + slowUpstream := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + time.Sleep(slowUpstreamSleep) + w.Header().Set("Content-Type", "application/json") + _, _ = w.Write([]byte(`{"id":"c2","object":"chat.completion","model":"gpt-test","choices":[{"index":0,"message":{"role":"assistant","content":"hi"},"finish_reason":"stop"}],"usage":{"prompt_tokens":1,"completion_tokens":1}}`)) + })) + defer slowUpstream.Close() + + attemptAccountingOverride := `{"providers":{"openai":{"type":"openai","baseUrl":"` + upstream.URL + `","apiKey":"sk-up","models":["` + testDataWantModel + `"]},"` + + slowProviderName + `":{"type":"openai","baseUrl":"` + slowUpstream.URL + `","apiKey":"sk-up","models":["` + slowProviderModel + `"]}},` + + `"admin":{"enabled":true},"users":{"inline":[{"name":"tester","group":"default","apiKey":"` + testDataUserAPIKey + `"},{"name":"admin1","group":"default","apiKey":"` + attemptAccountingAdminAPIKey + `","admin":true}]}}` if err = json.Unmarshal([]byte(attemptAccountingOverride), cfgVal.Interface()); err != nil { return fmt.Errorf("decode attempt-accounting harness override into the interpreted Config: %w", err) } @@ -248,20 +291,35 @@ func exerciseHandler(handler http.Handler) error { return nil } -// exerciseAttemptAccounting drives a real chat completion through -// handler (against the local httptest upstream run's own override wired -// in), then GET /admin/api/overview, asserting the resulting provider -// reports exactly one attempt and zero failures — Feature A's (v0.22) -// per-provider success-rate accounting, exercised end to end under -// Yaegi: runUnified's attemptRecorder (routes_unified.go) -> -// retryPolicy.do's context lookup (retry.go) -> +// exerciseAttemptAccounting drives two real requests through handler — +// Feature A's (v0.22) per-provider success-rate accounting, exercised +// end to end under Yaegi: runUnified's attemptRecorder (routes_unified. +// go) -> retryPolicy.do's context lookup (retry.go) -> // limiter.recordProviderAttempt's isTransient/isDeadlineExceeded -// classification (limits.go) -> its fire-and-forget spawn (SHOULD-5) -> -// buildAdminOverview's own batched providerUsage read (admin.go). Any -// interpreter-only failure in that chain — a construct `go build`/`go -// test` cannot catch, exactly the class of bug this harness exists for -// (SHOULD-4, v0.22 review round) — surfaces here as a non-1/non-0 count -// or an outright panic under Yaegi. +// classification (limits.go, including matchesSentinel's errors.Is call +// through providers.go's own multi-%w wrapping) -> its fire-and-forget +// spawn (SHOULD-5) -> buildAdminOverview's own batched providerUsage read +// (admin.go). Any interpreter-only failure in that chain — a construct +// `go build`/`go test` cannot catch, exactly the class of bug this +// harness exists for (SHOULD-4, v0.22 review round) — surfaces here as a +// non-1/non-0 count or an outright panic under Yaegi. +// +// The first request (against "openai", instant upstream) proves the +// success path: one attempt, zero failures. The second (against +// slowProviderName, an upstream that never answers within +// slowRequestDeadline — SHOULD-A, round 2) proves the FAILURE path: +// exactly what round 1 of this harness claimed to prove but never +// actually drove — the interpreted plugin never saw a non-nil error at +// all, so isDeadlineExceeded was never exercised under this harness even +// while it ran (and passed) under `go test`. THIS is what SHOULD-A was +// for: the first version of this second request, run against round 2's +// hand-rolled comma-ok Unwrap-walk fix (limits.go's matchesSentinel, +// since replaced), FAILED right here — under the interpreter only, +// despite passing every compiled `go test` row for the identical error +// shape — because an interpreted interface type does not correctly match +// a compiled concrete value's method set in Yaegi. matchesSentinel now +// uses real errors.Is instead (its own doc comment in limits.go has the +// full account); this harness is what caught the difference. func exerciseAttemptAccounting(handler http.Handler) error { chatReq := httptest.NewRequest(http.MethodPost, "/v1/chat/completions", strings.NewReader( `{"model":"`+testDataWantModel+`","messages":[{"role":"user","content":"hi"}]}`, @@ -274,33 +332,61 @@ func exerciseAttemptAccounting(handler http.Handler) error { return fmt.Errorf("POST /v1/chat/completions (attempt-accounting harness): status = %d, want 200, body=%s", chatRec.Code, chatRec.Body.String()) } - attemptsDay, failuresDay, err := pollProviderAttemptCounters(handler) + attemptsDay, failuresDay, err := pollProviderAttemptCounters(handler, "openai") if err != nil { return err } if attemptsDay != 1 { - return fmt.Errorf("admin overview providers[0].attemptsDay = %v, want 1 (Feature A attempt-accounting harness)", attemptsDay) + return fmt.Errorf(`admin overview provider "openai" attemptsDay = %v, want 1 (Feature A attempt-accounting harness)`, attemptsDay) } if failuresDay != 0 { - return fmt.Errorf("admin overview providers[0].failuresDay = %v, want 0", failuresDay) + return fmt.Errorf(`admin overview provider "openai" failuresDay = %v, want 0`, failuresDay) + } + + // SHOULD-A: a real, interpreted context-deadline timeout against a + // deliberately slow upstream must record a FAILURE — the whole + // reason this harness exists after round 2's blocker. + slowCtx, cancel := context.WithTimeout(context.Background(), slowRequestDeadline) + defer cancel() + slowReq := httptest.NewRequest(http.MethodPost, "/v1/chat/completions", strings.NewReader( + `{"model":"`+slowProviderName+`/`+slowProviderModel+`","messages":[{"role":"user","content":"hi"}]}`, + )).WithContext(slowCtx) + slowReq.Header.Set("Authorization", "Bearer "+testDataUserAPIKey) + slowReq.Header.Set("Content-Type", "application/json") + slowRec := httptest.NewRecorder() + handler.ServeHTTP(slowRec, slowReq) + // No status assertion here on purpose: the point of interest is the + // PROVIDER-HEALTH counter a timed-out upstream attempt leaves behind, + // not what status code a canceled/timed-out client request itself + // gets back (which the existing route-level Go tests already pin). + + slowAttemptsDay, slowFailuresDay, err := pollProviderAttemptCounters(handler, slowProviderName) + if err != nil { + return err + } + if slowAttemptsDay != 1 { + return fmt.Errorf("admin overview provider %q attemptsDay = %v, want 1 (SHOULD-A timeout harness)", slowProviderName, slowAttemptsDay) + } + if slowFailuresDay != 1 { + return fmt.Errorf("admin overview provider %q failuresDay = %v, want 1 — a real interpreted context-deadline timeout must count as a provider-health failure (SHOULD-A, closes the round-2 blocker)", slowProviderName, slowFailuresDay) } return nil } // pollProviderAttemptCounters drives GET /admin/api/overview against -// handler repeatedly until providers[0].attemptsDay is non-zero or a 2s +// handler repeatedly until providerName's attemptsDay is non-zero or a 2s // budget elapses, then returns its final reading either way — SHOULD-5 // (v0.22 review round): recordProviderAttempt's store write runs on its -// own goroutine (limiter.spawn), off the chat request that triggered it, -// so a single immediate read right after that request returns could race +// own goroutine (limiter.spawn), off the request that triggered it, so a +// single immediate read right after that request returns could race // ahead of the write landing. A real goroutine still schedules promptly // under Yaegi (only the INTERPRETED code driving it runs slower, not the // underlying Go runtime's scheduler), so this is a short poll, not a // long one. -func pollProviderAttemptCounters(handler http.Handler) (attemptsDay, failuresDay float64, err error) { +func pollProviderAttemptCounters(handler http.Handler, providerName string) (attemptsDay, failuresDay float64, err error) { deadline := time.Now().Add(2 * time.Second) for { - attemptsDay, failuresDay, err = readProviderAttemptCounters(handler) + attemptsDay, failuresDay, err = readProviderAttemptCounters(handler, providerName) if err != nil { return 0, 0, err } @@ -311,14 +397,18 @@ func pollProviderAttemptCounters(handler http.Handler) (attemptsDay, failuresDay } } -// readProviderAttemptCounters reads GET /admin/api/overview's first -// provider's attemptsDay/failuresDay fields via a generic map[string]any -// decode — this harness module is compiled, not interpreted, so it could -// import the plugin's own admin.go types directly, but they are -// unexported (adminOverviewResponse, adminProviderView); decoding -// generically here is simpler than exporting test-only types across that -// boundary just for this one harness. -func readProviderAttemptCounters(handler http.Handler) (attemptsDay, failuresDay float64, err error) { +// readProviderAttemptCounters reads GET /admin/api/overview, finds the +// entry named providerName, and returns its attemptsDay/failuresDay +// fields via a generic map[string]any decode — this harness module is +// compiled, not interpreted, so it could import the plugin's own admin.go +// types directly, but they are unexported (adminOverviewResponse, +// adminProviderView); decoding generically here is simpler than exporting +// test-only types across that boundary just for this one harness. Looked +// up by name, not index 0 (round 1 of this harness only ever had one +// configured provider): buildAdminOverview sorts providers by name +// (registry.go), so adding slowProviderName ("slow") after "openai" +// changed which index held which provider. +func readProviderAttemptCounters(handler http.Handler, providerName string) (attemptsDay, failuresDay float64, err error) { req := httptest.NewRequest(http.MethodGet, "/admin/api/overview", nil) req.Header.Set("Authorization", "Bearer "+attemptAccountingAdminAPIKey) rec := httptest.NewRecorder() @@ -332,16 +422,22 @@ func readProviderAttemptCounters(handler http.Handler) (attemptsDay, failuresDay return 0, 0, fmt.Errorf("decode GET /admin/api/overview body: %w", err) } providers, ok := body["providers"].([]any) - if !ok || len(providers) == 0 { - return 0, 0, fmt.Errorf("admin overview body has no providers: %s", rec.Body.String()) - } - p, ok := providers[0].(map[string]any) if !ok { - return 0, 0, fmt.Errorf("admin overview providers[0] is not an object: %s", rec.Body.String()) + return 0, 0, fmt.Errorf("admin overview body has no providers array: %s", rec.Body.String()) } - attemptsDay, _ = p["attemptsDay"].(float64) - failuresDay, _ = p["failuresDay"].(float64) - return attemptsDay, failuresDay, nil + for _, raw := range providers { + p, ok := raw.(map[string]any) + if !ok { + continue + } + if name, _ := p["name"].(string); name != providerName { + continue + } + attemptsDay, _ = p["attemptsDay"].(float64) + failuresDay, _ = p["failuresDay"].(float64) + return attemptsDay, failuresDay, nil + } + return 0, 0, fmt.Errorf("admin overview body has no provider named %q: %s", providerName, rec.Body.String()) } // readModulePath returns the module path declared by goModPath's