From 9823c0820dd3bf1ebaacbfe2e3ae857bd6ad85c5 Mon Sep 17 00:00:00 2001 From: Juan Antonio Osorio Date: Sun, 19 Jul 2026 20:14:16 +0300 Subject: [PATCH] Audit authorization denials on the proxy runner path Both middleware chain builders in pkg/runner appended the audit middleware after authorization. The proxies wrap handlers in reverse slice order, so audit ran inside authz: a Cedar denial wrote its 403 and returned before the audit middleware ever executed, and denied requests produced no audit events. Audit trails missed exactly the events they most need to record. Move audit before authz in PopulateMiddlewareConfigs (operator and proxyrunner path, used by MCPServer and MCPRemoteProxy) and WithMiddlewareFromFlags (thv run CLI path) so audit wraps authz and records denials with outcome "denied". The audit middleware already classified 401/403 as denied; it just never ran for them. The vMCP Serve path was already correct (its authorization CallGate runs inside the audit middleware); pin that behavior with a test. Correct several comments and docs that described the wrap order backwards (they claimed the last-appended entry is the outermost wrapper; it is the innermost). Fixes #5871 Co-Authored-By: Claude Fable 5 Claude-Session: https://claude.ai/code/session_017attizo5HSwpLcPoimd6Xi --- docs/arch/03-transport-architecture.md | 6 +- docs/middleware.md | 73 ++++----- pkg/runner/authz_audit_integration_test.go | 171 +++++++++++++++++++++ pkg/runner/config_builder.go | 25 +-- pkg/runner/config_builder_test.go | 49 ++++++ pkg/runner/middleware.go | 36 +++-- pkg/runner/middleware_test.go | 38 +++++ pkg/vmcp/server/authz_integration_test.go | 86 +++++++++-- 8 files changed, 411 insertions(+), 73 deletions(-) create mode 100644 pkg/runner/authz_audit_integration_test.go diff --git a/docs/arch/03-transport-architecture.md b/docs/arch/03-transport-architecture.md index 1b944cc836..f1405f1640 100644 --- a/docs/arch/03-transport-architecture.md +++ b/docs/arch/03-transport-architecture.md @@ -213,8 +213,8 @@ All proxy types integrate with the middleware chain: graph LR Client[Client Request] --> MW1[Middleware 1
Auth] MW1 --> MW2[Middleware 2
Parser] - MW2 --> MW3[Middleware 3
Authz] - MW3 --> MW4[Middleware 4
Audit] + MW2 --> MW3[Middleware 3
Audit] + MW3 --> MW4[Middleware 4
Authz] MW4 --> Proxy[Proxy Handler] Proxy --> Container[MCP Server] @@ -227,7 +227,7 @@ graph LR **Implementation:** - `pkg/transport/types/transport.go` - `MiddlewareFunction` and `NamedMiddleware` types -- Middleware applied in reverse order (last registered = outermost) +- Middleware wraps the handler in reverse registration order, so the first registered entry is the outermost wrapper and runs first at request time - Each transport type accepts `[]NamedMiddleware` in constructor (each wraps a `MiddlewareFunction` with its name for logging) ## Remote MCP Server Proxying diff --git a/docs/middleware.md b/docs/middleware.md index 19bb148cd1..559d6b0cb2 100644 --- a/docs/middleware.md +++ b/docs/middleware.md @@ -17,8 +17,8 @@ The middleware chain consists of the following components: 5. **Tool Mapping Middleware**: Enables tool filtering and override capabilities through two complementary middleware components that process outgoing `tools/list` responses and incoming `tools/call` requests (optional) 6. **Usage Metrics Middleware**: Collects anonymous usage metrics for ToolHive development (optional) 7. **Telemetry Middleware**: Instruments requests with OpenTelemetry (optional) -8. **Authorization Middleware**: Evaluates Cedar policies to authorize requests (optional) -9. **Audit Middleware**: Logs request events for compliance and monitoring (optional) +8. **Audit Middleware**: Logs request events for compliance and monitoring (optional) +9. **Authorization Middleware**: Evaluates Cedar policies to authorize requests (optional) 10. **Header Forward Middleware**: Injects custom headers into requests to remote MCP servers (optional) 11. **Recovery Middleware**: Catches panics and returns HTTP 500 errors (always present) @@ -38,7 +38,7 @@ When configured together, the effective order is: 3. MCP parsing 4. Mutating webhooks 5. Validating webhooks -6. Telemetry, authorization, and audit middleware +6. Telemetry, audit, and authorization middleware Multiple webhook definitions of the same type run in configuration order. When multiple `--webhook-config` files are provided, later files override earlier webhook definitions with the same `name`. @@ -59,12 +59,12 @@ Example config files: ```mermaid graph TD - A[Incoming MCP Request] --> R[Recovery Middleware] - R --> B[Authentication Middleware] + A[Incoming MCP Request] --> B[Authentication Middleware] B --> C[MCP Parsing Middleware] - C --> D[Authorization Middleware] - D --> E[Audit Middleware] - E --> F[MCP Server Handler] + C --> E[Audit Middleware] + E --> D[Authorization Middleware] + D --> R[Recovery Middleware] + R --> F[MCP Server Handler] R --> R1[Catch Panics] R1 --> R2[Log Stack Trace] @@ -101,17 +101,15 @@ graph TD ```mermaid sequenceDiagram participant Client - participant Recovery as Recovery participant Auth as Authentication participant Parser as MCP Parser - participant Authz as Authorization participant Audit as Audit + participant Authz as Authorization + participant Recovery as Recovery participant Server as MCP Server - Client->>Recovery: HTTP Request - Note over Recovery: Wraps entire chain to catch panics - - Recovery->>Auth: HTTP Request with JWT + Client->>Auth: HTTP Request with JWT + Note over Recovery: Innermost wrapper: catches panics
from the handler and inner middleware Auth->>Auth: Validate JWT Token Auth->>Auth: Extract Claims Note over Auth: Add claims to context @@ -122,19 +120,23 @@ sequenceDiagram Parser->>Parser: Extract Resource ID & Arguments Note over Parser: Add parsed data to context - Parser->>Authz: Request + Parsed MCP Data + Parser->>Audit: Request + Parsed MCP Data + Note over Audit: Wraps authorization so every
request is logged, including denials + + Audit->>Authz: Request Authz->>Authz: Get Parsed Data from Context Authz->>Authz: Create Cedar Entities Authz->>Authz: Evaluate Policies alt Authorized - Authz->>Audit: Authorized Request - Audit->>Audit: Extract Event Data - Audit->>Audit: Log Audit Event - Audit->>Server: Process Request - Server->>Client: Response + Authz->>Server: Process Request + Server->>Audit: Response + Audit->>Audit: Log Audit Event (outcome success) + Audit->>Client: Response else Unauthorized - Authz->>Client: 403 Forbidden + Authz->>Audit: 403 Forbidden + Audit->>Audit: Log Audit Event (outcome denied) + Audit->>Client: 403 Forbidden else Panic Occurs Recovery->>Recovery: Log stack trace Recovery->>Client: 500 Internal Server Error @@ -389,6 +391,7 @@ thv config usage-metrics enable - Log structured audit events as JSON - Track request duration and outcome - Support file-based and stdout log destinations +- Wrap the authorization middleware so denied requests are still recorded (outcome `denied`) **Event Types**: - `mcp_initialize` - Client initialization events @@ -560,8 +563,7 @@ thv run --transport sse --name my-server --audit-config <(echo '{"component":"my - Prevent server crashes from unhandled panics **Behavior**: -- Always added as the outermost middleware wrapper (added last in chain, executes first) -- Catches any panic from the entire middleware chain and MCP handlers +- On the `vmcp` path it is applied explicitly as the outermost wrapper and catches panics from the entire chain. On the `thv`/`thv-proxyrunner` path it is appended last to the config slice, which makes it the innermost wrapper: it catches panics from the proxy handler, but not from middleware that wrap it - Logs error with stack trace using `logger.Errorf` - Returns generic "Internal Server Error" message (no sensitive details exposed) @@ -618,8 +620,8 @@ The middleware chain uses Go's `context.Context` to pass data between components graph LR A[Request Context] --> B[+ JWT Claims] B --> C[+ Parsed MCP Data] - C --> D[+ Authorization Result] - D --> E[+ Audit Metadata] + C --> E[+ Audit Metadata] + E --> D[+ Authorization Result] subgraph "Authentication" B @@ -629,13 +631,13 @@ graph LR C end - subgraph "Authorization" - D - end - subgraph "Audit" E end + + subgraph "Authorization" + D + end ``` ## Configuration @@ -661,8 +663,8 @@ The middleware order is critical and enforced by the system: 1. **Authentication** - Must be first to establish client identity 2. **MCP Parsing** - Must come after authentication to access JWT context -3. **Authorization** - Must come after parsing to access structured MCP data -4. **Audit** - Must be last to capture the complete request lifecycle +3. **Audit** - Must wrap authorization so every request is logged, including policy denials (outcome `denied`) +4. **Authorization** - Must come after parsing to access structured MCP data ## Error Handling @@ -1001,10 +1003,10 @@ The middleware chain execution order is critical and controlled by the order in 6. **MCP Parser Middleware** (always present) - Parses JSON-RPC MCP requests 7. **Usage Metrics Middleware** (if enabled) - Tracks tool call counts 8. **Telemetry Middleware** (if enabled) - OpenTelemetry instrumentation -9. **Authorization Middleware** (if enabled) - Cedar policy evaluation -10. **Audit Middleware** (if enabled) - Request logging +9. **Audit Middleware** (if enabled) - Request logging +10. **Authorization Middleware** (if enabled) - Cedar policy evaluation 11. **Header Forward Middleware** (if configured for remote servers) - Injects custom headers -12. **Recovery Middleware** (always present) - Catches panics (outermost wrapper) +12. **Recovery Middleware** (always present) - Catches panics **Important Ordering Rules**: - Authentication must come first to establish client identity @@ -1012,8 +1014,9 @@ The middleware chain execution order is critical and controlled by the order in - Token Exchange must come after Upstream Swap if both are used (can further transform the upstream IdP token) - Tool filters should come before MCP Parser to operate on raw requests - MCP Parser must come before Authorization (provides structured MCP data) +- Audit must come before Authorization so it wraps it: policy denials (403) must still produce an audit event with outcome `denied` - Header Forward executes close to the backend handler (innermost position) -- Recovery is always last in config (so it executes first as outermost wrapper) +- Recovery is always last in config, making it the innermost wrapper (the chain wraps in reverse config order, so the first entry is the outermost and runs first) ### Custom Authorization Policies diff --git a/pkg/runner/authz_audit_integration_test.go b/pkg/runner/authz_audit_integration_test.go new file mode 100644 index 0000000000..f78ceda731 --- /dev/null +++ b/pkg/runner/authz_audit_integration_test.go @@ -0,0 +1,171 @@ +// SPDX-FileCopyrightText: Copyright 2025 Stacklok, Inc. +// SPDX-License-Identifier: Apache-2.0 + +package runner + +import ( + "bytes" + "encoding/json" + "net/http" + "net/http/httptest" + "os" + "path/filepath" + "strings" + "testing" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "go.uber.org/mock/gomock" + + "github.com/stacklok/toolhive/pkg/audit" + "github.com/stacklok/toolhive/pkg/authz/authorizers" + "github.com/stacklok/toolhive/pkg/authz/authorizers/cedar" + statusesmocks "github.com/stacklok/toolhive/pkg/workloads/statuses/mocks" +) + +// buildRunnerMiddlewareChain populates the middleware configs for runConfig, +// instantiates the middlewares through the runner factories (the same path the +// proxyrunner takes), and wraps final with them in the order the proxies apply +// them (reverse slice order, so index 0 is the outermost wrapper). +func buildRunnerMiddlewareChain(t *testing.T, runConfig *RunConfig, final http.Handler) http.Handler { + t.Helper() + + require.NoError(t, PopulateMiddlewareConfigs(runConfig)) + + ctrl := gomock.NewController(t) + t.Cleanup(ctrl.Finish) + mockStatusManager := statusesmocks.NewMockStatusManager(ctrl) + + runner := NewRunner(runConfig, mockStatusManager) + for _, mwConfig := range runConfig.MiddlewareConfigs { + factory, ok := runner.supportedMiddleware[mwConfig.Type] + require.True(t, ok, "no factory for middleware type %q", mwConfig.Type) + require.NoError(t, factory(&mwConfig, runner)) + } + require.NotEmpty(t, runner.middlewares) + // The factories acquire resources (the auditor's log file, the usage-metrics + // flush goroutine); release them when the test finishes. + t.Cleanup(func() { + for _, mw := range runner.middlewares { + _ = mw.Close() + } + }) + + handler := final + for i := len(runner.middlewares) - 1; i >= 0; i-- { + handler = runner.middlewares[i].Handler()(handler) + } + return handler +} + +// readAuditEvents parses the newline-delimited JSON audit log at path. +func readAuditEvents(t *testing.T, path string) []map[string]any { + t.Helper() + + data, err := os.ReadFile(path) + require.NoError(t, err) + + var events []map[string]any + for _, line := range strings.Split(strings.TrimSpace(string(data)), "\n") { + if line == "" { + continue + } + var event map[string]any + require.NoError(t, json.Unmarshal([]byte(line), &event), "audit log line is not JSON: %s", line) + events = append(events, event) + } + return events +} + +// TestAuthzDecisionIsAudited proves, through the full middleware chain the +// proxyrunner builds via PopulateMiddlewareConfigs, that authorization +// decisions produce audit events: a Cedar-denied tools/call must return HTTP +// 403 AND still emit an audit event with outcome "denied", and an authorized +// call must emit one with outcome "success". This is the regression guard for +// the ordering bug where audit was wired inside authz and denials were never +// audited. +func TestAuthzDecisionIsAudited(t *testing.T) { + t.Parallel() + + tests := []struct { + name string + policy string + wantStatus int + wantOutcome string + wantHandlerHit bool + wantDeniedError bool + }{ + { + name: "denied tool call returns 403 and is audited with outcome denied", + // Permit only an unrelated tool: "target_tool" is default-denied. + policy: `permit(principal, action == Action::"call_tool", resource == Tool::"some_other_tool");`, + wantStatus: http.StatusForbidden, + wantOutcome: "denied", + wantHandlerHit: false, + wantDeniedError: true, + }, + { + name: "allowed tool call returns 200 and is audited with outcome success", + policy: `permit(principal, action, resource);`, + wantStatus: http.StatusOK, + wantOutcome: "success", + wantHandlerHit: true, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + t.Parallel() + + authzConfig, err := authorizers.NewConfig(cedar.Config{ + Version: "1.0", + Type: cedar.ConfigType, + Options: &cedar.ConfigOptions{ + Policies: []string{tt.policy}, + EntitiesJSON: "[]", + }, + }) + require.NoError(t, err) + + auditLogPath := filepath.Join(t.TempDir(), "audit.log") + + runConfig := NewRunConfig() + runConfig.Name = "test-server" + runConfig.AuthzConfig = authzConfig + runConfig.AuditConfig = &audit.Config{ + Component: "test-component", + LogFile: auditLogPath, + } + + handlerHit := false + backend := http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { + handlerHit = true + w.WriteHeader(http.StatusOK) + _, _ = w.Write([]byte(`{"jsonrpc":"2.0","id":1,"result":{}}`)) + }) + + handler := buildRunnerMiddlewareChain(t, runConfig, backend) + + reqBody := `{"jsonrpc":"2.0","method":"tools/call","id":1,"params":{"name":"target_tool","arguments":{}}}` + req := httptest.NewRequest(http.MethodPost, "/", bytes.NewBufferString(reqBody)) + req.Header.Set("Content-Type", "application/json") + + rr := httptest.NewRecorder() + handler.ServeHTTP(rr, req) + + require.Equal(t, tt.wantStatus, rr.Code, "response body: %s", rr.Body.String()) + assert.Equal(t, tt.wantHandlerHit, handlerHit) + if tt.wantDeniedError { + assert.Contains(t, rr.Body.String(), "Unauthorized", + "denied response must carry the authorization-denied error") + } + + events := readAuditEvents(t, auditLogPath) + require.Len(t, events, 1, "exactly one audit event must be emitted") + event := events[0] + assert.Equal(t, "mcp_tool_call", event["type"], + "the parsed MCP method must drive the audit event type") + assert.Equal(t, tt.wantOutcome, event["outcome"]) + }) + } +} diff --git a/pkg/runner/config_builder.go b/pkg/runner/config_builder.go index a6d48ff1dd..947c9185c0 100644 --- a/pkg/runner/config_builder.go +++ b/pkg/runner/config_builder.go @@ -656,10 +656,10 @@ func WithMiddlewareFromFlags( var middlewareConfigs []types.MiddlewareConfig // NOTE: order matters here. Specifically, these routines use append - // to add new middleware configs, but once these routines are called, - // inside the proxy, they are applied in reverse order, so the first - // being added here is effectively the last being called at HTTP - // request time. + // to add new middleware configs. The proxy wraps the handler in + // reverse slice order (see applyMiddlewares), so the first entry + // added here is the OUTERMOST wrapper and runs first at HTTP request + // time; the last entry runs closest to the handler. // // We should avoid doing this and a better pattern would be to let the // actual proxy determine the order of application of middlewares, since @@ -696,16 +696,20 @@ func WithMiddlewareFromFlags( return err } - // Add optional middlewares + // Add optional middlewares. Audit is added BEFORE authorization so it + // wraps it at request time: authorization denials (403) must still + // produce an audit event with outcome "denied". middlewareConfigs = addTelemetryMiddleware(middlewareConfigs, telemetryConfig, serverName, transportType) + middlewareConfigs = addAuditMiddleware(middlewareConfigs, enableAudit, auditConfigPath, serverName, transportType) var authzErr error middlewareConfigs, authzErr = addAuthzMiddleware(middlewareConfigs, authzConfigPath, b.config.EmbeddedAuthServerConfig) if authzErr != nil { return authzErr } - middlewareConfigs = addAuditMiddleware(middlewareConfigs, enableAudit, auditConfigPath, serverName, transportType) - // Add recovery middleware (always present, added last to be outermost wrapper) + // Add recovery middleware (always present, added last so it is the + // innermost wrapper, executing closest to the handler — matching + // PopulateMiddlewareConfigs) middlewareConfigs = addRecoveryMiddleware(middlewareConfigs) // Set the populated middleware configs @@ -939,9 +943,10 @@ func addAuditMiddleware( return middlewareConfigs } -// addRecoveryMiddleware adds recovery middleware (always present, added last to be outermost wrapper) -// Middleware is applied in reverse order, so adding last means it executes first -// and catches panics from all other middleware and handlers. +// addRecoveryMiddleware adds recovery middleware (always present, added last). +// The proxy wraps the handler in reverse slice order, so the last entry is the +// INNERMOST wrapper: it catches panics from the handler itself, but not from +// middleware added earlier in the slice (which wrap it). func addRecoveryMiddleware(middlewareConfigs []types.MiddlewareConfig) []types.MiddlewareConfig { recoveryConfig, err := types.NewMiddlewareConfig(recovery.MiddlewareType, nil) if err != nil { diff --git a/pkg/runner/config_builder_test.go b/pkg/runner/config_builder_test.go index cbced11fee..6bebe049fb 100644 --- a/pkg/runner/config_builder_test.go +++ b/pkg/runner/config_builder_test.go @@ -16,9 +16,11 @@ import ( "github.com/stacklok/toolhive-core/permissions" regtypes "github.com/stacklok/toolhive-core/registry/types" + "github.com/stacklok/toolhive/pkg/audit" "github.com/stacklok/toolhive/pkg/auth" "github.com/stacklok/toolhive/pkg/authserver" "github.com/stacklok/toolhive/pkg/authserver/server/registration" + "github.com/stacklok/toolhive/pkg/authz" appconfig "github.com/stacklok/toolhive/pkg/config" "github.com/stacklok/toolhive/pkg/mcp" "github.com/stacklok/toolhive/pkg/networking" @@ -1583,6 +1585,53 @@ func TestResolveRegistryServerName(t *testing.T) { } } +// TestWithMiddlewareFromFlags_AuditBeforeAuthz pins the same audit-wraps-authz +// ordering invariant on the CLI flag path that +// TestPopulateMiddlewareConfigs_AuditBeforeAuthz pins on the operator path: +// audit must precede authorization in the config slice (earlier entries wrap +// later ones at request time) so authorization denials still produce an audit +// event with outcome "denied". +func TestWithMiddlewareFromFlags_AuditBeforeAuthz(t *testing.T) { + t.Parallel() + + builder := &runConfigBuilder{config: NewRunConfig()} + opt := WithMiddlewareFromFlags( + nil, // oidcConfig + nil, // tokenExchangeConfig + nil, // toolsFilter + nil, // toolsOverride + nil, // telemetryConfig + writeCedarConfigFile(t), // authzConfigPath + true, // enableAudit + "", // auditConfigPath + "test-server", // serverName + "streamable-http", // transportType + true, // disableUsageMetrics + ) + require.NoError(t, opt(builder)) + + typeIndex := make(map[string]int, len(builder.config.MiddlewareConfigs)) + for i, mw := range builder.config.MiddlewareConfigs { + typeIndex[mw.Type] = i + } + + auditIdx, ok := typeIndex[audit.MiddlewareType] + require.True(t, ok, "audit middleware must be present") + authzIdx, ok := typeIndex[authz.MiddlewareType] + require.True(t, ok, "authz middleware must be present") + authIdx, ok := typeIndex[auth.MiddlewareType] + require.True(t, ok, "auth middleware must be present") + parserIdx, ok := typeIndex[mcp.ParserMiddlewareType] + require.True(t, ok, "MCP parser middleware must be present") + + assert.Less(t, auditIdx, authzIdx, + "audit must precede authz so authorization denials are audited") + assert.Less(t, authIdx, auditIdx, + "auth must precede audit so the identity is available to audit events") + assert.Less(t, parserIdx, auditIdx, + "MCP parser must precede audit so parsed MCP data is available to audit events") +} + // TestWithAdditionalMiddlewareConfigs verifies the generic injected-middleware // builder option: it appends pre-built configs (across multiple calls and // multiple arguments), preserves order, and skips nil entries. The option is diff --git a/pkg/runner/middleware.go b/pkg/runner/middleware.go index 1debe3fe87..5e33ad5515 100644 --- a/pkg/runner/middleware.go +++ b/pkg/runner/middleware.go @@ -151,7 +151,7 @@ func PopulateMiddlewareConfigs(config *RunConfig) error { // Mutating Webhooks middleware (if configured). // Must run BEFORE validating webhooks: - // MCP Parser -> [Mutating Webhooks] -> [Validating Webhooks] -> Authz -> Audit + // MCP Parser -> [Mutating Webhooks] -> [Validating Webhooks] -> Audit -> Authz middlewareConfigs, err = addMutatingWebhookMiddleware(middlewareConfigs, config) if err != nil { return err @@ -187,6 +187,25 @@ func PopulateMiddlewareConfigs(config *RunConfig) error { middlewareConfigs = append(middlewareConfigs, *telemetryConfig) } + // Audit middleware (if enabled) + // Added BEFORE authorization so it wraps it at request time: authorization + // denials (403) must still produce an audit event with outcome "denied". + // If audit ran inside authz, a deny would short-circuit before the auditor + // ever saw the request. + if config.AuditConfig != nil { + auditParams := audit.MiddlewareParams{ + ConfigPath: config.AuditConfigPath, // Keep for backwards compatibility + ConfigData: config.AuditConfig, // Use the loaded config data + Component: config.AuditConfig.Component, + TransportType: config.Transport.String(), // Pass the actual transport type + } + auditConfig, err := types.NewMiddlewareConfig(audit.MiddlewareType, auditParams) + if err != nil { + return fmt.Errorf("failed to create audit middleware config: %w", err) + } + middlewareConfigs = append(middlewareConfigs, *auditConfig) + } + // Authorization middleware (if enabled) if config.AuthzConfig != nil { authzCfgData, err := injectUpstreamProviderIfNeeded(config.AuthzConfig, config.EmbeddedAuthServerConfig) @@ -204,21 +223,6 @@ func PopulateMiddlewareConfigs(config *RunConfig) error { middlewareConfigs = append(middlewareConfigs, *authzConfig) } - // Audit middleware (if enabled) - if config.AuditConfig != nil { - auditParams := audit.MiddlewareParams{ - ConfigPath: config.AuditConfigPath, // Keep for backwards compatibility - ConfigData: config.AuditConfig, // Use the loaded config data - Component: config.AuditConfig.Component, - TransportType: config.Transport.String(), // Pass the actual transport type - } - auditConfig, err := types.NewMiddlewareConfig(audit.MiddlewareType, auditParams) - if err != nil { - return fmt.Errorf("failed to create audit middleware config: %w", err) - } - middlewareConfigs = append(middlewareConfigs, *auditConfig) - } - // AWS STS middleware (if configured) // Placed after audit/authz so that authorization is checked before exchanging // credentials, and close to the backend so SigV4 signing happens as late as diff --git a/pkg/runner/middleware_test.go b/pkg/runner/middleware_test.go index bf51aa04ce..7cc8f8b99b 100644 --- a/pkg/runner/middleware_test.go +++ b/pkg/runner/middleware_test.go @@ -1354,6 +1354,44 @@ func TestPopulateMiddlewareConfigs_FullCoverage(t *testing.T) { assert.True(t, typeIndex[audit.MiddlewareType]) } +// TestPopulateMiddlewareConfigs_AuditBeforeAuthz pins the ordering invariant +// that the audit middleware precedes authorization in the config slice. +// Earlier entries wrap later ones at request time, so audit must wrap authz +// for an authorization denial (403) to still produce an audit event with +// outcome "denied". It must in turn come after auth and the MCP parser, which +// provide the identity and parsed MCP data the audit event is built from. +func TestPopulateMiddlewareConfigs_AuditBeforeAuthz(t *testing.T) { + t.Parallel() + + config := &RunConfig{ + AuthzConfig: &authz.Config{}, + AuditConfig: &audit.Config{Component: "test-component"}, + } + + require.NoError(t, PopulateMiddlewareConfigs(config)) + + typeIndex := make(map[string]int, len(config.MiddlewareConfigs)) + for i, mw := range config.MiddlewareConfigs { + typeIndex[mw.Type] = i + } + + auditIdx, ok := typeIndex[audit.MiddlewareType] + require.True(t, ok, "audit middleware must be present") + authzIdx, ok := typeIndex[authz.MiddlewareType] + require.True(t, ok, "authz middleware must be present") + authIdx, ok := typeIndex[auth.MiddlewareType] + require.True(t, ok, "auth middleware must be present") + parserIdx, ok := typeIndex[mcp.ParserMiddlewareType] + require.True(t, ok, "MCP parser middleware must be present") + + assert.Less(t, auditIdx, authzIdx, + "audit must precede authz so authorization denials are audited") + assert.Less(t, authIdx, auditIdx, + "auth must precede audit so the identity is available to audit events") + assert.Less(t, parserIdx, auditIdx, + "MCP parser must precede audit so parsed MCP data is available to audit events") +} + // TestPopulateMiddlewareConfigs_StripAuthOrdering pins the ordering invariant // for strip-auth: the auth middleware must precede it in the chain so the // client JWT is fully validated (and the identity stored in the request diff --git a/pkg/vmcp/server/authz_integration_test.go b/pkg/vmcp/server/authz_integration_test.go index 4839fa4841..b9ba48d4a8 100644 --- a/pkg/vmcp/server/authz_integration_test.go +++ b/pkg/vmcp/server/authz_integration_test.go @@ -4,11 +4,13 @@ package server_test import ( - "context" "encoding/json" "io" "net/http" "net/http/httptest" + "os" + "path/filepath" + "strings" "testing" "time" @@ -16,6 +18,7 @@ import ( "github.com/stretchr/testify/require" "go.uber.org/mock/gomock" + "github.com/stacklok/toolhive/pkg/audit" "github.com/stacklok/toolhive/pkg/auth" "github.com/stacklok/toolhive/pkg/authz/authorizers" "github.com/stacklok/toolhive/pkg/authz/authorizers/cedar" @@ -65,7 +68,7 @@ func parseRPCError(t *testing.T, body []byte) rpcErrorFields { // chain that replaced the legacy HTTP authz middleware on the Serve path. func newCedarAuthzTestServer(t *testing.T, backendURL string, policies ...string) *httptest.Server { t.Helper() - return buildCedarAuthzServer(t, backendURL, nil, policies...) + return buildCedarAuthzServer(t, backendURL, nil, nil, policies...) } // newCedarAuthzCodeModeServer is newCedarAuthzTestServer with code mode enabled, so @@ -74,14 +77,15 @@ func newCedarAuthzTestServer(t *testing.T, backendURL string, policies ...string // while a directly-denied tool still 403s. func newCedarAuthzCodeModeServer(t *testing.T, backendURL string, policies ...string) *httptest.Server { t.Helper() - return buildCedarAuthzServer(t, backendURL, &codemode.Config{}, policies...) + return buildCedarAuthzServer(t, backendURL, &codemode.Config{}, nil, policies...) } // buildCedarAuthzServer builds the vMCP test server. A non-nil codeModeCfg enables -// the codemode decorator; a nil policies slice leaves Authz unset (allow-all, gate -// not installed) — used by the no-Authz parity guard. +// the codemode decorator; a non-nil auditCfg enables the audit middleware; a nil +// policies slice leaves Authz unset (allow-all, gate not installed) — used by the +// no-Authz parity guard. func buildCedarAuthzServer( - t *testing.T, backendURL string, codeModeCfg *codemode.Config, policies ...string, + t *testing.T, backendURL string, codeModeCfg *codemode.Config, auditCfg *audit.Config, policies ...string, ) *httptest.Server { t.Helper() @@ -116,14 +120,18 @@ func buildCedarAuthzServer( // Inject a fixed authenticated identity on every request so the session binds to it at // initialize and the Cedar authorizer can resolve the principal on subsequent calls. + // The MCP parser is composed inside it, mirroring the production incoming-auth factory + // (see pkg/vmcp/auth/factory): audit and authz read parsed MCP data from the request + // context, and the audit middleware sits between auth and the parser applied in Handler. identityMiddleware := func(next http.Handler) http.Handler { + withParser := mcpparser.ParsingMiddleware(next) return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { id := &auth.Identity{PrincipalInfo: auth.PrincipalInfo{ Subject: "user-123", Name: "Test User", Claims: map[string]any{"sub": "user-123", "name": "Test User"}, }} - next.ServeHTTP(w, r.WithContext(auth.WithIdentity(r.Context(), id))) + withParser.ServeHTTP(w, r.WithContext(auth.WithIdentity(r.Context(), id))) }) } @@ -141,7 +149,7 @@ func buildCedarAuthzServer( } srv, err := server.New( - context.Background(), + t.Context(), &server.Config{ // Name is non-empty: deriveCoreConfig forwards the raw server name to the core, // and the Cedar admission seam requires it (resource entities are scoped to @@ -154,6 +162,7 @@ func buildCedarAuthzServer( Aggregator: agg, AuthMiddleware: identityMiddleware, Authz: authzCfg, + AuditConfig: auditCfg, CodeModeConfig: codeModeCfg, }, router.NewSessionRouter(&vmcp.RoutingTable{}), @@ -163,7 +172,7 @@ func buildCedarAuthzServer( ) require.NoError(t, err) - handler, err := srv.Handler(context.Background()) + handler, err := srv.Handler(t.Context()) require.NoError(t, err) ts := httptest.NewServer(handler) @@ -431,3 +440,62 @@ func TestIntegration_RealBackend_CodeMode_Authz(t *testing.T) { require.Equal(t, http.StatusForbidden, denyResp.StatusCode, "body: %s", string(denyBody)) assert.Equal(t, mcpparser.JSONRPCCodeDenied, parseRPCError(t, denyBody).code) } + +// TestIntegration_CedarAuthzDenialIsAudited proves that on the vMCP Serve path a +// policy-denied tools/call still produces an audit event with outcome "denied". +// The pre-dispatch authorization gate runs inside the audit middleware, so the +// 403 it writes must be captured as the event outcome. This is the vMCP +// counterpart of the proxyrunner-path guard in pkg/runner +// (TestAuthzDecisionIsAudited). +func TestIntegration_CedarAuthzDenialIsAudited(t *testing.T) { + t.Parallel() + + backendURL := startRealMCPBackend(t) + auditLogPath := filepath.Join(t.TempDir(), "audit.log") + // Permit only an unrelated tool: "echo" is default-denied. + ts := buildCedarAuthzServer(t, backendURL, nil, + &audit.Config{Component: "vmcp-server", LogFile: auditLogPath}, + `permit(principal, action == Action::"call_tool", resource == Tool::"unrelated");`) + + client := NewMCPTestClient(t, ts.URL) + client.InitializeSession() + + resp := client.CallTool("echo", map[string]any{"input": "hello"}) + defer resp.Body.Close() + body, err := io.ReadAll(resp.Body) + require.NoError(t, err) + require.Equal(t, http.StatusForbidden, resp.StatusCode, "body: %s", string(body)) + + // The audit event is written after the response is flushed, so poll briefly. + require.Eventually(t, func() bool { + return findAuditEvent(t, auditLogPath, "mcp_tool_call") != nil + }, 5*time.Second, 50*time.Millisecond, "a tools/call audit event must be emitted for the denied call") + + event := findAuditEvent(t, auditLogPath, "mcp_tool_call") + assert.Equal(t, "denied", event["outcome"], + "a policy-denied tools/call must be audited with outcome denied") +} + +// findAuditEvent reads the newline-delimited JSON audit log at path and returns +// the first event whose "type" matches eventType, or nil if none is present yet. +func findAuditEvent(t *testing.T, path string, eventType string) map[string]any { + t.Helper() + + data, err := os.ReadFile(path) + if err != nil { + return nil + } + for _, line := range strings.Split(strings.TrimSpace(string(data)), "\n") { + if line == "" { + continue + } + var event map[string]any + if err := json.Unmarshal([]byte(line), &event); err != nil { + continue + } + if event["type"] == eventType { + return event + } + } + return nil +}