diff --git a/admin.go b/admin.go index 57fc013..ca865fd 100644 --- a/admin.go +++ b/admin.go @@ -67,10 +67,13 @@ func adminEnabled(cfg *Config) bool { // isAdminPath reports whether path is one of the admin dashboard's // routes: the page, any hashed asset under adminAssetsPathPrefix, or one -// of the /admin/api/* JSON routes. +// of the /admin/api/* JSON routes. adminEventsPath (F3, v0.3 dashboard +// task) is defined in events.go, alongside the rest of that feature's own +// constants. func isAdminPath(path string) bool { if path == adminPagePath || path == adminOverviewPath || path == adminUsagePath || - path == adminUsageHistoryPath || path == adminUsageModelsPath || path == adminTargetsPath { + path == adminUsageHistoryPath || path == adminUsageModelsPath || path == adminTargetsPath || + path == adminEventsPath { return true } return strings.HasPrefix(path, adminAssetsPathPrefix) @@ -147,6 +150,8 @@ func (g *Gateway) handleAdminAPI(sw *statusTrackingWriter, r *http.Request) { g.serveAdminUsageModels(sw, r) case adminTargetsPath: g.serveAdminTargets(sw) + case adminEventsPath: + g.serveAdminEvents(sw, r) } } @@ -612,12 +617,18 @@ type adminAliasView struct { // reflects current state. type adminOverviewResponse struct { Version string `json:"version"` + Replica string `json:"replica"` // F4/F9, v0.3 dashboard task: os.Hostname() -> $HOSTNAME -> "unknown" (replicaID, llmgateway.go) + Instance string `json:"instance"` + Warnings []string `json:"warnings"` // F10, v0.3 dashboard task: collected construction warnings, never nil Providers []adminProviderView `json:"providers"` Groups []adminGroupView `json:"groups"` Aliases []adminAliasView `json:"aliases"` Redis adminRedisView `json:"redis"` Cache adminCacheView `json:"cache"` Retry adminRetryView `json:"retry"` + // WarningsDropped counts construction warnings that did not fit within + // configWarningsCap (logger.go) — omitted (0) means nothing was dropped. + WarningsDropped int `json:"warningsDropped,omitempty"` } // buildAdminOverview assembles adminOverviewResponse from the registry, @@ -731,14 +742,19 @@ func (g *Gateway) buildAdminOverview() adminOverviewResponse { } } + warnings, warningsDropped := g.configWarningsSnapshot() return adminOverviewResponse{ - Providers: providers, - Redis: adminRedisView{Configured: configured, LastErr: redisLastErr, LastErrAt: redisLastErrAt}, - Cache: adminCacheView{Enabled: cacheEnabled, TTL: ttl}, - Retry: retryView, - Groups: groups, - Aliases: aliases, - Version: pluginVersion, + Providers: providers, + Redis: adminRedisView{Configured: configured, LastErr: redisLastErr, LastErrAt: redisLastErrAt}, + Cache: adminCacheView{Enabled: cacheEnabled, TTL: ttl}, + Retry: retryView, + Groups: groups, + Aliases: aliases, + Version: pluginVersion, + Replica: g.replica, + Instance: g.name, + Warnings: warnings, + WarningsDropped: warningsDropped, } } @@ -790,7 +806,11 @@ type adminUsageEntryView struct { TokensOutPerMonth int64 `json:"tokensOutPerMonth"` CostPerDayMicroUSD int64 `json:"costPerDayMicroUsd"` CostPerMonthMicroUSD int64 `json:"costPerMonthMicroUsd"` - StoreDown bool `json:"storeDown,omitempty"` + // RejectionsPerDay is the fleet-wide count of checkAndCount rejections + // attributed to this scope today (F4, v0.3 dashboard task) — read via + // windowKey's metric "rej", window "day" (limits.go's metricRej). + RejectionsPerDay int64 `json:"rejectionsPerDay"` + StoreDown bool `json:"storeDown,omitempty"` } // adminUsageResponse is the full body of GET /admin/api/usage: every @@ -820,6 +840,7 @@ func usageEntryView(su scopeUsage, limits *LimitsConfig) adminUsageEntryView { TokensOutPerMonth: su.tokensOutPerMonth, CostPerDayMicroUSD: su.costPerDayMicros, CostPerMonthMicroUSD: su.costPerMonthMicros, + RejectionsPerDay: su.rejectionsPerDay, StoreDown: su.storeDown, } } @@ -847,7 +868,8 @@ func usageEntryView(su scopeUsage, limits *LimitsConfig) adminUsageEntryView { // that round trip's own pipeline size, and how long it holds the shared, // mutex-guarded Redis connection (respClient, resp.go), now scales with // how many users and groups are configured. With 1,000 users that is -// ~8,000 GETs (usageKeysPerScope=8) in one pipelined call, during which +// ~9,000 GETs (usageKeysPerScope=9, F4 v0.3 dashboard task's rej:day +// counter) in one pipelined call, during which // every concurrent checkAndCount from live LLM traffic queues behind the // same connection mutex — and the admin dashboard polls this endpoint // every 5s. chunkedCurrentUsage (below) keeps each individual round trip's @@ -1156,6 +1178,51 @@ func parseUsageModelsLimit(raw string) (limit int, ok bool) { return n, true } +// usageModelsPrefixMaxLen bounds GET /admin/api/usage/models' optional +// "prefix" query parameter (item 6, v0.3 dashboard task round 2): an +// operator-typed search string from the Charts view's model filter box, +// not a value with any legitimate reason to run long — a real model id +// this endpoint ranks over is always far shorter. Bounding it keeps a +// malformed or hostile query cheap to reject before catalogModelScopeIDs +// is even walked. +const usageModelsPrefixMaxLen = 256 + +// parseUsageModelsPrefix parses GET /admin/api/usage/models' optional +// "prefix" query parameter: empty means no filtering (every catalogued +// model ranked, this endpoint's original, pre-prefix behavior), otherwise +// the raw string unchanged, so long as it is at most +// usageModelsPrefixMaxLen bytes. ok is false for anything longer, +// mirroring parseUsageModelsLimit/parseUsageModelsSpan's own +// validate-before-reading shape. No further validation: a prefix that +// matches nothing in the catalog is not an error, just an empty (still +// 200) ranking — the same "no non-zero models" shape an ordinary, +// unfiltered ranking already answers when nothing was used yet. +func parseUsageModelsPrefix(raw string) (prefix string, ok bool) { + if len(raw) > usageModelsPrefixMaxLen { + return "", false + } + return raw, true +} + +// parseUsageModelsSpan parses GET /admin/api/usage/models' optional +// "span" query parameter (F2, v0.3 dashboard task): empty means 1 — +// today's own bucket, this endpoint's original, pre-span behavior — +// otherwise an integer between 1 and window's own historyMaxSpan +// inclusive, mirroring parseHistorySpan's own validate-before-reading +// shape and identical range. window is assumed already validated by +// validHistoryWindow, exactly like parseHistorySpan's own precondition. +func parseUsageModelsSpan(raw, window string) (span int, ok bool) { + if raw == "" { + return 1, true + } + max := historyMaxSpan(window) + n, err := strconv.Atoi(raw) + if err != nil || n < 1 || n > max { + return 0, false + } + return n, true +} + // catalogModelScopeIDs returns every catalogued (provider, model) pair's // canonical kindModel scope id, in the registry snapshot's own order. It // is the enumeration GET /admin/api/usage/models ranks over, and the same @@ -1181,19 +1248,68 @@ type adminUsageModelEntryView struct { Value int64 `json:"value"` } -// adminUsageModelsResponse is GET /admin/api/usage/models' body. +// adminUsageModelsResponse is GET /admin/api/usage/models' body. Span +// (F2, v0.3 dashboard task) echoes the resolved span (1 when the request +// carried no ?span= parameter — parseUsageModelsSpan's own default). type adminUsageModelsResponse struct { Metric string `json:"metric"` Window string `json:"window"` Models []adminUsageModelEntryView `json:"models"` + Span int `json:"span"` +} + +// usageModelsChunkKeys bounds how many counterStore keys +// chunkedModelSpanTotals (below) reads in a single storeGetMulti round +// trip — adminUsageChunkScopes' own reasoning (buildAdminUsage, above) +// applied to the catalog-sized, now span-multiplied read GET +// /admin/api/usage/models performs once a caller asks for span > 1: with +// ?span=24 on an hour window and a 400-model catalog, an unchunked read +// would pipeline 400*24 = 9,600 keys in one call, holding the shared +// Redis connection mutex (respClient, resp.go) for that whole pipeline +// while live traffic's own checkAndCount/account calls queue behind it. +const usageModelsChunkKeys = 1600 + +// chunkedModelSpanTotals calls limiter.modelSpanTotals in batches sized +// so each batch's own key count (len(chunk)*span) stays at or under +// usageModelsChunkKeys — mirroring chunkedCurrentUsage's chunking +// (above), sized for span instead of the fixed usageKeysPerScope stride. +// now is resolved once by the caller and threaded through every chunk, so +// every id's span ends at the identical instant regardless of how many +// chunks the catalog splits into. Any chunk that fails (storeDown or a +// mismatched read) fails the whole call: a ranking silently missing an +// arbitrary subset of models is worse than a 503, so this never returns a +// partial ranking. +func (g *Gateway) chunkedModelSpanTotals(ids []string, metric, window string, now time.Time, span int) ([]int64, bool) { + perChunk := usageModelsChunkKeys / span + if perChunk < 1 { + perChunk = 1 + } + out := make([]int64, 0, len(ids)) + for len(ids) > 0 { + n := perChunk + if n > len(ids) { + n = len(ids) + } + totals, ok := g.limiter.modelSpanTotals(ids[:n], metric, window, now, span) + if !ok { + return nil, false + } + out = append(out, totals...) + ids = ids[n:] + } + return out, true } // serveAdminUsageModels writes GET /admin/api/usage/models' ranking of the // most-used models for one metric/window (the Charts view's "Models" // tab): "metric"=req|tokin|tokout|cost, "window"=hour|day|month, optional -// "limit"=N (default and max per the constants above). Every parameter is -// validated before the store is touched — 400 for an unrecognized metric -// or window, or an out-of-range limit. +// "limit"=N (default and max per the constants above), optional +// "prefix"=STRING (item 6, v0.3 dashboard task round 2: the Charts +// view's model search box) narrowing the catalog to ids that start with +// it before anything is ranked — see below. Every parameter is validated +// before the store is touched — 400 for an unrecognized metric or +// window, an out-of-range limit, or a prefix over +// usageModelsPrefixMaxLen. // // ONLY NON-ZERO models are returned, by explicit operator requirement: the // catalog runs to hundreds of models and a ranking padded with zeroes is @@ -1203,6 +1319,16 @@ type adminUsageModelsResponse struct { // one-batched-read-per-poll shape serveAdminOverview already uses for // per-provider counters. // +// prefix narrows catalogModelScopeIDs' own output BEFORE +// chunkedModelSpanTotals ever reads a counter for it, and before limit is +// applied — not a post-hoc filter over an already-ranked, already-limited +// result. A caller searching the Charts view down to one provider's +// models (a common id shape here is "provider/model") must not still pay +// a catalog-sized store read for ids its own prefix already excludes, and +// limit must cap the FILTERED set's own top-N, not silently return fewer +// than limit matches because the unfiltered ranking's top N happened to +// fall outside the prefix. +// // Ties break on the id, ascending, so a ranking of equal values is stable // across polls rather than reshuffling under the reader. A storeDown read // answers 503, never a silently-empty ranking — the same rule @@ -1226,9 +1352,28 @@ func (g *Gateway) serveAdminUsageModels(sw *statusTrackingWriter, r *http.Reques writeOAIError(sw, http.StatusBadRequest, "invalid_request_error", "invalid limit") return } + span, ok := parseUsageModelsSpan(q.Get("span"), window) + if !ok { + writeOAIError(sw, http.StatusBadRequest, "invalid_request_error", "invalid span") + return + } + prefix, ok := parseUsageModelsPrefix(q.Get("prefix")) + if !ok { + writeOAIError(sw, http.StatusBadRequest, "invalid_request_error", "invalid prefix") + return + } ids := g.catalogModelScopeIDs() - totals, storeOK := g.limiter.modelTotals(ids, metric, window) + if prefix != "" { + filtered := make([]string, 0, len(ids)) + for _, id := range ids { + if strings.HasPrefix(id, prefix) { + filtered = append(filtered, id) + } + } + ids = filtered + } + totals, storeOK := g.chunkedModelSpanTotals(ids, metric, window, g.limiter.now(), span) if !storeOK { writeOAIError(sw, http.StatusServiceUnavailable, "server_error", "usage history store unavailable") return @@ -1252,7 +1397,50 @@ func (g *Gateway) serveAdminUsageModels(sw *statusTrackingWriter, r *http.Reques } setAdminJSONHeaders(sw) - _ = json.NewEncoder(sw).Encode(adminUsageModelsResponse{Metric: metric, Window: window, Models: models}) + _ = json.NewEncoder(sw).Encode(adminUsageModelsResponse{Metric: metric, Window: window, Span: span, Models: models}) +} + +// parseEventsLimit parses GET /admin/api/events' "limit" query parameter +// (F3, v0.3 dashboard task): empty means adminEventsDefaultLimit, +// otherwise an integer between 1 and adminEventsMaxLimit inclusive, +// mirroring parseUsageModelsLimit's own validate-before-reading shape. +func parseEventsLimit(raw string) (limit int, ok bool) { + if raw == "" { + return adminEventsDefaultLimit, true + } + n, err := strconv.Atoi(raw) + if err != nil || n < 1 || n > adminEventsMaxLimit { + return 0, false + } + return n, true +} + +// serveAdminEvents writes GET /admin/api/events' most recent gateway +// events (F3, v0.3 dashboard task): rate-limit/budget/store-down +// admission rejections and upstream/timeout/unpriced/capacity error-path +// signals, newest first. "limit" is optional (adminEventsDefaultLimit), +// 1..adminEventsMaxLimit inclusive otherwise 400. Never calls +// checkAndCount — the same admin-traffic-must-not-move-usage-statistics +// rule every other /admin/api/* route already follows (handleAdminAPI's +// own doc comment). Answers from the shared Redis-backed list when +// reachable (source "redis"), falling back to this replica's own local +// ring otherwise (source "replica", Degraded true when Redis is +// configured but this particular read failed) — fail-open: the local +// ring always answers (eventLog.read's own doc comment, events.go). +func (g *Gateway) serveAdminEvents(sw *statusTrackingWriter, r *http.Request) { + limit, ok := parseEventsLimit(r.URL.Query().Get("limit")) + if !ok { + writeOAIError(sw, http.StatusBadRequest, "invalid_request_error", "invalid limit") + return + } + events, source, degraded := g.events.read(limit, g.limiter.storeLatched()) + if events == nil { + events = []gatewayEvent{} + } + setAdminJSONHeaders(sw) + _ = json.NewEncoder(sw).Encode(adminEventsResponse{ + Events: events, Source: source, Replica: g.replica, Capacity: eventRingCap, Degraded: degraded, + }) } // adminTargetCountersView is one target's current-window request counters diff --git a/admin_events_test.go b/admin_events_test.go new file mode 100644 index 0000000..6a98c58 --- /dev/null +++ b/admin_events_test.go @@ -0,0 +1,469 @@ +package traefikllmgateway + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "net/http" + "net/http/httptest" + "testing" + "time" +) + +// newEventsTestConfig builds a Config with Admin enabled, one openai-type +// provider pointed at upstreamURL, and two users: "alice" (an ordinary +// caller, Limits left to the test to set) and "admin1" (Admin: true, for +// reading GET /admin/api/events). Callers may mutate the returned Config +// (in particular cfg.Users.Inline[0].Limits) before calling New. +func newEventsTestConfig(upstreamURL string) *Config { + cfg := CreateConfig() + cfg.Admin = &AdminConfig{Enabled: true} + cfg.Providers = map[string]*ProviderConfig{ + "openai": {Type: "openai", BaseURL: upstreamURL, 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{}}, + {Name: "admin1", Group: "default", APIKey: "sk-admin1", Admin: true}, + }} + return cfg +} + +// getAdminEvents drives GET /admin/api/events?limit=... as sk-admin1 and +// decodes the response. +func getAdminEvents(t *testing.T, h http.Handler, query string) adminEventsResponse { + t.Helper() + req := httptest.NewRequest(http.MethodGet, adminEventsPath+query, nil) + req.Header.Set("Authorization", "Bearer sk-admin1") + rec := httptest.NewRecorder() + h.ServeHTTP(rec, req) + if rec.Code != http.StatusOK { + t.Fatalf("GET %s%s: status = %d, want 200, body=%s", adminEventsPath, query, rec.Code, rec.Body.String()) + } + var got adminEventsResponse + if err := json.Unmarshal(rec.Body.Bytes(), &got); err != nil { + t.Fatalf("decode: %v", err) + } + return got +} + +// --- gate (spec §4, same as every other /admin/api/* route) --- + +func TestAdminEvents_Gate(t *testing.T) { + t.Parallel() + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusOK) })) + defer srv.Close() + cfg := newEventsTestConfig(srv.URL) + 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) + } + + rec := httptest.NewRecorder() + h.ServeHTTP(rec, httptest.NewRequest(http.MethodGet, adminEventsPath, nil)) + if rec.Code != http.StatusUnauthorized { + t.Errorf("unauthenticated: status = %d, want 401", rec.Code) + } + + req := httptest.NewRequest(http.MethodGet, adminEventsPath, nil) + req.Header.Set("Authorization", "Bearer sk-alice") + rec = httptest.NewRecorder() + h.ServeHTTP(rec, req) + if rec.Code != http.StatusForbidden { + t.Errorf("non-admin: status = %d, want 403", rec.Code) + } + + got := getAdminEvents(t, h, "") + if got.Events == nil { + t.Error("Events must never be nil") + } + if got.Capacity != eventRingCap { + t.Errorf("Capacity = %d, want %d", got.Capacity, eventRingCap) + } +} + +// --- limit validation --- + +func TestAdminEvents_LimitValidation(t *testing.T) { + t.Parallel() + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusOK) })) + defer srv.Close() + cfg := newEventsTestConfig(srv.URL) + 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) + } + + for _, tc := range []struct{ name, query string }{ + {"zero", "?limit=0"}, + {"negative", "?limit=-1"}, + {"over max", fmt.Sprintf("?limit=%d", adminEventsMaxLimit+1)}, + {"not a number", "?limit=lots"}, + } { + t.Run(tc.name, func(t *testing.T) { + req := httptest.NewRequest(http.MethodGet, adminEventsPath+tc.query, nil) + req.Header.Set("Authorization", "Bearer sk-admin1") + rec := httptest.NewRecorder() + h.ServeHTTP(rec, req) + if rec.Code != http.StatusBadRequest { + t.Errorf("status = %d, want 400, body=%s", rec.Code, rec.Body.String()) + } + }) + } + + got := getAdminEvents(t, h, fmt.Sprintf("?limit=%d", adminEventsMaxLimit)) + if got.Events == nil { + t.Error("Events must never be nil at the max limit") + } +} + +// --- hook 1: rate_limit / budget events via a real admission rejection --- + +func TestAdminEvents_RateLimitEvent(t *testing.T) { + t.Parallel() + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "application/json") + w.WriteHeader(http.StatusOK) + _, _ = w.Write([]byte(`{"choices":[{"message":{"role":"assistant","content":"hi"}}],"usage":{"prompt_tokens":1,"completion_tokens":1}}`)) + })) + defer srv.Close() + cfg := newEventsTestConfig(srv.URL) + cfg.Users.Inline[0].Limits = &LimitsConfig{RequestsPerMinute: 1} + 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) + } + + body := map[string]any{"model": "gpt-test", "messages": []any{map[string]any{"role": "user", "content": "hi"}}} + rec1 := httptest.NewRecorder() + h.ServeHTTP(rec1, newUnifiedRequest(t, http.MethodPost, "/v1/chat/completions", "sk-alice", body)) + if rec1.Code != http.StatusOK { + t.Fatalf("1st call: status = %d, want 200, body=%s", rec1.Code, rec1.Body.String()) + } + rec2 := httptest.NewRecorder() + h.ServeHTTP(rec2, newUnifiedRequest(t, http.MethodPost, "/v1/chat/completions", "sk-alice", body)) + if rec2.Code != http.StatusTooManyRequests { + t.Fatalf("2nd call: status = %d, want 429 (over requestsPerMinute:1), body=%s", rec2.Code, rec2.Body.String()) + } + + got := getAdminEvents(t, h, "?limit=10") + if len(got.Events) == 0 { + t.Fatal("want at least one event") + } + ev := got.Events[0] // newest first + if ev.Kind != eventKindRateLimit { + t.Errorf("Kind = %q, want %q", ev.Kind, eventKindRateLimit) + } + if ev.Route != routeChatCompletions { + t.Errorf("Route = %q, want %q", ev.Route, routeChatCompletions) + } + if ev.User != "alice" { + t.Errorf("User = %q, want %q", ev.User, "alice") + } + if ev.Status != http.StatusTooManyRequests { + t.Errorf("Status = %d, want 429", ev.Status) + } +} + +func TestAdminEvents_BudgetEvent(t *testing.T) { + t.Parallel() + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "application/json") + w.WriteHeader(http.StatusOK) + _, _ = w.Write([]byte(`{"choices":[{"message":{"role":"assistant","content":"hi"}}],"usage":{"prompt_tokens":5,"completion_tokens":5}}`)) + })) + defer srv.Close() + cfg := newEventsTestConfig(srv.URL) + cfg.Users.Inline[0].Limits = &LimitsConfig{TokensPerDay: 1} // the 1st call's own 10 reported tokens already exceeds this + 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) + } + + body := map[string]any{"model": "gpt-test", "messages": []any{map[string]any{"role": "user", "content": "hi"}}} + rec1 := httptest.NewRecorder() + h.ServeHTTP(rec1, newUnifiedRequest(t, http.MethodPost, "/v1/chat/completions", "sk-alice", body)) + if rec1.Code != http.StatusOK { + t.Fatalf("1st call: status = %d, want 200, body=%s", rec1.Code, rec1.Body.String()) + } + rec2 := httptest.NewRecorder() + h.ServeHTTP(rec2, newUnifiedRequest(t, http.MethodPost, "/v1/chat/completions", "sk-alice", body)) + if rec2.Code != http.StatusTooManyRequests { + t.Fatalf("2nd call: status = %d, want 429 (over tokensPerDay:1 budget), body=%s", rec2.Code, rec2.Body.String()) + } + + got := getAdminEvents(t, h, "?limit=10") + if len(got.Events) == 0 { + t.Fatal("want at least one event") + } + if got.Events[0].Kind != eventKindBudget { + t.Errorf("Kind = %q, want %q", got.Events[0].Kind, eventKindBudget) + } +} + +// --- hook 2: upstream event via a real 500 from the provider --- + +func TestAdminEvents_UpstreamEvent(t *testing.T) { + t.Parallel() + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.WriteHeader(http.StatusInternalServerError) + _, _ = w.Write([]byte(`{"error":"boom"}`)) + })) + defer srv.Close() + cfg := newEventsTestConfig(srv.URL) + 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) + } + + body := map[string]any{"model": "gpt-test", "messages": []any{map[string]any{"role": "user", "content": "hi"}}} + rec := httptest.NewRecorder() + h.ServeHTTP(rec, newUnifiedRequest(t, http.MethodPost, "/v1/chat/completions", "sk-alice", body)) + if rec.Code != http.StatusInternalServerError { + t.Fatalf("status = %d, want 500 (provider's own status forwarded), body=%s", rec.Code, rec.Body.String()) + } + + got := getAdminEvents(t, h, "?limit=10") + if len(got.Events) == 0 { + t.Fatal("want at least one event") + } + ev := got.Events[0] + if ev.Kind != eventKindUpstream { + t.Errorf("Kind = %q, want %q", ev.Kind, eventKindUpstream) + } + if ev.Status != http.StatusInternalServerError { + t.Errorf("Status = %d, want 500", ev.Status) + } + if ev.Provider != "openai" { + t.Errorf("Provider = %q, want %q", ev.Provider, "openai") + } + if ev.User != "alice" { + t.Errorf("User = %q, want %q", ev.User, "alice") + } +} + +// --- hook 4: unpriced event via pricingWarn --- + +func TestAdminEvents_UnpricedEvent(t *testing.T) { + // warnedModels is a process-global dedup set (pricing.go) — reset + // around this test exactly like TestGateway_PricingWarn_LogsUnderOwnInstance + // (llmgateway_test.go) does, so a prior test's own warning for the + // same model id can't suppress this one. + warnedModelsMu.Lock() + prevWarned, prevCapNotified := warnedModels, warnCapNotified + warnedModels = map[string]bool{} + warnCapNotified = false + warnedModelsMu.Unlock() + t.Cleanup(func() { + warnedModelsMu.Lock() + warnedModels, warnCapNotified = prevWarned, prevCapNotified + warnedModelsMu.Unlock() + }) + + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusOK) })) + defer srv.Close() + cfg := newEventsTestConfig(srv.URL) + 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 := h.(*Gateway) + + const model = "totally-unpriced-model-for-admin-events-test" + costMicrosKnownFor(model, usage{prompt: 1}, nil, gw.pricingWarn) + + got := getAdminEvents(t, h, "?limit=10") + if len(got.Events) == 0 { + t.Fatal("want at least one event") + } + ev := got.Events[0] + if ev.Kind != eventKindUnpriced { + t.Errorf("Kind = %q, want %q", ev.Kind, eventKindUnpriced) + } + if ev.Route != routePricing { + t.Errorf("Route = %q, want %q", ev.Route, routePricing) + } + if ev.Model != model { + t.Errorf("Model = %q, want %q", ev.Model, model) + } +} + +// --- source/degraded: local ring vs Redis-backed list --- + +// TestAdminEvents_RingFallback_NoRedisConfigured proves the local ring +// always answers, labeled source "replica", not degraded, when Redis is +// simply not configured (the common single-replica/no-Redis deployment). +func TestAdminEvents_RingFallback_NoRedisConfigured(t *testing.T) { + t.Parallel() + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusOK) })) + defer srv.Close() + cfg := newEventsTestConfig(srv.URL) + 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 := h.(*Gateway) + gw.events.ring.add(gatewayEvent{Route: routeCapacity, Kind: eventKindCapacity, Message: "seed"}) + + got := getAdminEvents(t, h, "") + if got.Source != "replica" { + t.Errorf("Source = %q, want %q", got.Source, "replica") + } + if got.Degraded { + t.Error("Degraded must be false when Redis was never configured") + } + if len(got.Events) != 1 || got.Events[0].Message != "seed" { + t.Errorf("Events = %+v, want the ring's own seeded entry", got.Events) + } +} + +// TestAdminEvents_RedisSource drives a real GET /admin/api/events against +// a scripted fake RESP server (F3, v0.3 dashboard task): the response +// carries a fixture event whose Replica ("other-pod") differs from this +// process's own — proving the multi-replica point of the feature: a +// dashboard reading through ANY replica sees every replica's events via +// the shared Redis-backed list, not just its own local ring. +func TestAdminEvents_RedisSource(t *testing.T) { + t.Parallel() + fixture := gatewayEvent{ + Time: time.Date(2026, 9, 23, 9, 0, 0, 0, time.UTC), Replica: "other-pod", Instance: "llmgw-other", + User: "bob", Route: routeChatCompletions, Kind: eventKindRateLimit, + Message: `user "bob" exceeded requests-per-minute limit (1)`, Status: http.StatusTooManyRequests, + } + payload, err := json.Marshal(fixture) + if err != nil { + t.Fatalf("marshal fixture: %v", err) + } + + ln := newFakeListener(t) + runFakeRESPServer(t, ln, []respStep{ + {wantArgs: []string{"SELECT", "0"}, reply: []byte("+OK\r\n")}, + {wantArgs: []string{"LRANGE", eventsRedisKey, "0", "49"}, reply: []byte(fmt.Sprintf("*1\r\n$%d\r\n%s\r\n", len(payload), payload))}, + }) + + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusOK) })) + defer srv.Close() + cfg := newEventsTestConfig(srv.URL) + cfg.Redis = &RedisConfig{Address: ln.Addr().String()} + 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) + } + + got := getAdminEvents(t, h, "") + if got.Source != "redis" { + t.Errorf("Source = %q, want %q", got.Source, "redis") + } + if got.Degraded { + t.Error("Degraded must be false on a successful redis read") + } + if len(got.Events) != 1 { + t.Fatalf("Events = %+v, want exactly the 1 fixture entry", got.Events) + } + if got.Events[0].Replica != "other-pod" || got.Events[0].Message != fixture.Message { + t.Errorf("Events[0] = %+v, want the fixture read back from redis", got.Events[0]) + } +} + +// TestAdminEvents_Degraded_OnLRangeError proves a Redis error reply to +// LRANGE (not just a dead connection) falls back to the local ring, +// labeled source "replica" with Degraded true — Redis IS configured, this +// particular read just failed, which is exactly what Degraded means +// (never "Redis not configured at all", eventLog.read's own doc comment). +func TestAdminEvents_Degraded_OnLRangeError(t *testing.T) { + t.Parallel() + ln := newFakeListener(t) + runFakeRESPServer(t, ln, []respStep{ + {wantArgs: []string{"SELECT", "0"}, reply: []byte("+OK\r\n")}, + {wantArgs: []string{"LRANGE", eventsRedisKey, "0", "49"}, reply: []byte("-ERR wrongtype or similar\r\n")}, + }) + + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusOK) })) + defer srv.Close() + cfg := newEventsTestConfig(srv.URL) + cfg.Redis = &RedisConfig{Address: ln.Addr().String()} + 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 := h.(*Gateway) + gw.events.ring.add(gatewayEvent{Route: routeCapacity, Kind: eventKindCapacity, Message: "local-fallback-seed"}) + + got := getAdminEvents(t, h, "") + if got.Source != "replica" { + t.Errorf("Source = %q, want %q (LRANGE errored, fall back to the local ring)", got.Source, "replica") + } + if !got.Degraded { + t.Error("Degraded must be true: redis IS configured, but this read failed") + } + if len(got.Events) != 1 || got.Events[0].Message != "local-fallback-seed" { + t.Errorf("Events = %+v, want the ring's own seeded entry", got.Events) + } +} + +// TestAdminEvents_Latched_SkipsLRANGE proves GET /admin/api/events answers +// from the local ring (source "replica", Degraded true) WITHOUT ever +// issuing LRANGE while the limiter's own store-down latch (limits.go's +// storeLatched) is open — item 3 fix (verify-dash-backend.md's lower- +// severity observation): before this fix, every admin poll during a +// store outage still paid LRANGE's own respCallTimeout before falling +// back, exactly like recordEvent already avoids paying for its own +// Redis mirror push while latched. The fake Redis server is scripted to +// answer LRANGE SUCCESSFULLY with a distinguishable fixture event, so a +// wrongly-issued LRANGE call would surface as source "redis" carrying +// that fixture — not silently indistinguishable from the correct skip, +// which also happens to report source "replica"/Degraded true. +func TestAdminEvents_Latched_SkipsLRANGE(t *testing.T) { + t.Parallel() + fixture := gatewayEvent{ + Time: time.Now(), Replica: "other-pod", Route: routeChatCompletions, Kind: eventKindRateLimit, + Message: "SHOULD-NOT-BE-SEEN: LRANGE was issued while the store was latched down", + } + payload, err := json.Marshal(fixture) + if err != nil { + t.Fatalf("marshal fixture: %v", err) + } + + ln := newFakeListener(t) + runFakeRESPServer(t, ln, []respStep{ + {wantArgs: []string{"SELECT", "0"}, reply: []byte("+OK\r\n")}, + {wantArgs: []string{"LRANGE", eventsRedisKey, "0", "49"}, reply: []byte(fmt.Sprintf("*1\r\n$%d\r\n%s\r\n", len(payload), payload))}, + }) + + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusOK) })) + defer srv.Close() + cfg := newEventsTestConfig(srv.URL) + cfg.Redis = &RedisConfig{Address: ln.Addr().String()} + 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 := h.(*Gateway) + gw.events.ring.add(gatewayEvent{Route: routeCapacity, Kind: eventKindCapacity, Message: "local-fallback-seed"}) + // Opens the SAME latch storeIncrMulti/storeGetMulti already respect + // (limits.go's own storeLatched doc comment) — recordStoreFailure is + // the real trigger a live store outage uses, not a hand-set field. + gw.limiter.recordStoreFailure(errors.New("simulated store outage for this test")) + + got := getAdminEvents(t, h, "") + if got.Source != "replica" { + t.Errorf("Source = %q, want %q (latched: LRANGE must be skipped entirely, not merely tolerated if it failed)", got.Source, "replica") + } + if !got.Degraded { + t.Error("Degraded must be true while the store is latched down") + } + if len(got.Events) != 1 || got.Events[0].Message != "local-fallback-seed" { + t.Errorf("Events = %+v, want only the ring's own seeded entry — the fixture LRANGE would have answered must never appear", got.Events) + } +} diff --git a/admin_test.go b/admin_test.go index 6c77fa9..adc09aa 100644 --- a/admin_test.go +++ b/admin_test.go @@ -93,6 +93,36 @@ func TestAdmin_Disabled_FallsThroughTo404(t *testing.T) { } } +// TestIsAdminPath covers every admin route, including adminEventsPath +// (F3, v0.3 dashboard task), plus representative non-admin paths. +func TestIsAdminPath(t *testing.T) { + t.Parallel() + cases := []struct { + path string + want bool + }{ + {adminPagePath, true}, + {adminOverviewPath, true}, + {adminUsagePath, true}, + {adminUsageHistoryPath, true}, + {adminUsageModelsPath, true}, + {adminTargetsPath, true}, + {adminEventsPath, true}, + {adminAssetsPathPrefix + "index-abc123.js", true}, + {"/v1/chat/completions", false}, + {"/admin/api/unknown", false}, + {"/adminx", false}, + {"/", false}, + } + for _, c := range cases { + t.Run(c.path, func(t *testing.T) { + if got := isAdminPath(c.path); got != c.want { + t.Errorf("isAdminPath(%q) = %v, want %v", c.path, got, c.want) + } + }) + } +} + func TestAdmin_DisabledExplicitly_FallsThroughTo404(t *testing.T) { t.Parallel() cfg := newAdminTestConfig() @@ -2452,6 +2482,8 @@ func TestAdminUsageModels_ValidatesParameters(t *testing.T) { {"limit negative", "?metric=cost&window=day&limit=-3"}, {"limit over max", "?metric=cost&window=day&limit=101"}, {"limit not a number", "?metric=cost&window=day&limit=lots"}, + // item 6, v0.3 dashboard task round 2: prefix over usageModelsPrefixMaxLen. + {"prefix over max length", "?metric=cost&window=day&prefix=" + strings.Repeat("a", usageModelsPrefixMaxLen+1)}, } { t.Run(tc.name, func(t *testing.T) { rec := httptest.NewRecorder() @@ -2463,6 +2495,104 @@ func TestAdminUsageModels_ValidatesParameters(t *testing.T) { } } +// TestAdminUsageModels_PrefixFiltersCatalog proves ?prefix= (item 6, v0.3 +// dashboard task round 2) narrows the ranking to catalog ids that start +// with it, excluding a non-zero model outside the prefix rather than +// merely deprioritizing it. +func TestAdminUsageModels_PrefixFiltersCatalog(t *testing.T) { + t.Parallel() + cfg := newAdminTestConfig() + h, gw := newAdminGatewayHandle(t, cfg) + + fixedNow := time.Date(2026, 8, 20, 12, 30, 0, 0, time.UTC) + gw.limiter.nowFn = func() time.Time { return fixedNow } + + seedModelCounter(gw, "alpha/a-model-1", metricCost, windowDay, fixedNow, 10) + seedModelCounter(gw, "alpha/a-model-2", metricCost, windowDay, fixedNow, 20) + seedModelCounter(gw, "zeta/z-model", metricCost, windowDay, fixedNow, 4_100) + + rec := httptest.NewRecorder() + h.ServeHTTP(rec, adminRequest(http.MethodGet, adminUsageModelsPath+"?metric=cost&window=day&prefix=alpha%2F", "sk-admin1")) + if rec.Code != http.StatusOK { + t.Fatalf("status = %d, want 200, body=%s", rec.Code, rec.Body.String()) + } + var got adminUsageModelsResponse + if err := json.Unmarshal(rec.Body.Bytes(), &got); err != nil { + t.Fatalf("decode: %v", err) + } + if len(got.Models) != 2 { + t.Fatalf("models = %+v, want exactly the 2 alpha/ entries", got.Models) + } + for _, m := range got.Models { + if m.ID == "zeta/z-model" { + t.Errorf("prefix=alpha/ must exclude zeta/z-model even though it is the busiest model: %+v", got.Models) + } + } +} + +// TestAdminUsageModels_PrefixAppliesBeforeLimit proves prefix narrows the +// catalog BEFORE limit caps it — limit truncates the FILTERED ranking's +// own top-N, not the unfiltered ranking's top-N re-filtered afterward, +// which would silently return fewer than limit matches (or the wrong +// ones) whenever a higher-value id outside the prefix would otherwise +// have consumed the limit's budget. +func TestAdminUsageModels_PrefixAppliesBeforeLimit(t *testing.T) { + t.Parallel() + cfg := newAdminTestConfig() + h, gw := newAdminGatewayHandle(t, cfg) + + fixedNow := time.Date(2026, 8, 20, 12, 30, 0, 0, time.UTC) + gw.limiter.nowFn = func() time.Time { return fixedNow } + + seedModelCounter(gw, "alpha/a-model-1", metricCost, windowDay, fixedNow, 10) + seedModelCounter(gw, "alpha/a-model-2", metricCost, windowDay, fixedNow, 50) + // zeta/z-model is the GLOBAL busiest model — with limit=1 and no + // prefix it would be the only entry returned (TestAdminUsageModels_ + // Limit's own case). With prefix=alpha/, it must never appear. + seedModelCounter(gw, "zeta/z-model", metricCost, windowDay, fixedNow, 999) + + rec := httptest.NewRecorder() + h.ServeHTTP(rec, adminRequest(http.MethodGet, adminUsageModelsPath+"?metric=cost&window=day&prefix=alpha%2F&limit=1", "sk-admin1")) + if rec.Code != http.StatusOK { + t.Fatalf("status = %d, want 200, body=%s", rec.Code, rec.Body.String()) + } + var got adminUsageModelsResponse + if err := json.Unmarshal(rec.Body.Bytes(), &got); err != nil { + t.Fatalf("decode: %v", err) + } + if len(got.Models) != 1 || got.Models[0].ID != "alpha/a-model-2" { + t.Errorf("models = %+v, want only alpha/a-model-2 (the busiest WITHIN the alpha/ prefix)", got.Models) + } +} + +// TestAdminUsageModels_PrefixEmptyMatchesEverything proves an absent (or +// empty) ?prefix= behaves exactly as before the parameter existed — the +// pre-item-6 unfiltered ranking, not an empty result. +func TestAdminUsageModels_PrefixEmptyMatchesEverything(t *testing.T) { + t.Parallel() + cfg := newAdminTestConfig() + h, gw := newAdminGatewayHandle(t, cfg) + + fixedNow := time.Date(2026, 8, 20, 12, 30, 0, 0, time.UTC) + gw.limiter.nowFn = func() time.Time { return fixedNow } + + seedModelCounter(gw, "alpha/a-model-1", metricCost, windowDay, fixedNow, 10) + seedModelCounter(gw, "zeta/z-model", metricCost, windowDay, fixedNow, 20) + + rec := httptest.NewRecorder() + h.ServeHTTP(rec, adminRequest(http.MethodGet, adminUsageModelsPath+"?metric=cost&window=day&prefix=", "sk-admin1")) + if rec.Code != http.StatusOK { + t.Fatalf("status = %d, want 200, body=%s", rec.Code, rec.Body.String()) + } + var got adminUsageModelsResponse + if err := json.Unmarshal(rec.Body.Bytes(), &got); err != nil { + t.Fatalf("decode: %v", err) + } + if len(got.Models) != 2 { + t.Errorf("models = %+v, want both entries (empty prefix filters nothing)", got.Models) + } +} + // TestAdminUsageModels_StoreDownIs503 pins the rule the whole feature rests // on: an unreachable store must never render as "no model was used". func TestAdminUsageModels_StoreDownIs503(t *testing.T) { @@ -2478,6 +2608,263 @@ func TestAdminUsageModels_StoreDownIs503(t *testing.T) { } } +// --- usage/models: span (F2, v0.3 dashboard task) --- + +// TestAdminUsageModels_SpanDefaultIsCurrentBucket proves an absent +// ?span= behaves exactly as before span existed: only today's own bucket +// counts, and the response echoes Span=1. +func TestAdminUsageModels_SpanDefaultIsCurrentBucket(t *testing.T) { + t.Parallel() + cfg := newAdminTestConfig() + h, gw := newAdminGatewayHandle(t, cfg) + + fixedNow := time.Date(2026, 8, 20, 12, 30, 0, 0, time.UTC) + gw.limiter.nowFn = func() time.Time { return fixedNow } + + seedModelCounter(gw, "alpha/a-model-1", metricReq, windowDay, fixedNow, 5) + // Yesterday's traffic must NOT count without an explicit ?span=. + gw.limiter.incrCounter(kindModel, "alpha/a-model-1", metricReq, windowDay, historyStepBack(fixedNow, windowDay, 1), 100, dayWindowTTL) + + rec := httptest.NewRecorder() + h.ServeHTTP(rec, adminRequest(http.MethodGet, adminUsageModelsPath+"?metric=req&window=day", "sk-admin1")) + if rec.Code != http.StatusOK { + t.Fatalf("status = %d, want 200, body=%s", rec.Code, rec.Body.String()) + } + var got adminUsageModelsResponse + if err := json.Unmarshal(rec.Body.Bytes(), &got); err != nil { + t.Fatalf("decode: %v", err) + } + if got.Span != 1 { + t.Errorf("Span = %d, want 1 (default)", got.Span) + } + if len(got.Models) != 1 || got.Models[0].Value != 5 { + t.Errorf("models = %+v, want only today's own bucket (5), not yesterday's 100 too", got.Models) + } +} + +// TestAdminUsageModels_SpanSumsPastBuckets proves ?span=N actually sums +// N buckets ending at now, using the SAME seeded-yesterday traffic +// TestAdminUsageModels_SpanDefaultIsCurrentBucket proved span=1 excludes. +func TestAdminUsageModels_SpanSumsPastBuckets(t *testing.T) { + t.Parallel() + cfg := newAdminTestConfig() + h, gw := newAdminGatewayHandle(t, cfg) + + fixedNow := time.Date(2026, 8, 20, 12, 30, 0, 0, time.UTC) + gw.limiter.nowFn = func() time.Time { return fixedNow } + + seedModelCounter(gw, "alpha/a-model-1", metricReq, windowDay, fixedNow, 5) + gw.limiter.incrCounter(kindModel, "alpha/a-model-1", metricReq, windowDay, historyStepBack(fixedNow, windowDay, 1), 100, dayWindowTTL) + + rec := httptest.NewRecorder() + h.ServeHTTP(rec, adminRequest(http.MethodGet, adminUsageModelsPath+"?metric=req&window=day&span=2", "sk-admin1")) + if rec.Code != http.StatusOK { + t.Fatalf("status = %d, want 200, body=%s", rec.Code, rec.Body.String()) + } + var got adminUsageModelsResponse + if err := json.Unmarshal(rec.Body.Bytes(), &got); err != nil { + t.Fatalf("decode: %v", err) + } + if got.Span != 2 { + t.Errorf("Span = %d, want 2", got.Span) + } + if len(got.Models) != 1 || got.Models[0].Value != 105 { + t.Errorf("models = %+v, want [alpha/a-model-1: 105] (5 today + 100 yesterday)", got.Models) + } +} + +// TestAdminUsageModels_SpanBounds covers the validation range: 0 and +// window's max+1 are both 400, a non-integer is 400, and window's own +// max (historyMaxSpan) is accepted. +func TestAdminUsageModels_SpanBounds(t *testing.T) { + t.Parallel() + cfg := newAdminTestConfig() + h, _ := newAdminGatewayHandle(t, cfg) + + for _, tc := range []struct{ name, query string }{ + {"span zero", "?metric=cost&window=day&span=0"}, + {"span negative", "?metric=cost&window=day&span=-1"}, + {"span over max", fmt.Sprintf("?metric=cost&window=day&span=%d", historyMaxSpan(windowDay)+1)}, + {"span not a number", "?metric=cost&window=day&span=lots"}, + } { + t.Run(tc.name, func(t *testing.T) { + rec := httptest.NewRecorder() + h.ServeHTTP(rec, adminRequest(http.MethodGet, adminUsageModelsPath+tc.query, "sk-admin1")) + if rec.Code != http.StatusBadRequest { + t.Errorf("status = %d, want 400, body=%s", rec.Code, rec.Body.String()) + } + }) + } + + rec := httptest.NewRecorder() + h.ServeHTTP(rec, adminRequest(http.MethodGet, fmt.Sprintf("%s?metric=cost&window=day&span=%d", adminUsageModelsPath, historyMaxSpan(windowDay)), "sk-admin1")) + if rec.Code != http.StatusOK { + t.Fatalf("status = %d, want 200 for span at window's own max, body=%s", rec.Code, rec.Body.String()) + } + var got adminUsageModelsResponse + if err := json.Unmarshal(rec.Body.Bytes(), &got); err != nil { + t.Fatalf("decode: %v", err) + } + if got.Span != historyMaxSpan(windowDay) { + t.Errorf("Span = %d, want %d", got.Span, historyMaxSpan(windowDay)) + } +} + +// TestAdminUsageModels_SpanStoreDownIs503 is TestAdminUsageModels_StoreDownIs503's +// own span-path counterpart: an unreachable store must answer 503 through +// chunkedModelSpanTotals too, not just modelTotals' own span=1 path. +func TestAdminUsageModels_SpanStoreDownIs503(t *testing.T) { + t.Parallel() + cfg := newAdminTestConfig() + h, gw := newAdminGatewayHandle(t, cfg) + gw.limiter = newLimiter(alwaysErrStore{}, false) + + rec := httptest.NewRecorder() + h.ServeHTTP(rec, adminRequest(http.MethodGet, adminUsageModelsPath+"?metric=cost&window=day&span=5", "sk-admin1")) + if rec.Code != http.StatusServiceUnavailable { + t.Fatalf("status = %d, want 503, body=%s", rec.Code, rec.Body.String()) + } +} + +// TestChunkedModelSpanTotals_SplitsIntoMultipleRoundTrips is F2 (v0.3 +// dashboard task): a span-multiplied catalog read stays chunked to at +// most usageModelsChunkKeys keys per storeGetMulti round trip, mirroring +// TestChunkedCurrentUsage_SplitsIntoMultipleRoundTrips' own multi-round- +// trip discipline (above), sized for span instead of the fixed +// usageKeysPerScope stride. wantCalls is derived from the SAME +// perChunk/ceil-division formula chunkedModelSpanTotals itself applies, +// so this asserts the real chunk boundary, not a hand-picked number. +func TestChunkedModelSpanTotals_SplitsIntoMultipleRoundTrips(t *testing.T) { + t.Parallel() + fixedNow := time.Date(2026, 9, 23, 10, 0, 0, 0, time.UTC) + const n = 400 + const span = 24 + + store := &countingMultiStore{values: make(map[string]int64, n)} + ids := make([]string, n) + for i := 0; i < n; i++ { + ids[i] = fmt.Sprintf("provider/model-%d", i) + // Only today's own bucket is seeded, so each id's span sum is + // exactly its own index i — a direct probe of ordering. + store.values[windowKey(kindModel, ids[i], metricReq, windowDay, fixedNow)] = int64(i) + } + + l := newLimiter(store, true) + l.nowFn = func() time.Time { return fixedNow } + gw := &Gateway{limiter: l} + + got, ok := gw.chunkedModelSpanTotals(ids, metricReq, windowDay, fixedNow, span) + if !ok { + t.Fatal("want ok=true") + } + if len(got) != n { + t.Fatalf("len(got) = %d, want %d", len(got), n) + } + + perChunk := usageModelsChunkKeys / span + wantCalls := (n + perChunk - 1) / perChunk + if store.getMultiCalls != wantCalls { + t.Errorf("getMultiCalls = %d, want %d (%d ids, %d ids/chunk, each chunk <= %d keys)", store.getMultiCalls, wantCalls, n, perChunk, usageModelsChunkKeys) + } + // Order preserved across the chunk boundary. + if got[perChunk] != int64(perChunk) { + t.Errorf("got[%d] = %d, want %d (order preserved across the chunk boundary)", perChunk, got[perChunk], perChunk) + } + if got[n-1] != int64(n-1) { + t.Errorf("got[%d] = %d, want %d", n-1, got[n-1], n-1) + } +} + +// --- usage: rejectionsPerDay (F4, v0.3 dashboard task) --- + +// TestAdminUsage_RejectionsPerDayField proves rejectionsPerDay is +// fleet-wide: a rejection recorded by one replica's own limiter (sharing +// the same underlying counterStore) is visible through GET +// /admin/api/usage served by a DIFFERENT limiter/replica reading the +// identical store — the rej:day key checkAndCount/settleRejection write +// to depends only on (kind, id), never on which *limiter instance wrote +// it. +func TestAdminUsage_RejectionsPerDayField(t *testing.T) { + t.Parallel() + fixedNow := time.Date(2026, 9, 23, 9, 0, 0, 0, time.UTC) + shared := newMemoryStore() + + replicaA := newLimiter(shared, true) + replicaA.nowFn = func() time.Time { return fixedNow } + scopes := withTotalScope([]limitScope{{kind: "user", id: "alice", limits: &LimitsConfig{RequestsPerMinute: 1}}}) + if v := replicaA.checkAndCount(scopes); v != nil { + t.Fatalf("1st call should pass, got %+v", v) + } + if v := replicaA.checkAndCount(scopes); v == nil { + t.Fatal("2nd call should violate alice's requestsPerMinute:1") + } + + cfg := newAdminTestConfig() + h, gw := newAdminGatewayHandle(t, cfg) + replicaB := newLimiter(shared, true) + replicaB.nowFn = func() time.Time { return fixedNow } + gw.limiter = replicaB + + rec := httptest.NewRecorder() + h.ServeHTTP(rec, adminRequest(http.MethodGet, adminUsagePath, "sk-admin1")) + if rec.Code != http.StatusOK { + t.Fatalf("status = %d, want 200, body=%s", rec.Code, rec.Body.String()) + } + var got adminUsageResponse + if err := json.Unmarshal(rec.Body.Bytes(), &got); err != nil { + t.Fatalf("decode: %v", err) + } + var alice *adminUsageEntryView + for i := range got.Users { + if got.Users[i].ID == "alice" { + alice = &got.Users[i] + } + } + if alice == nil { + t.Fatalf("alice not found in users: %+v", got.Users) + } + if alice.RejectionsPerDay != 1 { + t.Errorf("alice.RejectionsPerDay = %d, want 1", alice.RejectionsPerDay) + } + if got.Total.RejectionsPerDay != 1 { + t.Errorf("total.RejectionsPerDay = %d, want 1 (Q6: rejections attributed to total/all too)", got.Total.RejectionsPerDay) + } +} + +// --- overview: replica/instance/warnings (F4/F9/F10, v0.3 dashboard task) --- + +// TestAdminOverview_Replica proves the overview response carries a +// non-empty Replica identical to g.replica, Instance echoing the +// middleware instance name New(...) was given, and a never-nil Warnings +// slice. +func TestAdminOverview_Replica(t *testing.T) { + t.Parallel() + cfg := newAdminTestConfig() + h, gw := newAdminGatewayHandle(t, cfg) + + rec := httptest.NewRecorder() + h.ServeHTTP(rec, adminRequest(http.MethodGet, adminOverviewPath, "sk-admin1")) + if rec.Code != http.StatusOK { + t.Fatalf("status = %d, want 200, body=%s", rec.Code, rec.Body.String()) + } + var got adminOverviewResponse + if err := json.Unmarshal(rec.Body.Bytes(), &got); err != nil { + t.Fatalf("decode: %v", err) + } + if got.Replica == "" { + t.Error("Replica must not be empty") + } + if got.Replica != gw.replica { + t.Errorf("Replica = %q, want %q (g.replica)", got.Replica, gw.replica) + } + if got.Instance != "llmgw" { + t.Errorf("Instance = %q, want %q (the New(...) instance name)", got.Instance, "llmgw") + } + if got.Warnings == nil { + t.Error("Warnings must never be nil") + } +} + // --- usage/history: the model scope --- // TestAdminUsageHistory_ModelScope drives a model through the SAME history diff --git a/events.go b/events.go new file mode 100644 index 0000000..71142ba --- /dev/null +++ b/events.go @@ -0,0 +1,483 @@ +package traefikllmgateway + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "net/http" + "strconv" + "sync" + "time" +) + +// Event kind vocabulary GET /admin/api/events' gatewayEvent.Kind field +// takes (F3, v0.3 dashboard task) — every hook below sets exactly one of +// these. eventRingCap bounds both the local eventRing's capacity and the +// Redis-backed list's own LTRIM cap (Q2, coordinator decision: "no +// expiry, bounded by LTRIM to 200 entries" — no separate TTL, the list is +// self-bounding by size alone). eventsRedisKey is that Redis list's key. +// eventPushPerSecond is the per-replica push-rate cap (Q3: "push throttle +// 50/s/replica: accepted") — the local ring is never throttled, only the +// best-effort Redis mirror. adminEventsDefaultLimit/adminEventsMaxLimit +// bound GET /admin/api/events' own "limit" query parameter, mirroring +// parseUsageModelsLimit's own default/max pair (admin.go). +const ( + eventKindRateLimit = "rate_limit" + eventKindBudget = "budget" + eventKindStoreDown = "store_down" + eventKindUpstream = "upstream" + eventKindTimeout = "timeout" + eventKindUnpriced = "unpriced" + eventKindCapacity = "capacity" + + eventRingCap = 200 + eventsRedisKey = "llmgw:events" + eventPushPerSecond = 50 + + adminEventsPath = "/admin/api/events" + adminEventsDefaultLimit = 50 + adminEventsMaxLimit = eventRingCap +) + +// Route vocabulary gatewayEvent.Route takes (plan §1.4): one fixed string +// per metered entry point, independent of cacheKey's own cacheEndpoint* +// constants (cache.go), which exist for a different purpose (collision +// avoidance between differently-shaped cache keys) and must never be +// repurposed here. targetKindMCP/targetKindAgent (mcp_a2a.go) already +// equal "mcp"/"a2a" and are used directly at their own call site rather +// than duplicated as a second pair of constants here. +const ( + routeChatCompletions = "chat/completions" + routeEmbeddings = "embeddings" + routeMessages = "messages" + routeImages = "images" + routeAudioSpeech = "audio/speech" + routeAudioTranscriptions = "audio/transcriptions" + routePassthrough = "passthrough" + routeMCPFederated = "mcp-federated" + routePricing = "pricing" + // routeCapacity is NOT part of plan §1.4's route vocabulary: the + // capacity hook (acquireBodyAdmission, routes_unified.go) is a + // route-agnostic shared semaphore shared with routes_messages.go + // (unowned this round — see acquireBodyAdmission's own doc comment), + // so it cannot cheaply name which endpoint hit capacity without a + // signature change that would ripple into that unowned file. This + // fixed value is the documented, deliberate simplification. + routeCapacity = "capacity" +) + +// eventRouteForEndpoint maps runMeteredCall's own endpoint argument +// (cacheEndpointChat/cacheEndpointEmbeddings/cacheEndpointMessages, +// cache.go/routes_messages.go) to the Route vocabulary above. +// cacheEndpointEmbeddings/cacheEndpointMessages already equal +// "embeddings"/"messages" verbatim; only cacheEndpointChat ("chat") needs +// remapping to "chat/completions". +func eventRouteForEndpoint(endpoint string) string { + if endpoint == cacheEndpointChat { + return routeChatCompletions + } + return endpoint +} + +// gatewayEvent is one entry in GET /admin/api/events' feed — the exact +// shape stored as JSON in both the local ring and the Redis-backed list, +// so read (below) can unmarshal a Redis entry straight into this type +// with no translation step. Route values are the vocabulary above; Kind +// is the eventKind* vocabulary; User/Group/Model/Provider/Instance/Status +// are omitted when not applicable to the hook that recorded this event. +// +// Risk (plan §6): Message is always either a fixed string or +// sanitizeProviderErr's scrubbed output — never a raw response body, +// header, or key. Every hook below is written to that constraint; see +// events_test.go's own credential-scrubbing assertion. +type gatewayEvent struct { + Time time.Time `json:"time"` + Replica string `json:"replica"` + Instance string `json:"instance,omitempty"` + User string `json:"user,omitempty"` + Group string `json:"group,omitempty"` + Model string `json:"model,omitempty"` + Provider string `json:"provider,omitempty"` + Route string `json:"route"` + Kind string `json:"kind"` + Message string `json:"message"` + Status int `json:"status,omitempty"` +} + +// adminEventsResponse is the full body of GET /admin/api/events. +type adminEventsResponse struct { + Source string `json:"source"` + Replica string `json:"replica"` + Events []gatewayEvent `json:"events"` + Capacity int `json:"capacity"` + Degraded bool `json:"degraded,omitempty"` +} + +// eventRing is a fixed-capacity, newest-overwrites-oldest ring buffer of +// gatewayEvent — this process's own local fallback event feed (F3, v0.3 +// dashboard task), always able to answer GET /admin/api/events even when +// Redis is absent or unreachable (fail-open: recordEvent's own doc +// comment). Guarded by mu: add runs on every metered request's error +// path, snapshot on every admin poll — both must be safe for concurrent +// use across goroutines. +type eventRing struct { + buf [eventRingCap]gatewayEvent + mu sync.Mutex + next int // index the NEXT add writes to + n int // number of valid entries so far, capped at eventRingCap +} + +// add appends ev, overwriting the oldest entry once the ring is full. +func (r *eventRing) add(ev gatewayEvent) { + r.mu.Lock() + defer r.mu.Unlock() + r.buf[r.next] = ev + r.next = (r.next + 1) % eventRingCap + if r.n < eventRingCap { + r.n++ + } +} + +// snapshot returns up to limit of the ring's most recently added entries, +// newest first, as a fresh copy the caller may retain or mutate freely — +// never sharing the ring's own backing array. +func (r *eventRing) snapshot(limit int) []gatewayEvent { + r.mu.Lock() + defer r.mu.Unlock() + n := r.n + if limit < n { + n = limit + } + out := make([]gatewayEvent, n) + for i := 0; i < n; i++ { + idx := (r.next - 1 - i + eventRingCap) % eventRingCap + out[i] = r.buf[idx] + } + return out +} + +// eventLog is the Gateway-level owner of the event feed: the local ring +// (always answers) plus a best-effort mirror of every event onto a +// Redis-backed capped list, so a dashboard reading through ANY replica in +// a multi-instance deployment sees every replica's events, not just its +// own. Built once in newGateway, after g.redisClient/g.limiter — client +// is the SAME shared respClient the limiter's redisStore uses (spec §2's +// "one connection, one config"), and storeLatched (recordEvent) borrows +// the limiter's own store-health latch rather than maintaining a second, +// independent one for the identical underlying connection. +type eventLog struct { + ring *eventRing + client *respClient // nil when Redis is not configured + replica string + instance string + nowFn func() time.Time + spawn func(func()) + logf func(format string, args ...any) + logGate logGate + + throttleMu sync.Mutex + throttleSecond int64 // unix second of the current push-rate window + throttleCount int // pushes already spawned within throttleSecond +} + +// allowPush reports whether one more Redis push may be spawned this +// second, enforcing eventPushPerSecond (Q3, coordinator ruling: "push +// throttle 50/s/replica: accepted") — a construction-warning storm or a +// sustained rejection flood must never turn recordEvent's best-effort +// Redis mirror into an unbounded write amplifier against the shared +// store. The local ring (recordEvent's own fail-open path) is never +// throttled: every event always lands there regardless of this limit. +func (el *eventLog) allowPush(now time.Time) bool { + sec := now.Unix() + el.throttleMu.Lock() + defer el.throttleMu.Unlock() + if sec != el.throttleSecond { + el.throttleSecond = sec + el.throttleCount = 0 + } + if el.throttleCount >= eventPushPerSecond { + return false + } + el.throttleCount++ + return true +} + +// push mirrors ev to Redis's capped event list in one pipelined round +// trip: LPUSH the newest entry, LTRIM to eventRingCap-1 immediately after +// — never a separate call, so the list can never be observed to grow +// past eventRingCap between the two. Runs inside el.spawn's own goroutine +// (recordEvent's own doc comment), off the request's hot path. Its own +// failure is logged through el.logGate (rate-limited, mirroring +// limiter.logStoreError's identical shape) and NEVER calls +// limiter.recordStoreFailure — a lost event mirror is not a limit-store +// outage and must not open the limiter's fail-open/fail-closed latch for +// unrelated request traffic. +func (el *eventLog) push(ev gatewayEvent) { + payload, err := json.Marshal(ev) + if err != nil { + return // a gatewayEvent literal always marshals; defensive only + } + _, err = el.client.pipeline([][]string{ + {"LPUSH", eventsRedisKey, string(payload)}, + {"LTRIM", eventsRedisKey, "0", strconv.Itoa(eventRingCap - 1)}, + }) + if err != nil { + if log, suppressed := el.logGate.shouldLog(el.nowFn()); log { + // Yaegi trap (limiter.logf's own doc comment, limits.go): a + // struct field of variadic func type crashes Yaegi v0.16.1's + // CFG builder past ONE variadic argument. el.logf is exactly + // such a field, so the message is pre-formatted here and + // passed through as the single variadic argument, mirroring + // limits.go's own l.logf("%s", fmt.Sprintf(...)) pattern. + el.logf("%s", fmt.Sprintf("events: push to redis failed%s: %v", suppressedSuffix(suppressed), err)) + } + } +} + +// read answers GET /admin/api/events: up to limit events from the +// Redis-backed list when el has a configured, reachable client (source +// "redis"), or this replica's own local ring otherwise (source +// "replica"). degraded is true only when a store IS configured but this +// particular read failed — never for "Redis not configured at all", which +// is expected, ordinary operation for a single-replica or Redis-less +// deployment, not degradation. +// +// storeLatched is the limiter's own storeLatched() (limits.go), passed in +// by the caller (serveAdminEvents, admin.go) rather than read from a +// stored reference here — mirrors recordEvent's identical check, just +// evaluated by the caller instead of el itself. While latched, LRANGE is +// SKIPPED, not attempted: recordEvent already skips the Redis mirror +// push for the same reason (its own doc comment), so an LRANGE issued +// here would fail identically, just after paying respCallTimeout to find +// out — on every admin poll, for the whole latch window. Going straight +// to the ring is the same "store IS configured but this particular read +// failed" outcome a failed LRANGE already produces below (source +// "replica", degraded true), at zero network cost. +func (el *eventLog) read(limit int, storeLatched bool) (events []gatewayEvent, source string, degraded bool) { + if el == nil { + return []gatewayEvent{}, "replica", false + } + if el.client == nil { + return el.ring.snapshot(limit), "replica", false + } + if storeLatched { + return el.ring.snapshot(limit), "replica", true + } + reply, err := el.client.do("LRANGE", eventsRedisKey, "0", strconv.Itoa(limit-1)) + if err != nil { + return el.ring.snapshot(limit), "replica", true + } + arr, ok := reply.([]any) + if !ok { + return el.ring.snapshot(limit), "replica", true + } + out := make([]gatewayEvent, 0, len(arr)) + for _, item := range arr { + b, ok := item.([]byte) + if !ok { + continue // a malformed or error-typed entry — skip it, never fail the whole read for one bad element + } + var ev gatewayEvent + if json.Unmarshal(b, &ev) != nil { + continue + } + out = append(out, ev) + } + return out, "redis", false +} + +// recordEvent stamps ev's Time/Replica/Instance, appends it to the local +// ring unconditionally — fail-open: the ring always answers GET +// /admin/api/events regardless of Redis — and, only when a store is +// configured, currently reachable (per the limiter's own storeLatched), +// and the push-rate throttle allows it, mirrors ev to Redis via el.spawn, +// off the request's own hot path — exactly like recordProviderAttempt's +// identical telemetry-only spawn (limits.go). Every call site below is on +// an ERROR path only; a successful request never reaches here, so this +// costs nothing on the hot path. +func (g *Gateway) recordEvent(ev gatewayEvent) { + el := g.events + if el == nil { + return + } + ev.Time = el.nowFn() + ev.Replica = el.replica + ev.Instance = el.instance + el.ring.add(ev) + + if el.client == nil || g.limiter.storeLatched() || !el.allowPush(ev.Time) { + return + } + el.spawn(func() { el.push(ev) }) +} + +// applyScopeAttribution sets ev.User/ev.Group from the first "user"/ +// "group"-kind scope in scopes (buildLimitScopes' own user-then-group +// order) — shared by every F3 hook below that records an event alongside +// a limitScope slice. +func applyScopeAttribution(ev *gatewayEvent, scopes []limitScope) { + for _, sc := range scopes { + switch sc.kind { + case "user": + if ev.User == "" { + ev.User = sc.id + } + case "group": + if ev.Group == "" { + ev.Group = sc.id + } + } + } +} + +// recordLimitEvent records a rate_limit/budget/store_down event for a +// checkAndCount rejection (F3 hook 1) — scopes is the SAME slice +// checkAndCount was called with, so applyScopeAttribution finds the +// caller's own User/Group; v.kind/v.message/v.storeDown (limits.go) +// already carry everything else. Status mirrors +// writeLimitViolationEnvelope's own HTTP mapping (routes_unified.go): +// 503 for a store-down violation, 429 otherwise. +func (g *Gateway) recordLimitEvent(scopes []limitScope, route string, v *limitViolation) { + status := http.StatusTooManyRequests + if v.storeDown { + status = http.StatusServiceUnavailable + } + ev := gatewayEvent{Route: route, Kind: v.kind, Message: v.message, Status: status} + applyScopeAttribution(&ev, scopes) + g.recordEvent(ev) +} + +// providerBaseURL returns name's configured base URL from the current +// registry snapshot, or "" when no provider by that name is configured — +// recordUpstreamEvent's own lookup for sanitizeProviderErr (admin.go), +// which needs the RAW base URL to scrub, not just the provider's name. +// Error-path only (never called from a successful request), so the +// linear scan over the small, operator-configured provider list costs +// nothing hot-path-relevant. +func (g *Gateway) providerBaseURL(name string) string { + for _, s := range g.registry.snapshot() { + if s.name == name { + return s.baseURL + } + } + return "" +} + +// recordUpstreamEvent classifies err — an adapter or failover-loop +// failure, from a runMeteredCall/routes_media.go call site — into a +// timeout/upstream event and records it, or records nothing for an error +// class the dashboard has no use for (F3 hook 2): +// +// - matchesSentinel(err, errProviderTimeout) or isDeadlineExceeded: +// eventKindTimeout, HTTP 504. +// - *providerHTTPError: eventKindUpstream at the provider's own status, +// but ONLY when that status is 429 or >=500 — an ordinary 4xx is the +// CLIENT's own request being rejected, not a provider/gateway +// problem worth surfacing here. +// - *translateError or context.Canceled: no event — neither says +// anything about upstream health. +// - anything else: eventKindUpstream, HTTP 502, message scrubbed via +// sanitizeProviderErr (never the raw err text unscrubbed). +// +// model is the canonical "provider/model" id being attempted; provider is +// the provider's own configured name. +func (g *Gateway) recordUpstreamEvent(scopes []limitScope, model, provider, route string, err error) { + if err == nil || errors.Is(err, context.Canceled) { + return + } + if _, ok := err.(*translateError); ok { + return + } + + // ev's fields are set ONE AT A TIME below, never through a single + // "kind, status, message = a, b, c()" tuple assignment (the shape + // this switch used before this fix): yaegi v0.16.1 silently keeps + // only the LAST value of a tuple assignment whose right-hand side + // mixes a plain expression with a function/method call — every + // earlier target is left at its zero value, with no panic and no + // compile error, so a compiled `go test` run can never catch it + // (verify-dash-backend.md's probe against scratchpad/yrepro is what + // did: kind/status stayed "" and 0 for every upstream and timeout + // event recorded under the real interpreter). This is a DIFFERENT + // symptom from the multi-value-assignment trap translate_gemini.go's + // hasMaxTokens comment documents (mixing a variable and a literal + // there panics outright); this one fails silently, which is why every + // assignment below — and every other tuple assignment introduced in + // this round — is written as separate statements instead. + // + // The timeout branch also now runs through sanitizeProviderErr, like + // the generic branch below: a watchdog or context-deadline error can + // embed the same dialed URL (and any credentials/query on it) a + // generic connection error does, and only the generic branch used to + // scrub it. + ev := gatewayEvent{Model: model, Provider: provider, Route: route} + switch { + case matchesSentinel(err, errProviderTimeout) || isDeadlineExceeded(err): + ev.Kind = eventKindTimeout + ev.Status = http.StatusGatewayTimeout + ev.Message = sanitizeProviderErr(err.Error(), g.providerBaseURL(provider)) + default: + if perr, ok := err.(*providerHTTPError); ok { + if perr.status != http.StatusTooManyRequests && perr.status < http.StatusInternalServerError { + return + } + ev.Kind = eventKindUpstream + ev.Status = perr.status + ev.Message = perr.Error() + } else { + ev.Kind = eventKindUpstream + ev.Status = http.StatusBadGateway + ev.Message = sanitizeProviderErr(err.Error(), g.providerBaseURL(provider)) + } + } + + applyScopeAttribution(&ev, scopes) + g.recordEvent(ev) +} + +// recordUnpricedRefusalEvent records the 402 "no configured price, and a +// cost budget applies" refusal (F3 hook 5, item 5 this round) shared by +// routes_unified.go's own F-1 gate and routes_passthrough.go's identical +// guard (review-routes.md, finding 6) — the one place in each file that +// refuses the request outright rather than billing it 0. Reuses +// eventKindUnpriced, the SAME kind hook 4 (pricingWarn, logger.go) +// already records for the "billed 0" case; Status is what tells the two +// apart in the feed (402 here, unset/0 there — a billed-0 event carries +// no HTTP status of its own, since nothing was refused). +func (g *Gateway) recordUnpricedRefusalEvent(scopes []limitScope, model, provider, route string) { + ev := gatewayEvent{ + Model: model, Provider: provider, Route: route, Kind: eventKindUnpriced, Status: http.StatusPaymentRequired, + Message: fmt.Sprintf("model %q refused: no configured price, so the cost budget that applies to this caller cannot be enforced", model), + } + applyScopeAttribution(&ev, scopes) + g.recordEvent(ev) +} + +// recordProxyEvent records an upstream event for a proxyUpstream result +// that failed at 429/>=500, or never produced any response at all +// (result.status == 0) — F3 hook 3 (routes_passthrough.go's +// handlePassthrough, mcp_a2a.go's handleTargetProxy). Unlike +// recordUpstreamEvent (hook 2), proxyUpstream reports only a status code, +// not the underlying error (already logged at its own call site) — there +// is nothing for sanitizeProviderErr to scrub here, so the message is a +// fixed, route-scoped string, never upstream body/header/key content. A +// client-canceled result records nothing, matching hook 2's identical +// context.Canceled exclusion. +func (g *Gateway) recordProxyEvent(scopes []limitScope, provider, route string, result proxyResult) { + if result.clientCanceled { + return + } + if result.status != 0 && result.status != http.StatusTooManyRequests && result.status < http.StatusInternalServerError { + return + } + status := result.status + message := fmt.Sprintf("%s upstream returned status %d", route, result.status) + if status == 0 { + status = http.StatusBadGateway + message = "upstream connection error" + } + ev := gatewayEvent{Provider: provider, Route: route, Kind: eventKindUpstream, Message: message, Status: status} + applyScopeAttribution(&ev, scopes) + g.recordEvent(ev) +} diff --git a/events_test.go b/events_test.go new file mode 100644 index 0000000..8f99f51 --- /dev/null +++ b/events_test.go @@ -0,0 +1,357 @@ +package traefikllmgateway + +import ( + "context" + "encoding/json" + "errors" + "fmt" + "net/http" + "net/url" + "strings" + "testing" + "time" +) + +// --- eventRing: cap, order, copy semantics --- + +// TestEventRing_AddSnapshot_OrderAndCap proves add overwrites the oldest +// entry once the ring exceeds eventRingCap, and snapshot returns the +// survivors newest-first. +func TestEventRing_AddSnapshot_OrderAndCap(t *testing.T) { + r := &eventRing{} + const total = eventRingCap + 10 + for i := 0; i < total; i++ { + r.add(gatewayEvent{Message: fmt.Sprintf("event-%d", i)}) + } + + got := r.snapshot(eventRingCap) + if len(got) != eventRingCap { + t.Fatalf("len(got) = %d, want %d", len(got), eventRingCap) + } + if want := fmt.Sprintf("event-%d", total-1); got[0].Message != want { + t.Errorf("got[0] = %q, want %q (newest first)", got[0].Message, want) + } + if want := fmt.Sprintf("event-%d", total-eventRingCap); got[len(got)-1].Message != want { + t.Errorf("got[last] = %q, want %q (oldest surviving entry after the first 10 were overwritten)", got[len(got)-1].Message, want) + } +} + +// TestEventRing_Snapshot_LimitTruncates proves limit caps how many of the +// most recent entries snapshot returns, still newest-first. +func TestEventRing_Snapshot_LimitTruncates(t *testing.T) { + r := &eventRing{} + for i := 0; i < 10; i++ { + r.add(gatewayEvent{Message: fmt.Sprintf("e%d", i)}) + } + got := r.snapshot(3) + if len(got) != 3 { + t.Fatalf("len(got) = %d, want 3", len(got)) + } + want := []string{"e9", "e8", "e7"} + for i, w := range want { + if got[i].Message != w { + t.Errorf("got[%d] = %q, want %q", i, got[i].Message, w) + } + } +} + +// TestEventRing_Snapshot_ReturnsFreshCopy proves a caller mutating its own +// snapshot slice never corrupts the ring's own backing array. +func TestEventRing_Snapshot_ReturnsFreshCopy(t *testing.T) { + r := &eventRing{} + r.add(gatewayEvent{Message: "orig"}) + + got := r.snapshot(1) + got[0].Message = "mutated" + + again := r.snapshot(1) + if again[0].Message != "orig" { + t.Errorf("snapshot()[0].Message = %q after an external mutation, want %q (snapshot must copy)", again[0].Message, "orig") + } +} + +// TestEventRing_Snapshot_Empty proves an empty ring answers a limit +// request with an empty, non-panicking slice. +func TestEventRing_Snapshot_Empty(t *testing.T) { + r := &eventRing{} + got := r.snapshot(50) + if len(got) != 0 { + t.Errorf("len(got) = %d, want 0", len(got)) + } +} + +// --- eventLog: push-rate throttle (Q3: 50/s/replica) --- + +// TestEventLog_AllowPush_ThrottledAt50PerSecond proves eventPushPerSecond +// pushes are allowed within one second, the next is throttled, and a new +// second resets the window. +func TestEventLog_AllowPush_ThrottledAt50PerSecond(t *testing.T) { + el := &eventLog{} + now := time.Date(2026, 9, 23, 9, 0, 0, 0, time.UTC) + + for i := 0; i < eventPushPerSecond; i++ { + if !el.allowPush(now) { + t.Fatalf("push %d within the same second should be allowed", i) + } + } + if el.allowPush(now) { + t.Error("a push beyond eventPushPerSecond within the same second must be throttled") + } + if !el.allowPush(now.Add(time.Second)) { + t.Error("a new second must reset the throttle window") + } +} + +// --- gatewayEvent: JSON round trip (Redis storage shape == API shape) --- + +// TestGatewayEvent_JSONRoundTrip proves every field survives a +// marshal/unmarshal cycle unchanged — the exact contract eventLog.push/ +// read depend on (the stored Redis payload IS the API view, with no +// translation step). +func TestGatewayEvent_JSONRoundTrip(t *testing.T) { + ev := gatewayEvent{ + Time: time.Date(2026, 9, 23, 9, 0, 0, 0, time.UTC), + Replica: "pod-1", + Instance: "llmgw", + User: "alice", + Group: "eng", + Model: "openai/gpt-4o", + Provider: "openai", + Route: routeChatCompletions, + Kind: eventKindUpstream, + Message: "upstream connection error", + Status: http.StatusBadGateway, + } + b, err := json.Marshal(ev) + if err != nil { + t.Fatalf("Marshal: %v", err) + } + var got gatewayEvent + if unmarshalErr := json.Unmarshal(b, &got); unmarshalErr != nil { + t.Fatalf("Unmarshal: %v", unmarshalErr) + } + gotB, err := json.Marshal(got) + if err != nil { + t.Fatalf("re-Marshal: %v", err) + } + if string(gotB) != string(b) { + t.Errorf("round trip mismatch:\n got %s\nwant %s", gotB, b) + } +} + +// TestGatewayEvent_JSON_OmitsOptionalFields proves a minimal event (no +// Instance/User/Group/Model/Provider/Status) omits those keys entirely, +// matching gatewayEvent's own omitempty tags — Route/Kind/Message/Time/ +// Replica are the only fields a minimal event (e.g. the capacity hook) +// always carries. +func TestGatewayEvent_JSON_OmitsOptionalFields(t *testing.T) { + ev := gatewayEvent{Route: routeCapacity, Kind: eventKindCapacity, Message: "server is at capacity; try again shortly"} + b, err := json.Marshal(ev) + if err != nil { + t.Fatalf("Marshal: %v", err) + } + for _, absent := range []string{`"instance"`, `"user"`, `"group"`, `"model"`, `"provider"`, `"status"`} { + if strings.Contains(string(b), absent) { + t.Errorf("JSON = %s, must omit %s for an unset optional field", b, absent) + } + } + for _, present := range []string{`"time"`, `"replica"`, `"route"`, `"kind"`, `"message"`} { + if !strings.Contains(string(b), present) { + t.Errorf("JSON = %s, must always include %s", b, present) + } + } +} + +// --- recordUpstreamEvent: error classification (F3 hook 2) --- + +// TestRecordUpstreamEvent_Classification drives every classification +// branch recordUpstreamEvent's own doc comment promises: a wrapped +// errProviderTimeout or context.DeadlineExceeded is a timeout/504; a +// *providerHTTPError is an upstream event only at 429 or >=500, never at +// an ordinary 4xx; *translateError and context.Canceled record nothing; +// anything else is upstream/502 with the message scrubbed via +// sanitizeProviderErr — proven here with a genuine credential-bearing +// *url.Error, matching the plan's own risk-section requirement (§6). +func TestRecordUpstreamEvent_Classification(t *testing.T) { + // Built via net/url, not a literal credential-shaped string constant + // (matches TestAdminOverview_BaseURLStripsCredentials' own reasoning, + // admin_test.go): this is a fabricated test fixture, not a real + // credential, but a literal userinfo URL string in source still + // trips generic secret scanners. + credentialBaseURL := (&url.URL{ + Scheme: "https", + User: url.UserPassword("secretuser", "secretpass"), + Host: "openai.invalid", + }).String() + + // credentialAndKeyBaseURL additionally carries a "?key=" query + // parameter — the timeout branch's own risk (verify-dash-backend.md + // finding 2): before this fix only the generic (502) branch ran + // lastErr through sanitizeProviderErr, so a timeout error embedding + // this same base URL leaked BOTH the userinfo and any query-string + // credential riding it (net/http embeds the dialed URL verbatim in a + // *url.Error on a context-deadline failure). A separate provider + // ("openai-keyed") carries this BaseURL so the existing "openai" + // cases above are unaffected. + credentialAndKeyBaseURL := (&url.URL{ + Scheme: "https", + User: url.UserPassword("secretuser", "secretpass"), + Host: "openai.invalid", + RawQuery: "key=leakyquerykey", + }).String() + + cfg := CreateConfig() + cfg.Providers = map[string]*ProviderConfig{ + "openai": {Type: "openai", BaseURL: credentialBaseURL, APIKey: "sk"}, + "openai-keyed": {Type: "openai", BaseURL: credentialAndKeyBaseURL, APIKey: "sk"}, + } + 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 := h.(*Gateway) + gw.events.spawn = func(f func()) { f() } // deterministic: no Redis configured anyway, but keep this test independent of that fact + + watchdogTimeout := fmt.Errorf("%w: chat/completions: no upstream progress for 5m0s", errProviderTimeout) + + cases := []struct { + err error + name string + provider string // "" defaults to "openai" below + wantMsgHas string + wantKind string + wantStatus int + wantEvent bool + }{ + {name: "wrapped errProviderTimeout -> timeout/504", err: watchdogTimeout, wantEvent: true, wantKind: eventKindTimeout, wantStatus: http.StatusGatewayTimeout}, + {name: "context.DeadlineExceeded -> timeout/504", err: fmt.Errorf("dial: %w", context.DeadlineExceeded), wantEvent: true, wantKind: eventKindTimeout, wantStatus: http.StatusGatewayTimeout}, + {name: "providerHTTPError 429 -> upstream/429", err: &providerHTTPError{status: http.StatusTooManyRequests}, wantEvent: true, wantKind: eventKindUpstream, wantStatus: http.StatusTooManyRequests}, + {name: "providerHTTPError 500 -> upstream/500", err: &providerHTTPError{status: http.StatusInternalServerError}, wantEvent: true, wantKind: eventKindUpstream, wantStatus: http.StatusInternalServerError}, + {name: "providerHTTPError 404 -> no event (ordinary client error)", err: &providerHTTPError{status: http.StatusNotFound}, wantEvent: false}, + {name: "providerHTTPError 400 -> no event (ordinary client error)", err: &providerHTTPError{status: http.StatusBadRequest}, wantEvent: false}, + {name: "translateError -> no event", err: &translateError{msg: "bad field"}, wantEvent: false}, + {name: "context.Canceled -> no event", err: context.Canceled, wantEvent: false}, + {name: "nil err -> no event", err: nil, wantEvent: false}, + { + name: "generic connection error -> upstream/502, credential scrubbed", + err: &url.Error{Op: "Get", URL: credentialBaseURL + "/v1/chat/completions", Err: errors.New("connection refused")}, + wantEvent: true, + wantKind: eventKindUpstream, + wantStatus: http.StatusBadGateway, + wantMsgHas: "connection refused", + }, + { + // Finding 2 fix (verify-dash-backend.md): a *url.Error + // wrapping context.DeadlineExceeded — net/http's own shape + // for a context-deadline failure mid-dial — used to skip + // sanitizeProviderErr entirely on the timeout branch, so + // BOTH the userinfo (secretuser:secretpass@) and the + // "?key=" query credential embedded in the dialed URL + // leaked verbatim into the event feed. + name: "timeout: *url.Error wrapping DeadlineExceeded, userinfo and ?key= scrubbed", + provider: "openai-keyed", + err: &url.Error{Op: "Get", URL: credentialAndKeyBaseURL + "/v1/chat/completions", Err: context.DeadlineExceeded}, + wantEvent: true, + wantKind: eventKindTimeout, + wantStatus: http.StatusGatewayTimeout, + }, + } + + for _, c := range cases { + t.Run(c.name, func(t *testing.T) { + provider := c.provider + if provider == "" { + provider = "openai" + } + before := len(gw.events.ring.snapshot(eventRingCap)) + gw.recordUpstreamEvent(nil, "openai/gpt-4o", provider, routeChatCompletions, c.err) + after := gw.events.ring.snapshot(eventRingCap) + + if !c.wantEvent { + if len(after) != before { + t.Fatalf("recorded an event for err=%v, want none: %+v", c.err, after[0]) + } + return + } + if len(after) != before+1 { + t.Fatalf("did not record an event for err=%v", c.err) + } + got := after[0] // newest first + if got.Kind != c.wantKind { + t.Errorf("Kind = %q, want %q", got.Kind, c.wantKind) + } + if got.Status != c.wantStatus { + t.Errorf("Status = %d, want %d", got.Status, c.wantStatus) + } + if c.wantMsgHas != "" && !strings.Contains(got.Message, c.wantMsgHas) { + t.Errorf("Message = %q, want it to contain %q", got.Message, c.wantMsgHas) + } + for _, leaked := range []string{"secretuser", "secretpass", "leakyquerykey"} { + if strings.Contains(got.Message, leaked) { + t.Errorf("Message leaks credential material %q: %q", leaked, got.Message) + } + } + }) + } +} + +// TestRecordProxyEvent_Classification covers recordProxyEvent's own +// status-based rule (F3 hook 3): 0/429/>=500 record an event, everything +// else (including a client-canceled result) does not. +func TestRecordProxyEvent_Classification(t *testing.T) { + g := &Gateway{name: "llmgw", replica: "test-replica"} + g.events = &eventLog{ring: &eventRing{}, nowFn: time.Now, spawn: func(f func()) { f() }} + + cases := []struct { + wantKind string + result proxyResult + wantStatus int + wantEvent bool + }{ + {result: proxyResult{status: 0}, wantEvent: true, wantKind: eventKindUpstream, wantStatus: http.StatusBadGateway}, + {result: proxyResult{status: http.StatusTooManyRequests}, wantEvent: true, wantKind: eventKindUpstream, wantStatus: http.StatusTooManyRequests}, + {result: proxyResult{status: http.StatusBadGateway}, wantEvent: true, wantKind: eventKindUpstream, wantStatus: http.StatusBadGateway}, + {result: proxyResult{status: http.StatusOK}, wantEvent: false}, + {result: proxyResult{status: http.StatusNotFound}, wantEvent: false}, + {result: proxyResult{status: 0, clientCanceled: true}, wantEvent: false}, + {result: proxyResult{status: http.StatusInternalServerError, clientCanceled: true}, wantEvent: false}, + } + for _, c := range cases { + t.Run(fmt.Sprintf("status=%d canceled=%v", c.result.status, c.result.clientCanceled), func(t *testing.T) { + before := len(g.events.ring.snapshot(eventRingCap)) + g.recordProxyEvent(nil, "openai", routePassthrough, c.result) + after := g.events.ring.snapshot(eventRingCap) + if !c.wantEvent { + if len(after) != before { + t.Fatalf("recorded an event for %+v, want none", c.result) + } + return + } + if len(after) != before+1 { + t.Fatalf("did not record an event for %+v", c.result) + } + got := after[0] + if got.Kind != c.wantKind || got.Status != c.wantStatus { + t.Errorf("got Kind=%q Status=%d, want Kind=%q Status=%d", got.Kind, got.Status, c.wantKind, c.wantStatus) + } + }) + } +} + +// TestApplyScopeAttribution_FirstUserAndGroupWin proves +// applyScopeAttribution takes the FIRST user-kind and FIRST group-kind +// scope, ignoring a later total/other scope, matching +// buildLimitScopes/withTotalScope's own user-then-group-then-total order. +func TestApplyScopeAttribution_FirstUserAndGroupWin(t *testing.T) { + scopes := []limitScope{ + {kind: "user", id: "alice"}, + {kind: "group", id: "eng"}, + {kind: totalScopeKind, id: totalScopeID}, + } + var ev gatewayEvent + applyScopeAttribution(&ev, scopes) + if ev.User != "alice" || ev.Group != "eng" { + t.Errorf("ev = %+v, want User=alice Group=eng", ev) + } +} diff --git a/limits.go b/limits.go index 2ef1b71..ecf67d7 100644 --- a/limits.go +++ b/limits.go @@ -56,6 +56,13 @@ const ( metricTokIn = "tokin" metricTokOut = "tokout" metricCost = "cost" + // metricRej is the fleet-wide rejection counter F4 (v0.3 dashboard + // task) adds: a day-bucketed count of every checkAndCount rejection, + // per scope, folded into the SAME storeIncrMulti round trip + // settleRejection already pays to compensate other scopes' counters + // (below) — never a second round trip. Read back as + // scopeUsage.rejectionsPerDay / adminUsageEntryView.RejectionsPerDay. + metricRej = "rej" ) // TTLs applied to counter keys. They exceed their window's natural length @@ -502,6 +509,14 @@ const ( // limitViolation describes the first limit a request breached. type limitViolation struct { message string + // kind is one of the eventKindRateLimit/eventKindBudget/ + // eventKindStoreDown vocabulary (events.go, F3 v0.3 dashboard task) — + // set once, at construction (storeDownViolation, requestLimitViolation, + // checkAndCount's own budget-probe branch), so recordLimitEvent can + // classify GET /admin/api/events' Kind field straight from it instead + // of re-deriving the same distinction from v.message/v.storeDown a + // second time. + kind string // retryAfter is the number of seconds until the violated window ends // — until the client can plausibly succeed again. Left at its zero // value for a storeDown violation, which carries no meaningful window. @@ -1041,7 +1056,7 @@ func (l *limiter) failPolicyIncrAndGetMulti(entries []counterIncr, reads []strin // non-shared fallback, so a backend outage cannot let every configured // limit go unenforced across a fleet of gateway instances. func storeDownViolation() *limitViolation { - return &limitViolation{message: "limit store unavailable", storeDown: true} + return &limitViolation{message: "limit store unavailable", storeDown: true, kind: eventKindStoreDown} } // bucketFor formats t (in UTC) to window's bucket granularity: the string @@ -1222,18 +1237,19 @@ func buildBudgetProbes(scopes []limitScope, now time.Time) (probes []budgetProbe // storeDownViolation immediately — the request is refused rather than // evaluated against partial or fallback-only counters. // -// On a violation, rollbackOtherScopeCounts (finding F1, 2026-09 review) -// compensates the increments made above for every scope OTHER than the -// one that actually violated: the violating scope's own counter still -// reflects a real admission attempt against ITS OWN limit — unchanged, -// intentional — but WITHOUT the rollback, every OTHER scope (a user's -// group, the synthetic total scope) would also count that same rejected -// request toward ITS rate tracking, even though it never had anything to -// do with the rejection. Left unrolled-back, a single user hammering past -// their own requests-per-minute limit drives their group's identical -// counter up on every one of those 429s too, and can lock out every -// OTHER member of the group once the group's own limit is reached from -// traffic that was never actually admitted. +// On a violation, settleRejection (finding F1, 2026-09 review; extended by +// F4, v0.3 dashboard task, to also record the fleet-wide rejection — +// see its own doc comment) compensates the increments made above for +// every scope OTHER than the one that actually violated: the violating +// scope's own counter still reflects a real admission attempt against +// ITS OWN limit — unchanged, intentional — but WITHOUT the rollback, +// every OTHER scope (a user's group, the synthetic total scope) would +// also count that same rejected request toward ITS rate tracking, even +// though it never had anything to do with the rejection. Left unrolled- +// back, a single user hammering past their own requests-per-minute limit +// drives their group's identical counter up on every one of those 429s +// too, and can lock out every OTHER member of the group once the group's +// own limit is reached from traffic that was never actually admitted. // // Every scope's three increments AND every scope's token/cost budget reads // ride ONE storeIncrAndGetMulti round trip (perf review round 3, @@ -1302,12 +1318,12 @@ func (l *limiter) checkAndCount(scopes []limitScope) *limitViolation { // stats-only, deliberately never read here. if v := requestLimitViolation(sc, "requests-per-minute", sc.limits.RequestsPerMinute, minCount, windowMin, now); v != nil { l.rejections.increment(sc.kind, sc.id) - l.rollbackOtherScopeCounts(entries, i, len(scopes)) + l.settleRejection(entries, i, scopes, wb, et) return v } if v := requestLimitViolation(sc, "requests-per-day", sc.limits.RequestsPerDay, dayCount, windowDay, now); v != nil { l.rejections.increment(sc.kind, sc.id) - l.rollbackOtherScopeCounts(entries, i, len(scopes)) + l.settleRejection(entries, i, scopes, wb, et) return v } for _, p := range probes { @@ -1322,49 +1338,33 @@ func (l *limiter) checkAndCount(scopes []limitScope) *limitViolation { continue } l.rejections.increment(sc.kind, sc.id) - l.rollbackOtherScopeCounts(entries, i, len(scopes)) + l.settleRejection(entries, i, scopes, wb, et) return &limitViolation{ message: fmt.Sprintf("%s %q exceeded %s budget", sc.kind, sc.id, p.name), retryAfter: retryAfterSeconds(now, p.window), + kind: eventKindBudget, } } } return nil } -// rollbackOtherScopeCounts compensates the req:min/req:day/req:hour -// increments checkAndCount already made for every scope OTHER than -// violatedIdx, in ONE further batched store call (finding F1, 2026-09 -// review — the group-lockout bug): checkAndCount counts every scope -// UNCONDITIONALLY before evaluating any of them, by design, so that a -// request refused by one scope's own limit still counts toward every -// other scope's rate tracking (see checkAndCount's own doc comment) — but -// that means a user hammering past THEIR OWN requests-per-minute limit -// also drives up their group's identical counter on every one of those -// rejected attempts, and can lock out every other member of the group -// once the group's own limit is reached too, entirely from traffic that -// was never admitted. -// -// The scope that actually violated (violatedIdx) keeps its own -// increment — that counter reflecting a real admission attempt against -// ITS OWN limit is exactly the existing, intentional behavior; only the -// OTHER scopes' counts, which had nothing to do with this rejection, are -// undone. Sent as negative-delta counterIncr entries through the same -// storeIncrMulti path every other write in this file already uses — one -// extra round trip, only on rejection, never on the (overwhelmingly more -// common) admitted path. -// -// Best-effort: a failed rollback batch is logged and otherwise ignored — -// the request is being rejected either way, and a failed rollback only -// ever leaves an extra +1 on an unrelated scope's counter, which is -// exactly this bug's own pre-fix behavior for that one counter, not a new -// hazard. -func (l *limiter) rollbackOtherScopeCounts(entries []counterIncr, violatedIdx, numScopes int) { - if numScopes <= 1 { - return - } - comp := make([]counterIncr, 0, (numScopes-1)*checkAndCountKeysPerScope) - for i := 0; i < numScopes; i++ { +// settleRejection compensates the req:min/req:day/req:hour increments +// checkAndCount already made for every scope OTHER than violatedIdx — +// exactly what rollbackOtherScopeCounts (its pre-F4 name) did — AND, in +// the SAME batched store call, records the fleet-wide rejection: +1 to +// the violated scope's own rej:day counter, and +1 to the synthetic total +// scope's rej:day counter when one is present in scopes (F4, v0.3 +// dashboard task — GET /admin/api/usage's rejectionsPerDay field, Q6: +// "attribute rejections to total/all too"). Folding this into the +// compensating batch, rather than a separate storeIncrMulti call, means a +// rejection still pays exactly the one further round trip it already did +// before F4 existed — see checkAndCount's own doc comment for the round- +// trip accounting this preserves. +func (l *limiter) settleRejection(entries []counterIncr, violatedIdx int, scopes []limitScope, wb windowBuckets, et enforceTTLSet) { + comp := make([]counterIncr, 0, len(scopes)*checkAndCountKeysPerScope) + totalPresent := false + for i, sc := range scopes { if i == violatedIdx { continue } @@ -1372,15 +1372,28 @@ func (l *limiter) rollbackOtherScopeCounts(entries []counterIncr, violatedIdx, n e := entries[i*checkAndCountKeysPerScope+k] comp = append(comp, counterIncr{key: e.key, delta: -e.delta, ttl: e.ttl, enforceTTL: e.enforceTTL}) } + if sc.kind == totalScopeKind && sc.id == totalScopeID { + totalPresent = true + } } - if len(comp) == 0 { - return + violated := scopes[violatedIdx] + comp = append(comp, rejectionCounterIncr(violated.kind, violated.id, wb.day, et.day)) + if totalPresent { + comp = append(comp, rejectionCounterIncr(totalScopeKind, totalScopeID, wb.day, et.day)) } if _, ok := l.storeIncrMulti(comp); !ok { - l.logf("limits: rollback of other-scope request counters failed after a rejection; those scopes' req:min/day/hour counters may be over-counted by 1 for the current window") + l.logf("limits: rollback/rejection-accounting batch failed after a rejection; other scopes' req:min/day/hour counters may be over-counted by 1, and rejectionsPerDay may undercount, for the current window") } } +// rejectionCounterIncr builds the single rej:day counterIncr entry +// settleRejection adds per scope it attributes a rejection to — delta 1, +// ttl/enforceTTL matching every other day-window counter this file writes +// (dayWindowTTL/et.day, exactly like checkAndCount's own req:day entry). +func rejectionCounterIncr(kind, id, dayBucket string, enforceTTL time.Duration) counterIncr { + return counterIncr{key: windowKeyForBucket(kind, id, metricRej, windowDay, dayBucket), delta: 1, ttl: dayWindowTTL, enforceTTL: enforceTTL} +} + // requestLimitViolation reports a violation when count (already // incremented for this request) exceeds limit. limit<=0 means unlimited. func requestLimitViolation(sc limitScope, name string, limit, count int64, window string, now time.Time) *limitViolation { @@ -1390,6 +1403,7 @@ func requestLimitViolation(sc limitScope, name string, limit, count int64, windo return &limitViolation{ message: fmt.Sprintf("%s %q exceeded %s limit (%d)", sc.kind, sc.id, name, limit), retryAfter: retryAfterSeconds(now, window), + kind: eventKindRateLimit, } } @@ -1676,7 +1690,7 @@ const maxModelScopeIDLen = 256 // withModelScope returns scopes plus a kindModel scope for canonical, the // "provider/model" id that actually SERVED the request. It copies rather // than appending in place: the caller's slice is the same one -// admitRequest already passed to checkAndCount, and growing it through a +// admitRequestForRoute already passed to checkAndCount, and growing it through a // shared backing array would be a data race waiting to happen. // // canonical is returned unchanged (no model scope added) when it names no @@ -2081,8 +2095,10 @@ func (l *limiter) providerUsage(scopes []limitScope) []providerCounters { // v0.2 final review wave follow-up (2026-08-20) that flagged the previous // literal "6" as a magic-number stride: this task grows the per-scope key // count from 6 to 8 for the tokens-in/tokens-out split, which is exactly -// the moment a silent off-by-N here would have gone unnoticed. -const usageKeysPerScope = 8 +// the moment a silent off-by-N here would have gone unnoticed. F4 (v0.3 +// dashboard task) grows it again, 8 to 9, for the fleet-wide +// rejectionsPerDay counter (metricRej) usageWindowKeys now appends. +const usageKeysPerScope = 9 // scopeUsage is one scope's (a user's, a group's, or the synthetic total // scope's — totalScopeKind) current-window counter values — the admin @@ -2105,6 +2121,11 @@ type scopeUsage struct { tokensOutPerMonth int64 costPerDayMicros int64 costPerMonthMicros int64 + // rejectionsPerDay is the fleet-wide count of checkAndCount rejections + // attributed to this scope today (metricRej, F4 v0.3 dashboard task) — + // GET /admin/api/usage's rejectionsPerDay field. Unlike every other + // field here, this counts REFUSED requests, not admitted ones. + rejectionsPerDay int64 // storeDown reports whether reading any of the usageKeysPerScope // counters above failed closed (a configured store errored and // failOpen is false) — mirrors limitViolation.storeDown. Every value @@ -2116,9 +2137,10 @@ type scopeUsage struct { // usageWindowKeys returns the usageKeysPerScope windowKey strings // currentUsage reads for sc at time now, in a fixed order — req/min, // req/day, tokin/day, tokin/month, tokout/day, tokout/month, cost/day, -// cost/month — matching scopeUsage's field order exactly, so currentUsage -// can map storeGetMulti's result slice back to named fields by plain -// index. +// cost/month, rej/day — matching scopeUsage's field order exactly, so +// currentUsage can map storeGetMulti's result slice back to named fields +// by plain index. rej/day (F4, v0.3 dashboard task) is appended last so +// every existing index above it stays byte-for-byte unchanged. func usageWindowKeys(sc limitScope, now time.Time) []string { return []string{ windowKey(sc.kind, sc.id, metricReq, windowMin, now), @@ -2129,6 +2151,7 @@ func usageWindowKeys(sc limitScope, now time.Time) []string { windowKey(sc.kind, sc.id, metricTokOut, windowMonth, now), windowKey(sc.kind, sc.id, metricCost, windowDay, now), windowKey(sc.kind, sc.id, metricCost, windowMonth, now), + windowKey(sc.kind, sc.id, metricRej, windowDay, now), } } @@ -2203,6 +2226,7 @@ func (l *limiter) currentUsage(scopes []limitScope) []scopeUsage { tokensInPerDay: v[2], tokensInPerMonth: v[3], tokensOutPerDay: v[4], tokensOutPerMonth: v[5], costPerDayMicros: v[6], costPerMonthMicros: v[7], + rejectionsPerDay: v[8], } } return out @@ -2218,17 +2242,21 @@ type historyPoint struct { value int64 } -// modelTotals reads ONE counter per id — metric at window's CURRENT bucket -// — in a single storeGetMulti, returning values positionally (result[i] is -// ids[i]'s total). It backs GET /admin/api/usage/models, whose ranking -// needs a single comparable number per model rather than history's whole -// span: reading a span of buckets per model would multiply an already -// catalog-sized read (one key per configured model) by the span. +// modelSpanTotals reads span counter buckets per id — via +// historyBucketKeys, the identical per-id bucket walk history (below) +// uses for one scope — flattens every id's span keys into ONE +// storeGetMulti round trip, and returns each id's SUM over its own span, +// positionally (result[i] is the sum for ids[i]). F2, v0.3 dashboard +// task: backs GET /admin/api/usage/models' optional ?span= parameter, so +// the Charts view's "Models" ranking can show a window wider than the +// current bucket alone. modelTotals (below) is the span=1 special case, +// unchanged in behavior from before this function existed. // -// ok is false when the store read fails, exactly as history does, so the -// caller answers 503 rather than presenting an all-zero ranking as though -// no model had been used. An empty ids slice is not a store read at all: -// it returns an empty result and ok, never a round trip. +// ok is false when the store read fails, exactly as history/modelTotals +// already promise, so the caller answers 503 rather than presenting a +// partial or fallback-served sum as a genuine ranking. An empty ids slice +// is not a store read at all: it returns an empty result and ok, never a +// round trip. // // configuredStoreDown is checked alongside storeGetMulti's own ok // (finding F5, 2026-09 review, applying currentUsage/providerUsage's own @@ -2239,20 +2267,37 @@ type historyPoint struct { // present a fail-open read of near-empty fallback data as a genuine // "these models were barely used" ranking instead of the 503 this // function's own doc comment already promises for a store failure. -func (l *limiter) modelTotals(ids []string, metric, window string) ([]int64, bool) { +func (l *limiter) modelSpanTotals(ids []string, metric, window string, now time.Time, span int) ([]int64, bool) { if len(ids) == 0 { return nil, true } - now := l.now() - keys := make([]string, len(ids)) - for i, id := range ids { - keys[i] = windowKey(kindModel, id, metric, window, now) + allKeys := make([]string, 0, len(ids)*span) + for _, id := range ids { + keys, _ := historyBucketKeys(kindModel, id, metric, window, now, span) + allKeys = append(allKeys, keys...) } - vals, ok := l.storeGetMulti(keys) - if !ok || len(vals) != len(keys) || l.configuredStoreDown() { + vals, ok := l.storeGetMulti(allKeys) + if !ok || len(vals) != len(allKeys) || l.configuredStoreDown() { return nil, false } - return vals, true + out := make([]int64, len(ids)) + for i := range ids { + var sum int64 + for _, v := range vals[i*span : i*span+span] { + sum += v + } + out[i] = sum + } + return out, true +} + +// modelTotals reads ONE counter per id — metric at window's CURRENT +// bucket — the modelSpanTotals span=1 special case: historyBucketKeys' +// own i=0/span=1 step lands on exactly the same key windowKey(kindModel, +// id, metric, window, now) would have built directly, so this wrapper is +// byte-for-byte the pre-F2 implementation's behavior. +func (l *limiter) modelTotals(ids []string, metric, window string) ([]int64, bool) { + return l.modelSpanTotals(ids, metric, window, l.now(), 1) } // historyStepBack returns the instant window's bucket was current i steps diff --git a/limits_test.go b/limits_test.go index 9e5f2fa..236a2f3 100644 --- a/limits_test.go +++ b/limits_test.go @@ -2629,6 +2629,153 @@ func TestModelTotals_ConfiguredStoreDown_FailOpen_ReturnsNotOK(t *testing.T) { } } +// TestModelSpanTotalsSumsBuckets is F2 (v0.3 dashboard task): +// modelSpanTotals sums span buckets ending at now, per id, positionally +// — the arithmetic GET /admin/api/usage/models' ?span= parameter relies +// on. It also proves modelTotals (its span=1 special case) reads only +// today's own bucket, byte-for-byte the pre-F2 behavior. +func TestModelSpanTotalsSumsBuckets(t *testing.T) { + l := newLimiter(nil, true) + now := time.Date(2026, 9, 23, 10, 0, 0, 0, time.UTC) + id := "openai/gpt-4o" + + l.incrCounter(kindModel, id, metricReq, windowDay, historyStepBack(now, windowDay, 2), 5, dayWindowTTL) + l.incrCounter(kindModel, id, metricReq, windowDay, historyStepBack(now, windowDay, 1), 7, dayWindowTTL) + l.incrCounter(kindModel, id, metricReq, windowDay, historyStepBack(now, windowDay, 0), 11, dayWindowTTL) + + got, ok := l.modelSpanTotals([]string{id}, metricReq, windowDay, now, 3) + if !ok { + t.Fatal("want ok=true") + } + if len(got) != 1 || got[0] != 23 { + t.Errorf("span=3 got = %v, want [23] (5+7+11)", got) + } + + span1, ok := l.modelTotals([]string{id}, metricReq, windowDay) + if !ok || len(span1) != 1 || span1[0] != 11 { + t.Errorf("modelTotals (span=1 wrapper) got = %v ok=%v, want [11] (today's own bucket only)", span1, ok) + } +} + +// TestModelSpanTotalsSumsBuckets_MultipleIDsPositional proves the +// flattened storeGetMulti's reply is sliced back per id in the SAME +// order ids was given, not just correct for a single id. +func TestModelSpanTotalsSumsBuckets_MultipleIDsPositional(t *testing.T) { + l := newLimiter(nil, true) + now := time.Date(2026, 9, 23, 10, 0, 0, 0, time.UTC) + + l.incrCounter(kindModel, "a/one", metricCost, windowDay, historyStepBack(now, windowDay, 1), 100, dayWindowTTL) + l.incrCounter(kindModel, "a/one", metricCost, windowDay, historyStepBack(now, windowDay, 0), 50, dayWindowTTL) + l.incrCounter(kindModel, "b/two", metricCost, windowDay, historyStepBack(now, windowDay, 1), 3, dayWindowTTL) + l.incrCounter(kindModel, "b/two", metricCost, windowDay, historyStepBack(now, windowDay, 0), 4, dayWindowTTL) + + got, ok := l.modelSpanTotals([]string{"a/one", "b/two"}, metricCost, windowDay, now, 2) + if !ok { + t.Fatal("want ok=true") + } + if len(got) != 2 || got[0] != 150 || got[1] != 7 { + t.Errorf("got = %v, want [150 7]", got) + } +} + +// TestModelSpanTotals_EmptyIDs_NoStoreRead proves an empty ids slice +// never touches the store at all — matches modelTotals' own pre-existing +// contract, unaffected by F2's span extension. +func TestModelSpanTotals_EmptyIDs_NoStoreRead(t *testing.T) { + l := newLimiter(alwaysErrStore{}, false) // fail-closed AND always-erroring: any store read would fail the test + got, ok := l.modelSpanTotals(nil, metricReq, windowDay, time.Now(), 5) + if !ok || got != nil { + t.Errorf("got = %v, ok = %v, want nil, true (no store read for an empty ids slice)", got, ok) + } +} + +// TestCheckAndCountRejectionFoldedIntoRollbackBatch is F4 (v0.3 dashboard +// task): the fleet-wide rejectionsPerDay counter for the violated scope +// AND the synthetic total scope rides the SAME storeIncrMulti batch +// settleRejection already pays to compensate every other scope's +// increments (see TestCheckAndCount_OneIncrAndGetMultiCallRegardlessOfScopeCount +// above) — a rejection never costs a SECOND round trip beyond that one. +func TestCheckAndCountRejectionFoldedIntoRollbackBatch(t *testing.T) { + store := &countingIncrStore{} + l := newLimiter(store, true) + now := time.Date(2026, 9, 23, 9, 0, 0, 0, time.UTC) + l.nowFn = func() time.Time { return now } + + scopes := []limitScope{ + {kind: "user", id: "u", limits: &LimitsConfig{RequestsPerMinute: 1}}, + {kind: "group", id: "g", limits: nil}, + {kind: totalScopeKind, id: totalScopeID, limits: nil}, + } + + if v := l.checkAndCount(scopes); v != nil { + t.Fatalf("1st call should pass, got %+v", v) + } + v := l.checkAndCount(scopes) + if v == nil { + t.Fatal("2nd call should violate u's requestsPerMinute:1") + } + if v.kind != eventKindRateLimit { + t.Errorf("v.kind = %q, want %q", v.kind, eventKindRateLimit) + } + if store.incrMultiCalls != 1 { + t.Errorf("incrMultiCalls after the violation = %d, want 1 (compensations + rejection counters share one batch)", store.incrMultiCalls) + } + + uRej, ok := l.getCounter("user", "u", metricRej, windowDay, now) + if !ok || uRej != 1 { + t.Errorf("user rej:day = %d, ok=%v, want 1", uRej, ok) + } + totalRej, ok := l.getCounter(totalScopeKind, totalScopeID, metricRej, windowDay, now) + if !ok || totalRej != 1 { + t.Errorf("total rej:day = %d, ok=%v, want 1 (Q6: rejections attributed to total/all too)", totalRej, ok) + } + gRej, ok := l.getCounter("group", "g", metricRej, windowDay, now) + if ok && gRej != 0 { + t.Errorf("group rej:day = %d, want 0 (group did not violate)", gRej) + } +} + +// TestCheckAndCount_StoreDownRejection_NoRejCounterWrite proves the +// store-down branch stays purely in-process (limits.go's own checkAndCount +// doc comment): a storeDown violation never reaches settleRejection at +// all — it fires before any per-scope evaluation loop — so it costs no +// further store round trip beyond the one failed incrAndGetMulti attempt. +func TestCheckAndCount_StoreDownRejection_NoRejCounterWrite(t *testing.T) { + store := &erroringStore{err: errStoreDownStub} + l := newLimiter(store, false) // fail-closed + scopes := []limitScope{{kind: "user", id: "u", limits: &LimitsConfig{RequestsPerMinute: 1}}} + + v := l.checkAndCount(scopes) + if v == nil || !v.storeDown { + t.Fatalf("v = %+v, want a storeDown violation", v) + } + if v.kind != eventKindStoreDown { + t.Errorf("v.kind = %q, want %q", v.kind, eventKindStoreDown) + } +} + +// TestCurrentUsage_RejectionsPerDay proves currentUsage reads the +// rej:day counter into scopeUsage.rejectionsPerDay — F4's usageKeysPerScope +// 8->9 growth (v0.3 dashboard task). +func TestCurrentUsage_RejectionsPerDay(t *testing.T) { + l := newLimiter(nil, true) + now := time.Date(2026, 9, 23, 9, 0, 0, 0, time.UTC) + l.nowFn = func() time.Time { return now } + + l.incrCounter("user", "u", metricRej, windowDay, now, 3, dayWindowTTL) + + got := l.currentUsage([]limitScope{{kind: "user", id: "u"}}) + if len(got) != 1 { + t.Fatalf("len(got) = %d, want 1", len(got)) + } + if got[0].rejectionsPerDay != 3 { + t.Errorf("rejectionsPerDay = %d, want 3", got[0].rejectionsPerDay) + } + if got[0].storeDown { + t.Error("storeDown = true, want false") + } +} + // TestTargetUsage_ConfiguredStoreDown_FailOpen_ReturnsZeroCounters is // finding F5, 2026-09 review — targetUsage's own counterpart: with // failOpen=true, a store outage must fall back to the same zero-value diff --git a/llmgateway.go b/llmgateway.go index e3c63b6..56b84f1 100644 --- a/llmgateway.go +++ b/llmgateway.go @@ -726,8 +726,8 @@ const maxExplicitBodyAdmissionCap = 10_000 //nolint:govet type Gateway struct { next http.Handler - provenance *provenanceStore - targetClient *http.Client + events *eventLog + bodyAdmission chan struct{} failoverHealth *requestHealthTracker targetHealth *targetHealthTracker limiter *limiter @@ -735,18 +735,44 @@ type Gateway struct { adapters map[string]providerAdapter cfg *Config auth *authStore - bodyAdmission chan struct{} + cache *responseCache redisClient *respClient latency *latencyStore - cache *responseCache + targetClient *http.Client + provenance *provenanceStore name string + replica string failoverLogGate logGate metricsNets []*net.IPNet + configWarnings []string targetHealthCfg targetHealthConfig failover failoverConfig - targetHealthLastSweepUnixNano int64 targetTimeout time.Duration + targetHealthLastSweepUnixNano int64 + configWarningsDropped int + warnMu sync.Mutex targetHealthSweeping int32 + collectingWarnings bool +} + +// replicaID resolves this process's identity for Gateway.replica (F4/F9, +// v0.3 dashboard task): os.Hostname() when available — the pod name under +// Kubernetes with the common hostNetwork: false setup — else the +// HOSTNAME environment variable some container runtimes set directly, +// else the literal "unknown", so the field is never empty. Called once, +// in newGateway, not per request. +// +// CAVEAT (document in README, WP-C): under hostNetwork: true, every pod +// on a node shares the node's own hostname, so replica no longer +// uniquely identifies one gateway instance. +func replicaID() string { + if h, err := os.Hostname(); err == nil && h != "" { + return h + } + if h := os.Getenv("HOSTNAME"); h != "" { + return h + } + return "unknown" } // telemetryStartupOnce keeps the anonymous "plugin loaded" ping to one per @@ -865,6 +891,12 @@ func newGateway(ctx context.Context, next http.Handler, config *Config, name str return nil, err } g := &Gateway{next: next, name: name, cfg: config, auth: auth} + // replica/collectingWarnings (F4/F9/F10, v0.3 dashboard task): resolved + // immediately, before anything below can call warnf — every warnf + // call from here to this function's return is a construction-time + // warning noteConfigWarning (logger.go) must collect. + g.replica = replicaID() + g.collectingWarnings = true // feat/failover: validated once, here — see FailoverConfig's own doc // comment (failover.go) for the default (disabled, coordinator @@ -888,7 +920,13 @@ func newGateway(ctx context.Context, next http.Handler, config *Config, name str retries = defaultRetryAttempts } if worst := failoverCfg.maxAttempts * (retries + 1); worst > warnComposedOutboundCalls { - g.logf("config: failover.maxAttempts (%d) and retry.attempts (%d) compose to as many as %d outbound provider calls for ONE admitted client request; each consumes the provider quota shared by every tenant of this gateway", + // Q5 (coordinator decision, v0.3 dashboard task): promoted + // logf -> warnf — this is a config warning (an operator may + // want to know about it, resolved deterministically, no + // request affected), the exact class warnf's own doc comment + // describes, and GET /admin/api/overview's Warnings field + // (F10) should surface it. + g.warnf("config: failover.maxAttempts (%d) and retry.attempts (%d) compose to as many as %d outbound provider calls for ONE admitted client request; each consumes the provider quota shared by every tenant of this gateway", failoverCfg.maxAttempts, retries, worst) } } @@ -999,6 +1037,21 @@ func newGateway(ctx context.Context, next http.Handler, config *Config, name str lim := newConfiguredLimiter(config, redisClient) lim.logf = g.errorf g.limiter = lim + // events (F3, v0.3 dashboard task): built here, after redisClient/ + // limiter both exist — shares the SAME respClient (spec §2, above) + // and reuses the limiter's own bounded spawn (limits.go's + // providerAttemptSpawnCap semaphore) rather than a second one, so an + // event-feed write storm and a provider-attempt write storm compete + // for the identical bounded pool instead of two independent ones. + g.events = &eventLog{ + ring: &eventRing{}, + client: redisClient, + replica: g.replica, + instance: g.name, + nowFn: time.Now, + spawn: lim.spawn, + logf: g.errorf, + } cache, err := buildResponseCache(config.Cache, redisClient, g.logf, g.warnf, g.errorf) if err != nil { @@ -1045,6 +1098,20 @@ func newGateway(ctx context.Context, next http.Handler, config *Config, name str registry.warmFill(ctx) g.registry = registry + // F10 (v0.3 dashboard task): construction is finished — every warnf + // call from here on is a runtime warning, not a config warning, and + // noteConfigWarning must stop collecting it into g.configWarnings. + // + // Locked (item 4, this round): noteConfigWarning (logger.go) always + // reads collectingWarnings under warnMu, and this write is the one + // place that used to set it unlocked — harmless today (no goroutine + // calls warnf during construction: sweepTargetHealth/refreshProvider + // only ever start from ServeHTTP, after New has already returned), + // but taking the same lock here removes the need to keep re-proving + // that absence every time this file changes. + g.warnMu.Lock() + g.collectingWarnings = false + g.warnMu.Unlock() return g, nil } diff --git a/llmgateway_test.go b/llmgateway_test.go index d70b1c6..1e9e2f0 100644 --- a/llmgateway_test.go +++ b/llmgateway_test.go @@ -931,6 +931,88 @@ func TestGateway_PricingWarn_LogsUnderOwnInstance(t *testing.T) { } } +// TestNewCollectsConfigWarnings is F10 (v0.3 dashboard task): every +// construction-time warnf call — here, metrics.path="/v1/models" +// (shadowed-route warning) AND cache.ttl="0s" (zero-TTL warning), +// triggered together in one construction — lands in g.configWarnings, +// readable via GET /admin/api/overview's Warnings field. Both are real +// existing warnf call sites (TestNewGateway_MetricsPath_Validation/ +// TestBuildResponseCache_NonPositiveTTL_WarnsAndAccepts prove they fire +// at all); this test proves F10's NEW behavior — that warnf's own line +// is ALSO collected, not just written to stderr. +func TestNewCollectsConfigWarnings(t *testing.T) { + cfg := CreateConfig() + cfg.Providers = map[string]*ProviderConfig{"openai": {Type: "openai", APIKey: "k"}} + cfg.Metrics = &MetricsConfig{Enabled: true, Path: "/v1/models"} + cfg.Cache = CacheConfig{Enabled: true, TTL: "0s"} // no Redis configured — buildResponseCache still warns before its own nil-client return + 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 := h.(*Gateway) + + warnings, dropped := gw.configWarningsSnapshot() + if dropped != 0 { + t.Errorf("dropped = %d, want 0", dropped) + } + var sawMetricsPath, sawCacheTTL bool + for _, w := range warnings { + if strings.Contains(w, "metrics.path") { + sawMetricsPath = true + } + if strings.Contains(w, "cache: ttl") { + sawCacheTTL = true + } + } + if !sawMetricsPath { + t.Errorf("warnings = %v, want one mentioning metrics.path", warnings) + } + if !sawCacheTTL { + t.Errorf("warnings = %v, want one mentioning cache: ttl", warnings) + } +} + +// TestNoteConfigWarning_CapAndDropped proves configWarningsCap bounds +// g.configWarnings and configWarningsDropped counts what did not fit — +// F10's own overflow behavior, exercised directly against noteConfigWarning +// (via warnf) rather than contriving 50+ real construction warnings. +func TestNoteConfigWarning_CapAndDropped(t *testing.T) { + g := &Gateway{name: "llmgw", collectingWarnings: true} + const over = 5 + for i := 0; i < configWarningsCap+over; i++ { + g.warnf("warning %d", i) + } + warnings, dropped := g.configWarningsSnapshot() + if len(warnings) != configWarningsCap { + t.Errorf("len(warnings) = %d, want %d", len(warnings), configWarningsCap) + } + if dropped != over { + t.Errorf("dropped = %d, want %d", dropped, over) + } + if warnings[0] != "warning 0" { + t.Errorf("warnings[0] = %q, want %q (the first configWarningsCap warnings are kept, not the last)", warnings[0], "warning 0") + } +} + +// TestNoteConfigWarning_RuntimeWarnfNotCollected proves a warnf call +// AFTER collectingWarnings is false (construction finished — newGateway's +// own final step) is never appended to g.configWarnings: only +// construction-time warnings belong in GET /admin/api/overview's +// Warnings field. +func TestNoteConfigWarning_RuntimeWarnfNotCollected(t *testing.T) { + g := &Gateway{name: "llmgw", collectingWarnings: true} + g.warnf("during construction") + g.collectingWarnings = false + g.warnf("after construction, must not be collected") + + warnings, _ := g.configWarningsSnapshot() + if len(warnings) != 1 || warnings[0] != "during construction" { + t.Errorf("warnings = %v, want exactly [%q]", warnings, "during construction") + } +} + // TestShouldSendTelemetry pins the guard that keeps unstamped builds from // phoning home. Every developer checkout and every CI run carries // devPluginVersion, so the false cases are the state this code is in diff --git a/logger.go b/logger.go index b0ecced..7acf3d3 100644 --- a/logger.go +++ b/logger.go @@ -21,8 +21,60 @@ func (g *Gateway) logf(format string, args ...any) { // lines were ERROR until 2026-08-22, which put 144 of them in a healthy // pod's boot log on a cluster with overlapping catalogs and made real // errors harder to find. Reserve errorf for something actually broken. +// +// Also calls noteConfigWarning (F10, v0.3 dashboard task): while +// newGateway is still constructing g (collectingWarnings true), the +// formatted message is additionally collected into g.configWarnings — +// GET /admin/api/overview's Warnings field. A warnf call from +// request-handling code, after construction finished, is NOT collected — +// see noteConfigWarning's own doc comment for why. func (g *Gateway) warnf(format string, args ...any) { - fmt.Fprintf(os.Stderr, "llmgw[%s] WARN %s\n", g.name, fmt.Sprintf(format, args...)) + msg := fmt.Sprintf(format, args...) + fmt.Fprintf(os.Stderr, "llmgw[%s] WARN %s\n", g.name, msg) + g.noteConfigWarning(msg) +} + +// configWarningsCap bounds how many construction-time warnings +// g.configWarnings ever holds (F10, v0.3 dashboard task) — a +// misconfigured deployment logging hundreds of warnings during +// construction must not make GET /admin/api/overview's response itself +// unbounded. configWarningsDropped counts what did not fit, so the +// dashboard can say "and N more" instead of silently truncating. +const configWarningsCap = 50 + +// noteConfigWarning appends msg to g.configWarnings while newGateway is +// still collecting them — collectingWarnings is set true right after g is +// constructed and false just before newGateway returns (llmgateway.go), +// so every warnf call in that window is a CONSTRUCTION-time warning, +// exactly what GET /admin/api/overview's Warnings field surfaces. Once +// collectingWarnings is false (every warnf call from request-handling +// code, for the rest of the process lifetime), this is a no-op: such a +// warning already reached the operator via the stderr line warnf itself +// wrote, and an unbounded stream of runtime warnings must never keep +// growing this slice for the life of the process. +func (g *Gateway) noteConfigWarning(msg string) { + g.warnMu.Lock() + defer g.warnMu.Unlock() + if !g.collectingWarnings { + return + } + if len(g.configWarnings) >= configWarningsCap { + g.configWarningsDropped++ + return + } + g.configWarnings = append(g.configWarnings, msg) +} + +// configWarningsSnapshot returns a fresh copy of g.configWarnings — never +// nil, matching GET /admin/api/overview's own "never nil" contract for +// its Warnings field — and the dropped count, safe for concurrent use +// alongside noteConfigWarning. +func (g *Gateway) configWarningsSnapshot() (warnings []string, dropped int) { + g.warnMu.Lock() + defer g.warnMu.Unlock() + out := make([]string, len(g.configWarnings)) + copy(out, g.configWarnings) + return out, g.configWarningsDropped } // errorf writes an error-level log line to stderr. No timestamps — Traefik @@ -47,6 +99,16 @@ func (g *Gateway) pricingWarn(msg string) { return } g.logf("pricing: no price configured for model %q; cost will be recorded as 0", msg) + // F3 hook 4 (v0.3 dashboard task): msg is the bare unpriced model id + // here (warnUnknownModelFor's own "warn(model)" call, pricing.go) — + // the cap-message branch above is a process-wide meta-warning, not + // about any one model, so it is deliberately excluded from the event + // feed. Route is the fixed "pricing" label: this fires deep inside + // cost accounting, with no request-scoped route name available. + g.recordEvent(gatewayEvent{ + Model: msg, Route: routePricing, Kind: eventKindUnpriced, + Message: fmt.Sprintf("no price configured for model %q; cost recorded as 0", msg), + }) } // logAuthEvent logs one authentication attempt, at the point one of diff --git a/mcp_a2a.go b/mcp_a2a.go index 805adf7..4853a49 100644 --- a/mcp_a2a.go +++ b/mcp_a2a.go @@ -207,6 +207,7 @@ func (g *Gateway) handleTargetProxy(w http.ResponseWriter, r *http.Request, u *u scopes := withTotalScope(buildLimitScopes(u, grp)) if violation := g.limiter.checkAndCount(scopes); violation != nil { + g.recordLimitEvent(scopes, kind, violation) // F3 hook 1 (v0.3 dashboard task): kind is already "mcp"/"a2a" writeLimitViolation(w, violation) return } @@ -230,6 +231,7 @@ func (g *Gateway) handleTargetProxy(w http.ResponseWriter, r *http.Request, u *u start := time.Now() result, ok := g.proxyUpstream(w, r, upstreamURL, g.targetClient, nil, nil, false, kind+" target (name "+name+")", g.targetTimeout) g.recordTargetProxyHealth(kind, name, targetURL, result, ok, time.Since(start)) + g.recordProxyEvent(scopes, name, kind, result) // F3 hook 3 (v0.3 dashboard task) } // buildUpstreamTargetURL joins targetURL (an MCP server or A2A agent's own diff --git a/mcp_federation.go b/mcp_federation.go index 4de827f..e721ac2 100644 --- a/mcp_federation.go +++ b/mcp_federation.go @@ -463,6 +463,7 @@ func (g *Gateway) handleMCPFederated(w http.ResponseWriter, r *http.Request, u * scopes := withTotalScope(buildLimitScopes(u, grp)) if violation := g.limiter.checkAndCount(scopes); violation != nil { + g.recordLimitEvent(scopes, routeMCPFederated, violation) // F3 hook 1 (v0.3 dashboard task) writeLimitViolation(w, violation) return } diff --git a/resp.go b/resp.go index 992f847..b53f75d 100644 --- a/resp.go +++ b/resp.go @@ -351,10 +351,13 @@ func (c *respClient) pipelineEncoded(payload []byte, n int, mutates bool) ([]any // INCRBYFLOAT is not currently sent by this client (only INCRBY is — // redis_store.go), but is listed for the same reason INCRBY is: an // operator or a future caller adding it must not have to rediscover this -// gate. +// gate. LPUSH (events.go's eventLog.push, F3 v0.3 dashboard task) joins +// the same list for the identical reason: replaying it after an ambiguous +// failure could push the same event twice. var pipelineMutatingCommands = map[string]bool{ "INCRBY": true, "INCRBYFLOAT": true, + "LPUSH": true, } // pipelineMutates reports whether any command in cmds is one of diff --git a/resp_test.go b/resp_test.go index 7a4f49b..e01630a 100644 --- a/resp_test.go +++ b/resp_test.go @@ -17,6 +17,35 @@ import ( "github.com/stretchr/testify/require" ) +// TestPipelineMutates_LPUSH proves LPUSH is registered as a mutating +// command (F3, v0.3 dashboard task: events.go's eventLog.push sends it) — +// pipelineEncoded's own retry-safety gate must never blindly resend a +// pipeline containing it after a reply was lost mid-read, or a lost-ACK +// event push could be double-applied. Table-driven alongside the +// pre-existing INCRBY/INCRBYFLOAT/GET cases so a future change to any of +// the four can't silently drift the others. +func TestPipelineMutates_LPUSH(t *testing.T) { + cases := []struct { + name string + cmds [][]string + want bool + }{ + {name: "LPUSH alone", cmds: [][]string{{"LPUSH", "llmgw:events", "{}"}}, want: true}, + {name: "LPUSH+LTRIM (events.go's own pipeline)", cmds: [][]string{{"LPUSH", "k", "v"}, {"LTRIM", "k", "0", "199"}}, want: true}, + {name: "INCRBY still mutates", cmds: [][]string{{"INCRBY", "k", "1"}}, want: true}, + {name: "INCRBYFLOAT still mutates", cmds: [][]string{{"INCRBYFLOAT", "k", "1.5"}}, want: true}, + {name: "read-only GET/LRANGE does not mutate", cmds: [][]string{{"GET", "k"}, {"LRANGE", "llmgw:events", "0", "49"}}, want: false}, + {name: "empty pipeline does not mutate", cmds: nil, want: false}, + } + for _, c := range cases { + t.Run(c.name, func(t *testing.T) { + if got := pipelineMutates(c.cmds); got != c.want { + t.Errorf("pipelineMutates(%v) = %v, want %v", c.cmds, got, c.want) + } + }) + } +} + // TestEncodeCommand pins the exact RESP2 wire format every command must // use: "*N\r\n$len\r\narg\r\n..." — a fake or real server parses this // framing byte-for-byte, so a drift here breaks every other test silently. diff --git a/routes_media.go b/routes_media.go index bcf2370..a1ba686 100644 --- a/routes_media.go +++ b/routes_media.go @@ -82,13 +82,13 @@ func (g *Gateway) decodeMediaJSONRequest(sw *statusTrackingWriter, r *http.Reque // // This used to also run checkAndCount (a limit check), and was named // resolveMediaRequest — security review finding 1a, 2026-08-22, split -// that out into admitRequest (routes_unified.go), called by every media -// handler BEFORE the request body is even read: checkAndCount needs only -// u and grp, both already known ahead of decode, so there was never a +// that out into admitRequestForRoute (routes_unified.go), called by every +// media handler BEFORE the request body is even read: checkAndCount needs +// only u and grp, both already known ahead of decode, so there was never a // reason to make a rate-limited caller pay for reading and decoding a -// body that was always going to be discarded. See admitRequest's own doc -// comment for the full rationale, shared verbatim with runUnified's -// identical fix. +// body that was always going to be discarded. See admitRequestForRoute's +// own doc comment for the full rationale, shared verbatim with +// runUnified's identical fix. func (g *Gateway) resolveMediaModel(sw *statusTrackingWriter, grp *group, requestedModel string) (adapter providerAdapter, upstreamModel string, ok bool) { adapter, upstreamModel, _, err := g.registry.resolve(requestedModel, grp) if err != nil { @@ -103,11 +103,12 @@ func (g *Gateway) resolveMediaModel(sw *statusTrackingWriter, grp *group, reques // Imagen (translate_gemini_images.go); anthropic always answers 501 // (provider_anthropic.go's imagesGeneration). Images are never cached // (spec §2) and never cost-accounted (spec §3) — only the request -// counters admitRequest's checkAndCount call already incremented move. +// counters admitRequestForRoute's checkAndCount call already incremented move. func (g *Gateway) handleImagesGenerations(w http.ResponseWriter, r *http.Request, u *user, grp *group) { sw := &statusTrackingWriter{ResponseWriter: w} - if _, ok := g.admitRequest(sw, u, grp, writeOAIError); !ok { + scopes, ok := g.admitRequestForRoute(sw, u, grp, writeOAIError, routeImages) + if !ok { return } @@ -134,6 +135,7 @@ func (g *Gateway) handleImagesGenerations(w http.ResponseWriter, r *http.Request }) } if _, err := adapter.imagesGeneration(ctx, sw, req); err != nil { + g.recordUpstreamEvent(scopes, upstreamModel, adapter.name(), routeImages, err) g.handleAdapterError(sw, err, adapter.name()) } } @@ -151,7 +153,8 @@ func (g *Gateway) handleImagesGenerations(w http.ResponseWriter, r *http.Request func (g *Gateway) handleAudioSpeech(w http.ResponseWriter, r *http.Request, u *user, grp *group) { sw := &statusTrackingWriter{ResponseWriter: w} - if _, ok := g.admitRequest(sw, u, grp, writeOAIError); !ok { + scopes, ok := g.admitRequestForRoute(sw, u, grp, writeOAIError, routeAudioSpeech) + if !ok { return } @@ -199,6 +202,7 @@ func (g *Gateway) handleAudioSpeech(w http.ResponseWriter, r *http.Request, u *u }) } if _, err := adapter.audioSpeech(ctx, sw, body, "application/json"); err != nil { + g.recordUpstreamEvent(scopes, upstreamModel, adapter.name(), routeAudioSpeech, err) g.handleAdapterError(sw, err, adapter.name()) } } @@ -218,7 +222,8 @@ func (g *Gateway) handleAudioSpeech(w http.ResponseWriter, r *http.Request, u *u func (g *Gateway) handleAudioTranscriptions(w http.ResponseWriter, r *http.Request, u *user, grp *group) { sw := &statusTrackingWriter{ResponseWriter: w} - if _, ok := g.admitRequest(sw, u, grp, writeOAIError); !ok { + scopes, ok := g.admitRequestForRoute(sw, u, grp, writeOAIError, routeAudioTranscriptions) + if !ok { return } @@ -303,6 +308,7 @@ func (g *Gateway) handleAudioTranscriptions(w http.ResponseWriter, r *http.Reque }) } if _, err := adapter.audioTranscription(ctx, sw, uploadBody, uploadContentType); err != nil { + g.recordUpstreamEvent(scopes, upstreamModel, adapter.name(), routeAudioTranscriptions, err) g.handleAdapterError(sw, err, adapter.name()) } } diff --git a/routes_messages.go b/routes_messages.go index 861123e..416c578 100644 --- a/routes_messages.go +++ b/routes_messages.go @@ -55,11 +55,11 @@ var anthropicPassthroughForwardedHeaders = []string{"anthropic-beta"} // {"error":{...}} — see writeAnthropicError and its callers, below). // // ORDERING (item 2 fix, 2026-08-22 review): body admission + decode run -// BEFORE admitRequest (the rate-limit check) on THIS route — the +// BEFORE admitRequestForRoute (the rate-limit check) on THIS route — the // opposite order from runUnified's own finding 1a. anthropic-sdk-python // retries any status >= 500, and Claude Code streams on every call: the -// previous ordering (admitRequest first, streaming rejected only after -// decode) meant every real client hitting this not-yet-streaming-capable +// previous ordering (admitRequestForRoute first, streaming rejected only +// after decode) meant every real client hitting this not-yet-streaming-capable // route burned three requests of rate-limit budget per logical call — // verified repro: requestsPerMinute 2, three attempts -> 501, 501, 429, // day counter reads 3. Deciding "is this streaming" requires the decoded @@ -103,7 +103,7 @@ func (g *Gateway) handleMessages(w http.ResponseWriter, r *http.Request, u *user return } - scopes, ok := g.admitRequest(sw, u, grp, writeAnthropicError) + scopes, ok := g.admitRequestForRoute(sw, u, grp, writeAnthropicError, routeMessages) if !ok { return } diff --git a/routes_messages_test.go b/routes_messages_test.go index 5571d36..397d2c1 100644 --- a/routes_messages_test.go +++ b/routes_messages_test.go @@ -325,7 +325,7 @@ func TestHandleMessages_StreamingRejected(t *testing.T) { // requestsPerMinute: 1 so a second wrongly-counted request // would 429 — proving the rejection happens before - // admitRequest ever runs (item 2 fix): both requests below + // admitRequestForRoute ever runs (item 2 fix): both requests below // must succeed at the "not yet counted" stage. cfg := CreateConfig() cfg.Providers = map[string]*ProviderConfig{"anthropic": {Type: providerTypeAnthropic, BaseURL: srv.URL, APIKey: "sk-ant-up", Models: []string{"claude-test"}}} // #nosec G101 -- test fixture literal, not a real credential @@ -379,7 +379,7 @@ func TestHandleMessages_StreamingRejected(t *testing.T) { // item 2's actual fix: TWO streaming-rejected attempts against // a requestsPerMinute:1 user must BOTH succeed (as 400s, not - // as a 429 on the second one) — proving admitRequest's + // as a 429 on the second one) — proving admitRequestForRoute's // checkAndCount never ran for either. reqCount, ok := gw.limiter.getCounter("user", "alice", metricReq, windowMin, time.Now()) if !ok || reqCount != 0 { @@ -475,7 +475,7 @@ func TestHandleMessages_RateLimited_Returns429(t *testing.T) { } // Envelope-shape assertion (item 8 fix, 2026-08-22 review): now that - // admitRequest threads an envelopeWriter through + // admitRequestForRoute threads an envelopeWriter through // (routes_unified.go's writeLimitViolationEnvelope), a 429 on this // route must answer in Anthropic's shape like every other error this // route produces, not OpenAI's flat one. @@ -500,6 +500,70 @@ func TestHandleMessages_RateLimited_Returns429(t *testing.T) { } } +// TestHandleMessages_RateLimited_RecordsRateLimitEvent proves a +// /v1/messages 429 is recorded to GET /admin/api/events (F3 hook 1, v0.3 +// dashboard task) exactly like every other metered route: handleMessages +// switched from the route-blind admitRequest to admitRequestForRoute +// (routes_unified.go) with routeMessages, so recordLimitEvent now runs +// on this route's own rejection path too. Mirrors +// admin_events_test.go's TestAdminEvents_RateLimitEvent, scoped to this +// route's own Anthropic-shaped request/response. +func TestHandleMessages_RateLimited_RecordsRateLimitEvent(t *testing.T) { + const anthResp = `{"id":"msg_1","type":"message","role":"assistant","content":[{"type":"text","text":"ok"}],"model":"claude-real","stop_reason":"end_turn","usage":{"input_tokens":1,"output_tokens":1}}` + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + w.Header().Set("Content-Type", "application/json") + w.WriteHeader(http.StatusOK) + _, _ = w.Write([]byte(anthResp)) + })) + defer srv.Close() + + cfg := CreateConfig() + cfg.Admin = &AdminConfig{Enabled: true} + cfg.Providers = map[string]*ProviderConfig{"anthropic": {Type: providerTypeAnthropic, BaseURL: srv.URL, APIKey: "sk-ant-up", Models: []string{"claude-test"}}} // #nosec G101 -- test fixture literal, not a real credential + cfg.Groups = map[string]*GroupConfig{"default": {}} + cfg.Users = &UsersConfig{Inline: []*UserConfig{ + {Name: "alice", Group: "default", APIKey: "sk-alice", Limits: &LimitsConfig{RequestsPerMinute: 1}}, + {Name: "admin1", Group: "default", APIKey: "sk-admin1", Admin: true}, + }} + next := http.HandlerFunc(func(http.ResponseWriter, *http.Request) {}) + h, err := New(context.Background(), next, cfg, "llmgw") + if err != nil { + t.Fatalf("New: %v", err) + } + + body := map[string]any{"model": "claude-test", "max_tokens": 10, "messages": []any{map[string]any{"role": "user", "content": "hi"}}} + + rec1 := httptest.NewRecorder() + h.ServeHTTP(rec1, newMessagesRequest(t, body, "x-api-key", "sk-alice")) + if rec1.Code != http.StatusOK { + t.Fatalf("1st call: status = %d, want 200, body=%s", rec1.Code, rec1.Body.String()) + } + + rec2 := httptest.NewRecorder() + h.ServeHTTP(rec2, newMessagesRequest(t, body, "x-api-key", "sk-alice")) + if rec2.Code != http.StatusTooManyRequests { + t.Fatalf("2nd call: status = %d, want 429 (over requestsPerMinute:1), body=%s", rec2.Code, rec2.Body.String()) + } + + got := getAdminEvents(t, h, "?limit=10") + if len(got.Events) == 0 { + t.Fatal("want at least one event") + } + ev := got.Events[0] // newest first + if ev.Kind != eventKindRateLimit { + t.Errorf("Kind = %q, want %q", ev.Kind, eventKindRateLimit) + } + if ev.Route != routeMessages { + t.Errorf("Route = %q, want %q", ev.Route, routeMessages) + } + if ev.User != "alice" { + t.Errorf("User = %q, want %q", ev.User, "alice") + } + if ev.Status != http.StatusTooManyRequests { + t.Errorf("Status = %d, want 429", ev.Status) + } +} + // TestHandleMessages_TranslationFailureAfterBilledUsage_PreservesUsage is // the regression for item 1 (CRITICAL, 2026-08-22 review): an // openai-type provider's response can succeed (200, real usage the diff --git a/routes_passthrough.go b/routes_passthrough.go index ecb4931..0652297 100644 --- a/routes_passthrough.go +++ b/routes_passthrough.go @@ -1192,6 +1192,7 @@ func (g *Gateway) handlePassthrough(w http.ResponseWriter, r *http.Request, u *u scopes := withTotalScope(buildLimitScopes(u, grp)) if violation := g.limiter.checkAndCount(scopes); violation != nil { + g.recordLimitEvent(scopes, routePassthrough, violation) writeLimitViolation(w, violation) return } @@ -1225,6 +1226,7 @@ func (g *Gateway) handlePassthrough(w http.ResponseWriter, r *http.Request, u *u canonical := providerName + "/" + model if !priceKnown(canonical, model, g.cfg.Pricing, g.cfg.ModelMeta) { g.logf("passthrough: refusing model %q: it has no configured price, and a cost budget applies to this caller that cannot be enforced without one", model) + g.recordUnpricedRefusalEvent(scopes, canonical, providerName, routePassthrough) // F3 hook 5 (item 5, this round) writeOAIError(w, http.StatusPaymentRequired, "invalid_request_error", fmt.Sprintf("model %q has no configured price, so the cost budget that applies to this request cannot be enforced; add a \"pricing\" entry for it, or set allowUnpricedWithCostBudget to serve it unbounded", model)) return @@ -1257,6 +1259,7 @@ func (g *Gateway) handlePassthrough(w http.ResponseWriter, r *http.Request, u *u } result, complete := g.proxyUpstream(w, r, upstreamURL, adapter.httpClient(), adapter.injectAuth, providerCredentialRetargetHeaders, true, "passthrough (provider "+providerName+")", adapter.requestTimeout()) + g.recordProxyEvent(scopes, providerName, routePassthrough, result) // F3 hook 3 (v0.3 dashboard task) // Finding 2 fix (review-routes.md): a build/dial failure that never // produced any response at all (result.status == 0 — proxyUpstream diff --git a/routes_passthrough_test.go b/routes_passthrough_test.go index 52bcd5e..ebfa34d 100644 --- a/routes_passthrough_test.go +++ b/routes_passthrough_test.go @@ -1800,6 +1800,7 @@ func TestHandlePassthrough_UnpricedModelCostBudget_Returns402(t *testing.T) { wantCode int allowUnpricedWithCostBudget bool wantUpstreamCalled bool + wantEvent bool // item 5, this round: the 402 refusal must reach the events feed }{ { name: "unpriced model, cost budget configured: refused", @@ -1808,6 +1809,7 @@ func TestHandlePassthrough_UnpricedModelCostBudget_Returns402(t *testing.T) { costBudget: 5, wantCode: http.StatusPaymentRequired, wantUpstreamCalled: false, + wantEvent: true, }, { name: "unpriced model, no cost budget: passes", @@ -1881,6 +1883,22 @@ func TestHandlePassthrough_UnpricedModelCostBudget_Returns402(t *testing.T) { if upstreamCalled != tt.wantUpstreamCalled { t.Errorf("upstreamCalled = %v, want %v", upstreamCalled, tt.wantUpstreamCalled) } + if tt.wantEvent { + events := h.(*Gateway).events.ring.snapshot(eventRingCap) + if len(events) == 0 { + t.Fatal("want an event recorded for the 402 refusal, got none") + } + ev := events[0] // newest first + if ev.Kind != eventKindUnpriced { + t.Errorf("Kind = %q, want %q", ev.Kind, eventKindUnpriced) + } + if ev.Status != http.StatusPaymentRequired { + t.Errorf("Status = %d, want %d", ev.Status, http.StatusPaymentRequired) + } + if ev.Route != routePassthrough { + t.Errorf("Route = %q, want %q", ev.Route, routePassthrough) + } + } }) } } diff --git a/routes_unified.go b/routes_unified.go index 4efc5a9..31d060b 100644 --- a/routes_unified.go +++ b/routes_unified.go @@ -171,8 +171,8 @@ func (g *Gateway) handleEmbeddings(w http.ResponseWriter, r *http.Request, u *us // ordering (decode, resolve model, THEN checkAndCount) meant a caller // already over their requestsPerMinute paid the full cost of reading and // json-decoding a body that was always going to be discarded. -// admitRequest needs only u/grp, already available as this function's -// own parameters, so it has no reason to wait for the body. Model +// admitRequestForRoute needs only u/grp, already available as this +// function's own parameters, so it has no reason to wait for the body. Model // resolution still runs AFTER decode — it genuinely needs the client's // requested model id, which only exists once the body is parsed — so // its own errors (unknown/denied model) are still reported after a @@ -206,19 +206,20 @@ func (g *Gateway) handleEmbeddings(w http.ResponseWriter, r *http.Request, u *us // here since neither is visible from the diff alone. // // SHARED CORE (item 7 fix, 2026-08-22 review): routes_messages.go's -// handleMessages needs admitRequest and the body decode in a DIFFERENT -// relative order than this route does (its own doc comment explains -// why — a streaming request must never touch the rate-limit counters at -// all, which means it has to know "is this streaming" from the decoded -// body before admitRequest ever runs). That is the one genuine ordering -// difference between the two routes, and it is why THIS function still -// owns admitRequest/readAndDecodeUnifiedBody directly rather than folding +// handleMessages needs admitRequestForRoute and the body decode in a +// DIFFERENT relative order than this route does (its own doc comment +// explains why — a streaming request must never touch the rate-limit +// counters at all, which means it has to know "is this streaming" from +// the decoded body before admitRequestForRoute ever runs). That is the +// one genuine ordering difference between the two routes, and it is why +// THIS function still owns admitRequestForRoute/readAndDecodeUnifiedBody +// directly rather than folding // them into runMeteredCall too — everything after both are done is // identical regardless of wire shape, and lives in runMeteredCall alone. func (g *Gateway) runUnified(w http.ResponseWriter, r *http.Request, u *user, grp *group, endpoint string, call adapterCall) { sw := &statusTrackingWriter{ResponseWriter: w} - scopes, ok := g.admitRequest(sw, u, grp, writeOAIError) + scopes, ok := g.admitRequestForRoute(sw, u, grp, writeOAIError, eventRouteForEndpoint(endpoint)) if !ok { return } @@ -243,7 +244,7 @@ func (g *Gateway) runUnified(w http.ResponseWriter, r *http.Request, u *user, gr // routes_messages.go's handleMessages) that is genuinely identical // regardless of wire shape (item 7 fix, 2026-08-22 review: this body used // to be duplicated almost verbatim in routes_messages.go). Callers have -// already run admitRequest (rate limiting) and decoded the request body +// already run admitRequestForRoute (rate limiting) and decoded the request body // into req, in whichever relative order their own route needs (see // runUnified's own doc comment for why that order differs for // /v1/messages) — this function starts only once both are done. @@ -365,11 +366,12 @@ func (g *Gateway) runMeteredCall(sw *statusTrackingWriter, r *http.Request, scop // chasing further doomed candidates and wrongly opening a // perfectly healthy provider's request-health breaker. if r.Context().Err() != nil { + g.recordUpstreamEvent(scopes, candidates[i-1].canonical, lastProviderName, eventRouteForEndpoint(endpoint), lastErr) g.handleAdapterErrorEnvelope(sw, lastErr, lastProviderName, logPrefix, envelope, writeUpstream) return } - // checkAndCount above (admitRequest, this file) already + // checkAndCount above (admitRequestForRoute, this file) already // counted this request exactly once — never double-count: a // failover attempt is a NEW upstream attempt, not a new // logical request, so nothing here calls checkAndCount @@ -530,7 +532,7 @@ func (g *Gateway) runMeteredCall(sw *statusTrackingWriter, r *http.Request, scop // fire. Serving the request would spend the operator's money // against a control that provably cannot stop it. // - // Placed HERE, not in admitRequest, because admitRequest runs + // Placed HERE, not in admitRequestForRoute, because admitRequestForRoute runs // before the body is decoded (runUnified's own ordering) and so // before any model id exists; this is the first point where the // SERVING model is known. It is before call(), so nothing has been @@ -549,6 +551,7 @@ func (g *Gateway) runMeteredCall(sw *statusTrackingWriter, r *http.Request, scop !priceKnown(cand.canonical, cand.upstreamModel, g.cfg.Pricing, g.cfg.ModelMeta) && scopesHaveCostBudget(scopes) { g.logf("%s: refusing model %q: it has no configured price, and a cost budget applies to this caller that cannot be enforced without one", logPrefix, cand.canonical) + g.recordUnpricedRefusalEvent(scopes, cand.canonical, cand.providerName, eventRouteForEndpoint(endpoint)) // F3 hook 5 (item 5, this round) envelope(sw, http.StatusPaymentRequired, "invalid_request_error", fmt.Sprintf("model %q has no configured price, so the cost budget that applies to this request cannot be enforced; add a \"pricing\" entry for it, or set allowUnpricedWithCostBudget to serve it unbounded", cand.canonical)) return @@ -722,6 +725,7 @@ func (g *Gateway) runMeteredCall(sw *statusTrackingWriter, r *http.Request, scop // before this feature existed, regardless of how many candidates // remain. if sw.wroteHeader { + g.recordUpstreamEvent(scopes, cand.canonical, providerName, eventRouteForEndpoint(endpoint), callErr) g.handleAdapterErrorEnvelope(sw, callErr, providerName, logPrefix, envelope, writeUpstream) return } @@ -743,6 +747,7 @@ func (g *Gateway) runMeteredCall(sw *statusTrackingWriter, r *http.Request, scop g.errorf("%s: provider %q returned 404 for model %q; failing over to %q — this usually means a real provider/model configuration mistake, not a transient outage", logPrefix, providerName, requestedModel, candidates[i+1].providerName) } if !hasNext { + g.recordUpstreamEvent(scopes, cand.canonical, providerName, eventRouteForEndpoint(endpoint), callErr) g.handleAdapterErrorEnvelope(sw, callErr, providerName, logPrefix, envelope, writeUpstream) return } @@ -801,9 +806,10 @@ func buildLimitScopes(u *user, grp *group) []limitScope { // withTotalScope returns scopes with the synthetic total scope // (totalScopeKind/totalScopeID, limits.go) appended — the single helper -// every metered route (runUnified above, via admitRequest below; +// every metered route (runUnified above, via admitRequestForRoute below; // handleImagesGenerations/handleAudioSpeech/handleAudioTranscriptions, -// routes_media.go, via the same admitRequest; handlePassthrough, +// routes_media.go, via the same admitRequestForRoute; handleMessages, +// routes_messages.go, via the same admitRequestForRoute; handlePassthrough, // routes_passthrough.go; handleTargetProxy, mcp_a2a.go; handleMCPFederated, // mcp_federation.go) calls around its own buildLimitScopes result, so none // of them can forget it and none of them duplicate the scope literal. @@ -818,9 +824,9 @@ func withTotalScope(scopes []limitScope) []limitScope { return append(scopes, limitScope{kind: totalScopeKind, id: totalScopeID, limits: nil}) } -// admitRequest enforces per-user/per-group/total REQUEST-RATE limits -// (checkAndCount) using only u and grp — never a request body — so every -// caller can, and now does, call this before reading or decoding +// admitRequestForRoute enforces per-user/per-group/total REQUEST-RATE +// limits (checkAndCount) using only u and grp — never a request body — +// so every caller can, and does, call this before reading or decoding // anything (security review finding 1a, 2026-08-22): a caller already // over budget is refused on the strength of who they are alone, never // after paying the cost of reading and json-decoding a body that turns @@ -829,7 +835,10 @@ func withTotalScope(scopes []limitScope) []limitScope { // call, rather than rebuilding (and risking scope-list drift from) a // second buildLimitScopes/withTotalScope pair. A violation writes its // response to sw itself, via envelope (writeLimitViolationEnvelope, -// below), and returns ok=false. +// below), records a rate_limit/budget/store_down event (F3 hook 1, v0.3 +// dashboard task) via recordLimitEvent so GET /admin/api/events can +// attribute the rejection to route — one of the Route vocabulary +// constants, events.go — and returns ok=false. // // Shared verbatim by every unified/media/messages route (runUnified // above; handleImagesGenerations/handleAudioSpeech/ @@ -841,9 +850,10 @@ func withTotalScope(scopes []limitScope) []limitScope { // 2026-08-22 review) lets routes_messages.go answer a violation in // Anthropic's own error shape instead of OpenAI's, without a second copy // of this function's own logic. -func (g *Gateway) admitRequest(sw *statusTrackingWriter, u *user, grp *group, envelope envelopeWriter) (scopes []limitScope, ok bool) { +func (g *Gateway) admitRequestForRoute(sw *statusTrackingWriter, u *user, grp *group, envelope envelopeWriter, route string) (scopes []limitScope, ok bool) { scopes = withTotalScope(buildLimitScopes(u, grp)) if violation := g.limiter.checkAndCount(scopes); violation != nil { + g.recordLimitEvent(scopes, route, violation) writeLimitViolationEnvelope(sw, violation, envelope) return scopes, false } @@ -932,6 +942,14 @@ func (g *Gateway) acquireBodyAdmission(sw *statusTrackingWriter, envelope envelo default: sw.Header().Set("Retry-After", strconv.Itoa(bodyAdmissionRetryAfterSeconds)) envelope(sw, http.StatusServiceUnavailable, "server_error", "server is at capacity; try again shortly") + // F3 hook 5 (v0.3 dashboard task, Q4: "capacity 503 without user: + // record user-less"): this semaphore is shared across every + // unified/media/messages caller (readAndDecodeUnifiedBody/ + // decodeMediaJSONRequest/readAdmittedCapped) and fires before any + // caller-specific context is threaded through, so the event + // carries no User/Group/route attribution — routeCapacity is a + // fixed, documented simplification (events.go's own doc comment). + g.recordEvent(gatewayEvent{Route: routeCapacity, Kind: eventKindCapacity, Message: "server is at capacity; try again shortly", Status: http.StatusServiceUnavailable}) return func() {}, false } } @@ -1076,7 +1094,7 @@ func writeLimitViolationEnvelope(w http.ResponseWriter, v *limitViolation, envel // writeLimitViolation is writeLimitViolationEnvelope pinned to the // OpenAI envelope shape — the thin wrapper every existing direct call // site (mcp_a2a.go, mcp_federation.go, routes_passthrough.go, all of -// which call checkAndCount themselves rather than through admitRequest) +// which call checkAndCount themselves rather than through admitRequestForRoute) // keeps calling unchanged. func writeLimitViolation(w http.ResponseWriter, v *limitViolation) { writeLimitViolationEnvelope(w, v, writeOAIError) diff --git a/routes_unified_test.go b/routes_unified_test.go index bae5d4e..6fec182 100644 --- a/routes_unified_test.go +++ b/routes_unified_test.go @@ -2322,6 +2322,74 @@ func TestHandleChat_ContextDeadlineExceeded_RecordsProviderFailure(t *testing.T) } } +// TestHandleChat_UnpricedModelCostBudget_Returns402AndRecordsEvent is the +// unified route's own analog of routes_passthrough_test.go's +// TestHandlePassthrough_UnpricedModelCostBudget_Returns402: it drives a +// REAL request for an unpriced model against a caller with a configured +// cost budget through the security-audit run-1 finding F-1 gate +// (routes_unified.go, just before call()), and additionally proves item 5 +// (this round): the refusal now reaches GET /admin/api/events as an +// eventKindUnpriced/402 entry, not just a logged line — the ONLY route- +// level coverage this specific 402 gate had before this test was the +// upstream body never being reached (implicitly, via other tests); this +// asserts the response, the event, and that the upstream was never +// called, together. +func TestHandleChat_UnpricedModelCostBudget_Returns402AndRecordsEvent(t *testing.T) { + var upstreamCalled bool + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + upstreamCalled = true + w.WriteHeader(http.StatusOK) + })) + defer srv.Close() + + cfg := CreateConfig() + cfg.Providers = map[string]*ProviderConfig{ + "openai": {Type: "openai", BaseURL: srv.URL, APIKey: "sk-up", Models: []string{"totally-unpriced-model"}}, + } + cfg.Groups = map[string]*GroupConfig{"default": {}} + cfg.Users = &UsersConfig{Inline: []*UserConfig{ + {Name: "alice", Group: "default", APIKey: "sk-alice", Limits: &LimitsConfig{CostPerDayUSD: 5}}, + }} + 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") + } + + rec := httptest.NewRecorder() + h.ServeHTTP(rec, newUnifiedRequest(t, http.MethodPost, "/v1/chat/completions", "sk-alice", + map[string]any{"model": "totally-unpriced-model", "messages": []any{map[string]any{"role": "user", "content": "hi"}}})) + + if rec.Code != http.StatusPaymentRequired { + t.Fatalf("status = %d, want %d, body=%s", rec.Code, http.StatusPaymentRequired, rec.Body.String()) + } + if upstreamCalled { + t.Error("upstream must never be called: the refusal fires before call()") + } + + events := gw.events.ring.snapshot(eventRingCap) + if len(events) == 0 { + t.Fatal("want an event recorded for the 402 refusal, got none") + } + ev := events[0] // newest first + if ev.Kind != eventKindUnpriced { + t.Errorf("Kind = %q, want %q", ev.Kind, eventKindUnpriced) + } + if ev.Status != http.StatusPaymentRequired { + t.Errorf("Status = %d, want %d", ev.Status, http.StatusPaymentRequired) + } + if ev.Route != routeChatCompletions { + t.Errorf("Route = %q, want %q", ev.Route, routeChatCompletions) + } + if ev.User != "alice" { + t.Errorf("User = %q, want %q", ev.User, "alice") + } +} + // --- security review finding 1, 2026-08-22: admission before decode, // body-admission semaphore, narrower unified body cap --- @@ -2343,7 +2411,7 @@ func (b *readTrackingBody) Close() error { return nil } // TestHandleChat_RequestLimitExceeded_BodyNeverRead is the GATE's own // explicit requirement: a 429'd user's body must never be read at all, -// proving admitRequest now runs strictly before io.ReadAll in runUnified +// proving admitRequestForRoute now runs strictly before io.ReadAll in runUnified // (finding 1a) rather than merely returning the same status code for a // different reason. func TestHandleChat_RequestLimitExceeded_BodyNeverRead(t *testing.T) { @@ -2382,7 +2450,7 @@ func TestHandleChat_RequestLimitExceeded_BodyNeverRead(t *testing.T) { t.Fatalf("status = %d, want 429, body=%s", rec2.Code, rec2.Body.String()) } if tracked.called { - t.Error("a 429'd request's body must never be read — admitRequest must run before io.ReadAll") + t.Error("a 429'd request's body must never be read — admitRequestForRoute must run before io.ReadAll") } } @@ -2410,7 +2478,7 @@ func TestHandleImagesGenerations_RequestLimitExceeded_BodyNeverRead(t *testing.T t.Fatalf("status = %d, want 429, body=%s", rec2.Code, rec2.Body.String()) } if tracked.called { - t.Error("a 429'd media request's body must never be read — admitRequest must run before decode") + t.Error("a 429'd media request's body must never be read — admitRequestForRoute must run before decode") } }