diff --git a/limits.go b/limits.go index 3d29d01..00338b1 100644 --- a/limits.go +++ b/limits.go @@ -212,9 +212,13 @@ func (m *memoryStore) sweepLocked(now time.Time) { // arrived). type usage struct { prompt, completion int64 - // estimated is set by a later task's streaming/estimation path; this - // task only produces the field for that interface, never reads it. - estimated bool //nolint:unused // interface field for a later task, see comment above + // estimated is true when prompt/completion were derived from a + // tokenizer estimate (request body size ÷ 4) rather than the + // provider's own reported usage. routes_unified.go's runUnified reads + // this to log the estimate explicitly, so a caller reading logs can + // tell an estimated cost from a provider-reported one, per the spec's + // "logged as estimated" requirement. + estimated bool } // total returns the request's combined prompt and completion tokens. diff --git a/llmgateway.go b/llmgateway.go index b9fa238..5adfcfe 100644 --- a/llmgateway.go +++ b/llmgateway.go @@ -265,6 +265,7 @@ func (g *Gateway) ServeHTTP(w http.ResponseWriter, r *http.Request) { if r.Method == http.MethodPost && (r.URL.Path == "/v1/chat/completions" || r.URL.Path == "/v1/embeddings") { u, grp, ok := g.auth.identify(r) + g.logAuthEvent(ok, authEventUserName(u), r) if !ok { writeOAIError(sw, http.StatusUnauthorized, "authentication_error", "invalid or missing API key") return @@ -278,7 +279,8 @@ func (g *Gateway) ServeHTTP(w http.ResponseWriter, r *http.Request) { } if r.Method == http.MethodGet && (r.URL.Path == "/v1/mcp/servers" || r.URL.Path == "/v1/agents") { - _, grp, ok := g.auth.identify(r) + u, grp, ok := g.auth.identify(r) + g.logAuthEvent(ok, authEventUserName(u), r) if !ok { writeOAIError(sw, http.StatusUnauthorized, "authentication_error", "invalid or missing API key") return @@ -293,6 +295,7 @@ func (g *Gateway) ServeHTTP(w http.ResponseWriter, r *http.Request) { if name, rest, ok := targetRoute(r.URL.EscapedPath(), targetKindMCP); ok { u, grp, authOK := g.auth.identify(r) + g.logAuthEvent(authOK, authEventUserName(u), r) if !authOK { writeOAIError(sw, http.StatusUnauthorized, "authentication_error", "invalid or missing API key") return @@ -302,6 +305,7 @@ func (g *Gateway) ServeHTTP(w http.ResponseWriter, r *http.Request) { } if name, rest, ok := targetRoute(r.URL.EscapedPath(), targetKindAgent); ok { u, grp, authOK := g.auth.identify(r) + g.logAuthEvent(authOK, authEventUserName(u), r) if !authOK { writeOAIError(sw, http.StatusUnauthorized, "authentication_error", "invalid or missing API key") return @@ -313,6 +317,7 @@ func (g *Gateway) ServeHTTP(w http.ResponseWriter, r *http.Request) { if providerName, rest, ok := passthroughRoute(r.URL.EscapedPath()); ok { if _, known := g.adapters[providerName]; known { u, grp, ok := g.auth.identify(r) + g.logAuthEvent(ok, authEventUserName(u), r) if !ok { writeOAIError(sw, http.StatusUnauthorized, "authentication_error", "invalid or missing API key") return diff --git a/llmgateway_test.go b/llmgateway_test.go index 05fdcbf..a5744f3 100644 --- a/llmgateway_test.go +++ b/llmgateway_test.go @@ -176,6 +176,95 @@ func TestGateway_Logf_WritesInfoPrefix(t *testing.T) { } } +// TestServeHTTP_AuthFailed_LogsMethodPathNotKey proves a failed +// authentication attempt (I3) emits a log line naming the method and path, +// and proves the presented (wrong) API key never appears in that line — +// key material must never be logged, even on a failure. +func TestServeHTTP_AuthFailed_LogsMethodPathNotKey(t *testing.T) { + const presentedKey = "sk-wrong-should-never-be-logged" + + next := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {}) + cfg := CreateConfig() + cfg.Providers = map[string]*ProviderConfig{"openai": {Type: "openai", APIKey: "k"}} + cfg.Groups = map[string]*GroupConfig{"default": {}} + cfg.Users = &UsersConfig{Inline: []*UserConfig{{Name: "alice", Group: "default", APIKey: "sk-alice"}}} + h, err := New(context.Background(), next, cfg, "llmgw") + if err != nil { + t.Fatalf("New: %v", err) + } + + origStderr := os.Stderr + r, w, _ := os.Pipe() + os.Stderr = w + + req := httptest.NewRequest(http.MethodPost, "/v1/chat/completions", strings.NewReader(`{}`)) + req.Header.Set("Authorization", "Bearer "+presentedKey) + rec := httptest.NewRecorder() + h.ServeHTTP(rec, req) + + _ = w.Close() // closing the pipe write end to unblock the read; error not actionable in a test + os.Stderr = origStderr + var buf bytes.Buffer + if _, err := io.Copy(&buf, r); err != nil { + t.Fatalf("io.Copy: %v", err) + } + logged := buf.String() + + if rec.Code != http.StatusUnauthorized { + t.Fatalf("status = %d, want 401, body=%s", rec.Code, rec.Body.String()) + } + if !strings.Contains(logged, "auth failed") || !strings.Contains(logged, "POST") || !strings.Contains(logged, "/v1/chat/completions") { + t.Fatalf("want stderr to contain an auth-failed line with method and path, got %q", logged) + } + if strings.Contains(logged, presentedKey) { + t.Fatalf("stderr contains the presented API key %q — key material must never be logged: %q", presentedKey, logged) + } +} + +// TestServeHTTP_AuthOK_LogsUserNameAndRoute proves a successful +// authentication attempt logs the resolved user's name and the route, +// without ever logging the API key that authenticated them. +func TestServeHTTP_AuthOK_LogsUserNameAndRoute(t *testing.T) { + const presentedKey = "sk-alice-should-never-be-logged" + + next := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {}) + cfg := CreateConfig() + cfg.Providers = map[string]*ProviderConfig{"openai": {Type: "openai", APIKey: "k"}} + cfg.Groups = map[string]*GroupConfig{"default": {}} + cfg.Users = &UsersConfig{Inline: []*UserConfig{{Name: "alice", Group: "default", APIKey: presentedKey}}} + h, err := New(context.Background(), next, cfg, "llmgw") + if err != nil { + t.Fatalf("New: %v", err) + } + + origStderr := os.Stderr + r, w, _ := os.Pipe() + os.Stderr = w + + req := httptest.NewRequest(http.MethodGet, "/v1/models", nil) + req.Header.Set("Authorization", "Bearer "+presentedKey) + rec := httptest.NewRecorder() + h.ServeHTTP(rec, req) + + _ = w.Close() // closing the pipe write end to unblock the read; error not actionable in a test + os.Stderr = origStderr + var buf bytes.Buffer + if _, err := io.Copy(&buf, r); err != nil { + t.Fatalf("io.Copy: %v", err) + } + logged := buf.String() + + if rec.Code != http.StatusOK { + t.Fatalf("status = %d, want 200, body=%s", rec.Code, rec.Body.String()) + } + if !strings.Contains(logged, "auth ok") || !strings.Contains(logged, `"alice"`) || !strings.Contains(logged, "/v1/models") { + t.Fatalf("want stderr to contain an auth-ok line naming user alice and route /v1/models, got %q", logged) + } + if strings.Contains(logged, presentedKey) { + t.Fatalf("stderr contains the presented API key %q — key material must never be logged: %q", presentedKey, logged) + } +} + func TestGateway_Errorf_WritesErrorPrefix(t *testing.T) { next := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {}) cfg := CreateConfig() diff --git a/logger.go b/logger.go index 1cd8905..af06bd9 100644 --- a/logger.go +++ b/logger.go @@ -2,6 +2,7 @@ package traefikllmgateway import ( "fmt" + "net/http" "os" ) @@ -16,3 +17,28 @@ func (g *Gateway) logf(format string, args ...any) { func (g *Gateway) errorf(format string, args ...any) { fmt.Fprintf(os.Stderr, "llmgw[%s] ERROR %s\n", g.name, fmt.Sprintf(format, args...)) } + +// logAuthEvent logs one authentication attempt, at the point one of +// authStore.identify's six call sites resolves it. A failure logs the +// method, path, and remote address the request came from; a success logs +// the resolved user's name alongside the same method and path. Neither +// line ever includes the presented API key itself — identify resolves a +// key to a *user and hands this function only that user's name, never the +// key it authenticated. +func (g *Gateway) logAuthEvent(ok bool, userName string, r *http.Request) { + if !ok { + g.logf("auth failed: %s %s from %s", r.Method, r.URL.Path, r.RemoteAddr) + return + } + g.logf("auth ok: user %q %s %s", userName, r.Method, r.URL.Path) +} + +// authEventUserName extracts u's name for logAuthEvent's userName +// argument, or "" when u is nil — identify's failure path, which never +// resolves a user. +func authEventUserName(u *user) string { + if u == nil { + return "" + } + return u.name +} diff --git a/mcp_a2a_test.go b/mcp_a2a_test.go index a6be3f3..e38f25d 100644 --- a/mcp_a2a_test.go +++ b/mcp_a2a_test.go @@ -204,6 +204,53 @@ func TestHandleTargetProxy_StripsGatewayAuth_NoUpstreamInjection(t *testing.T) { } } +// TestHandleTargetProxy_ClientAPIKeyHeaderStripped_NoUpstreamInjection +// proves the client's gateway credential, presented via x-api-key rather +// than Authorization, never reaches an MCP target. handleTargetProxy +// injects no credential at all (unlike a provider adapter's injectAuth), +// so if gatewayCredentialHeaders' X-Api-Key entry were ever dropped from +// the strip set, the client's own key would pass straight through +// copyHeadersExcept to the upstream target (I1: the sibling test above +// authenticates via Authorization and never sends x-api-key at all, so it +// never exercised this strip entry). +func TestHandleTargetProxy_ClientAPIKeyHeaderStripped_NoUpstreamInjection(t *testing.T) { + var gotAPIKeyHeader string + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + gotAPIKeyHeader = r.Header.Get("x-api-key") + w.WriteHeader(http.StatusOK) + _, _ = w.Write([]byte("mcp-ok")) + })) + defer srv.Close() + + cfg := CreateConfig() + cfg.Providers = map[string]*ProviderConfig{"openai": {Type: "openai", APIKey: "k"}} + cfg.MCPServers = map[string]*TargetConfig{"alpha": {URL: srv.URL}} + cfg.Groups = map[string]*GroupConfig{"default": {}} + cfg.Users = &UsersConfig{Inline: []*UserConfig{{Name: "alice", Group: "default", APIKey: "gateway-key-must-not-leak"}}} + 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) + } + + req := httptest.NewRequest(http.MethodGet, "/mcp/alpha/tools/list", nil) + // Gateway auth presented via x-api-key only (no Authorization header) — + // presentedKey falls back to x-api-key when Authorization is absent. + req.Header.Set("x-api-key", "gateway-key-must-not-leak") + rec := httptest.NewRecorder() + h.ServeHTTP(rec, req) + + if rec.Code != http.StatusOK { + t.Fatalf("status = %d, want 200, body=%s", rec.Code, rec.Body.String()) + } + if rec.Body.String() != "mcp-ok" { + t.Errorf("body = %q, want verbatim upstream body", rec.Body.String()) + } + if gotAPIKeyHeader != "" { + t.Errorf("upstream saw x-api-key = %q, want empty (MCP target proxy injects nothing; the client's gateway credential must be stripped)", gotAPIKeyHeader) + } +} + // --- SSE-safe streaming through the target proxy --- func TestHandleTargetProxy_SSE_FlushesIncrementally(t *testing.T) { diff --git a/provider_openai.go b/provider_openai.go index dd9bce7..7e19923 100644 --- a/provider_openai.go +++ b/provider_openai.go @@ -88,12 +88,17 @@ type chatStreamChunk struct { // chatCompletion implements providerAdapter. // -// When req["stream"] is true, chatCompletion injects -// stream_options.include_usage=true into the upstream request only when -// the client did not already set stream_options itself — remembering -// whether the client asked, so the streaming response can suppress the -// resulting usage-only chunk from a client that never asked for it while -// still capturing its usage for accounting. +// When req["stream"] is true, chatCompletion always forces +// stream_options.include_usage=true on the outgoing request — a client +// sending include_usage=false must not be able to suppress upstream usage +// reporting and escape token/cost budgets (controller ruling C1). It merges +// that into a copy of the client's own stream_options map when present, so +// the caller's map is never mutated in place. clientAskedUsage records +// whether the client itself asked for usage (via isTruthy on the client's +// own include_usage value, never the forced upstream one), so the +// streaming response can still suppress the resulting usage-only chunk +// from a client that never asked for it, while always capturing the usage +// for accounting. func (a *openaiAdapter) chatCompletion(ctx context.Context, w http.ResponseWriter, req map[string]any) (usage, error) { // gatewayAliasKey must never reach the real provider: an openai-type // adapter forwards req verbatim as the upstream wire body, so a @@ -106,11 +111,15 @@ func (a *openaiAdapter) chatCompletion(ctx context.Context, w http.ResponseWrite streaming, _ := req["stream"].(bool) clientAskedUsage := false if streaming { - if _, present := req["stream_options"]; present { - clientAskedUsage = true - } else { - req["stream_options"] = map[string]any{"include_usage": true} + merged := map[string]any{} + if existing, ok := req["stream_options"].(map[string]any); ok { + for k, v := range existing { + merged[k] = v + } + clientAskedUsage = isTruthy(existing["include_usage"]) } + merged["include_usage"] = true + req["stream_options"] = merged } hdr := a.requestHeaders(true) diff --git a/provider_openai_test.go b/provider_openai_test.go index 6fb7413..ed0b257 100644 --- a/provider_openai_test.go +++ b/provider_openai_test.go @@ -200,9 +200,10 @@ func TestOpenAIAdapter_ChatCompletion_Streaming_ClientDidNotAskUsage(t *testing. } // TestOpenAIAdapter_ChatCompletion_Streaming_ClientAskedUsage proves that -// when the client already set stream_options itself, chatCompletion leaves -// it untouched (does not overwrite it) and forwards the usage-only chunk -// through to the client instead of suppressing it. +// when the client already set stream_options.include_usage=true itself, +// chatCompletion preserves that value (forcing true on top of true is a +// no-op) and forwards the usage-only chunk through to the client instead +// of suppressing it. func TestOpenAIAdapter_ChatCompletion_Streaming_ClientAskedUsage(t *testing.T) { var gotBody []byte srv := newStreamingFakeUpstream(t, &gotBody) @@ -247,6 +248,59 @@ func TestOpenAIAdapter_ChatCompletion_Streaming_ClientAskedUsage(t *testing.T) { } } +// TestOpenAIAdapter_ChatCompletion_Streaming_ClientSuppressesUsage proves +// the C1 fix: a client sending stream_options.include_usage=false must not +// be able to suppress upstream usage reporting and escape token/cost +// budgets. chatCompletion forces include_usage=true upstream regardless, +// still captures the resulting usage for accounting, but derives +// clientAskedUsage from the client's own (false) value — so the usage-only +// chunk is not forwarded to this client. It also proves the merge copies +// the client's stream_options map instead of mutating it in place. +func TestOpenAIAdapter_ChatCompletion_Streaming_ClientSuppressesUsage(t *testing.T) { + var gotBody []byte + srv := newStreamingFakeUpstream(t, &gotBody) + defer srv.Close() + + a := newOpenAIAdapter("p1", srv.URL, "sk-test") + rec := newRecordingResponseWriter() + + clientStreamOptions := map[string]any{"include_usage": false} + req := map[string]any{ + "model": "gpt-5", + "stream": true, + "stream_options": clientStreamOptions, + } + u, err := a.chatCompletion(context.Background(), rec, req) + if err != nil { + t.Fatalf("chatCompletion: %v", err) + } + + if u.prompt != 7 || u.completion != 9 { + t.Errorf("usage = %+v, want {prompt:7 completion:9} (must still be captured despite include_usage=false)", u) + } + + want := "data: " + streamFrames[0] + "\n\n" + + "data: " + streamFrames[1] + "\n\n" + + "data: " + streamFrames[2] + "\n\n" + + "data: [DONE]\n\n" + if got := rec.body.String(); got != want { + t.Errorf("forwarded body = %q, want %q (usage chunk must be suppressed, client never asked)", got, want) + } + + sent := decodeJSONBody(t, gotBody) + so, ok := sent["stream_options"].(map[string]any) + if !ok { + t.Fatalf("upstream request missing stream_options: %v", sent) + } + if so["include_usage"] != true { + t.Errorf("stream_options.include_usage = %v, want true (must be forced regardless of client value — quota bypass otherwise)", so["include_usage"]) + } + + if clientStreamOptions["include_usage"] != false { + t.Errorf("client's own stream_options map was mutated in place: %v, want include_usage still false", clientStreamOptions) + } +} + // TestOpenAIAdapter_ChatCompletion_Streaming_UsageCapturedBeforeAbruptClose // proves that when the upstream sends the usage-only chunk and then the // connection drops (no [DONE], no clean EOF), chatCompletion still returns diff --git a/routes_passthrough_test.go b/routes_passthrough_test.go index 5cd55ea..d40b348 100644 --- a/routes_passthrough_test.go +++ b/routes_passthrough_test.go @@ -182,6 +182,51 @@ func TestHandlePassthrough_ClientKeySwappedForProviderKey(t *testing.T) { } } +// TestHandlePassthrough_OpenAI_ClientAPIKeyHeaderStripped proves the +// client's gateway credential, presented via x-api-key rather than +// Authorization, never reaches an OpenAI passthrough upstream. openai's +// injectAuth only ever sets Authorization, so if gatewayCredentialHeaders' +// X-Api-Key entry were ever dropped from the strip set, this exact header +// would pass straight through copyHeadersExcept to the upstream (I1: the +// sibling test above authenticates via Authorization and never sends +// x-api-key at all, so it never exercised this strip entry; the anthropic +// coverage sends x-api-key but targets a provider whose own injectAuth +// always overwrites it regardless of whether the strip ran). +func TestHandlePassthrough_OpenAI_ClientAPIKeyHeaderStripped(t *testing.T) { + var gotAPIKeyHeader string + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + gotAPIKeyHeader = r.Header.Get("x-api-key") + w.WriteHeader(http.StatusOK) + })) + defer srv.Close() + + cfg := CreateConfig() + cfg.Providers = map[string]*ProviderConfig{ + "openai": {Type: "openai", BaseURL: srv.URL, APIKey: "sk-provider-real"}, + } + cfg.Groups = map[string]*GroupConfig{"default": {}} + cfg.Users = &UsersConfig{Inline: []*UserConfig{{Name: "alice", Group: "default", APIKey: "gateway-key-must-not-leak"}}} + 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) + } + + req := httptest.NewRequest(http.MethodPost, "/openai/v1/audio/speech", strings.NewReader(`{"foo":"bar"}`)) + // Gateway auth presented via x-api-key only (no Authorization header) — + // presentedKey falls back to x-api-key when Authorization is absent. + req.Header.Set("x-api-key", "gateway-key-must-not-leak") + rec := httptest.NewRecorder() + h.ServeHTTP(rec, req) + + if rec.Code != http.StatusOK { + t.Fatalf("status = %d, want 200, body=%s", rec.Code, rec.Body.String()) + } + if gotAPIKeyHeader != "" { + t.Errorf("upstream saw x-api-key = %q, want empty (openai adapter only ever sets Authorization; the client's gateway credential must be stripped)", gotAPIKeyHeader) + } +} + // syncFlushWriter is an http.ResponseWriter/http.Flusher test double that // signals writeCh (non-blocking) after every Write, so a test can prove // two upstream chunks reached the client as two distinct Write calls diff --git a/routes_unified.go b/routes_unified.go index 250c145..00f701a 100644 --- a/routes_unified.go +++ b/routes_unified.go @@ -40,7 +40,8 @@ const gatewayAliasKey = "__alias" // an OpenAI-compatible {"object":"list","data":[...]} envelope of the // models their group can see, via modelRegistry.listFor. func (g *Gateway) handleModels(w http.ResponseWriter, r *http.Request) { - _, grp, ok := g.auth.identify(r) + u, grp, ok := g.auth.identify(r) + g.logAuthEvent(ok, authEventUserName(u), r) if !ok { writeOAIError(w, http.StatusUnauthorized, "authentication_error", "invalid or missing API key") return @@ -139,6 +140,9 @@ func (g *Gateway) runUnified(w http.ResponseWriter, r *http.Request, u *user, gr } } g.limiter.account(scopes, result, unifiedCostMicros(canonical, upstreamModel, result, g.cfg.Pricing)) + if result.estimated { + g.logf("unified route: usage for model %q logged as estimated (%d prompt tokens derived from request body size, not the provider's reported usage)", canonical, result.prompt) + } if callErr != nil { g.handleAdapterError(sw, callErr, adapter.name()) diff --git a/secrets.go b/secrets.go index 632f740..75afb8c 100644 --- a/secrets.go +++ b/secrets.go @@ -28,7 +28,7 @@ func resolveSecret(v string) (string, error) { return val, nil } if path, ok := strings.CutPrefix(v, "file:"); ok { - b, err := os.ReadFile(path) + b, err := os.ReadFile(path) // #nosec G304 -- operator-supplied file path from middleware config if err != nil { return "", fmt.Errorf("llmgateway: cannot read secret file %q: %w", path, err) }