Files
gitea-mcp/pkg/middleware/logging_test.go
Klaus 316c2c4275
check-and-test / check-and-test (pull_request) Has been cancelled
debug: structured tool/HTTP logging, request IDs, config dump
Closes #13.

Today GITEA_DEBUG=true only flips the zap level to debug, dumps a
contextless `Text Result:` blob per tool call, and enables the gitea
SDK's own debug stream (which doesn't merge with our log file). That is
not enough to diagnose a misbehaving tool call in production.

This change introduces:

- A `pkg/middleware.ToolLogging` ToolHandlerMiddleware that logs each
  tool invocation on entry and exit with structured fields: tool name,
  redacted args, request_id, token source, duration_ms, and status. The
  request_id is stashed in the context so downstream layers can
  correlate.
- A `loggingRoundTripper` in `pkg/gitea` that wraps the shared HTTP
  transport and emits one structured line per upstream Gitea API call
  (method, token-stripped URL, status, duration_ms, bytes). This
  replaces — and is far more useful than — `gitea.SetDebugMode()`.
- An effective-config dump at startup (`logEffectiveConfig`) when
  debug+config scope is on, so "did my env var get picked up?" becomes
  answerable from the log file.
- Token source tracking. CLI flag / GITEA_ACCESS_TOKEN /
  GITEA_ACCESS_TOKEN_FILE / per-request Authorization header are now
  distinguished in logs as flag/env/env-file/header.
- A baseline redactor in `pkg/debug` that masks args / query params
  whose keys look like secrets (token, password, secret, api_key,
  authorization, …). This is the placeholder for issue #5's shared
  redactor; once that lands, callers here should defer to it.
- `GITEA_DEBUG_SCOPES` env var to scope debug output to any subset of
  `tools,http,config`. Default (unset) is "everything".

Test coverage was added for the redactor, scope flag, request-id
helpers, preview truncation (multibyte-safe), and the middleware's
context wiring + error propagation.

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
2026-05-23 19:04:28 +00:00

92 lines
2.4 KiB
Go

package middleware
import (
"context"
"errors"
"testing"
mcpContext "gitea.com/gitea/gitea-mcp/pkg/context"
"gitea.com/gitea/gitea-mcp/pkg/debug"
"gitea.com/gitea/gitea-mcp/pkg/flag"
"github.com/mark3labs/mcp-go/mcp"
)
func TestToolLogging_PropagatesContextValues(t *testing.T) {
origDebug := flag.Debug
defer func() { flag.Debug = origDebug }()
flag.Debug = false // exercise the no-log code path; context wiring runs regardless
var (
gotToolName string
gotReqID string
)
handler := func(ctx context.Context, _ mcp.CallToolRequest) (*mcp.CallToolResult, error) {
gotToolName = debug.ToolNameFromContext(ctx)
gotReqID = debug.RequestIDFromContext(ctx)
return mcp.NewToolResultText("ok"), nil
}
wrapped := ToolLogging(handler)
req := mcp.CallToolRequest{}
req.Params.Name = "get_me"
req.Params.Arguments = map[string]any{"x": 1}
res, err := wrapped(context.Background(), req)
if err != nil {
t.Fatalf("unexpected error: %v", err)
}
if res == nil {
t.Fatal("expected non-nil result")
}
if gotToolName != "get_me" {
t.Fatalf("tool name not propagated, got %q", gotToolName)
}
if gotReqID == "" {
t.Fatal("request id not propagated")
}
}
func TestToolLogging_ReturnsHandlerError(t *testing.T) {
want := errors.New("boom")
wrapped := ToolLogging(func(_ context.Context, _ mcp.CallToolRequest) (*mcp.CallToolResult, error) {
return nil, want
})
req := mcp.CallToolRequest{}
req.Params.Name = "broken_tool"
_, err := wrapped(context.Background(), req)
if !errors.Is(err, want) {
t.Fatalf("error not surfaced, got %v", err)
}
}
func TestTokenSourceFromContext(t *testing.T) {
origFlag := flag.TokenSource
defer func() { flag.TokenSource = origFlag }()
t.Run("falls back to flag.TokenSource", func(t *testing.T) {
flag.TokenSource = "env"
if got := tokenSourceFromContext(context.Background()); got != "env" {
t.Fatalf("got %q want env", got)
}
})
t.Run("returns none when no source is known", func(t *testing.T) {
flag.TokenSource = ""
if got := tokenSourceFromContext(context.Background()); got != "none" {
t.Fatalf("got %q want none", got)
}
})
t.Run("context value beats flag", func(t *testing.T) {
flag.TokenSource = "env"
ctx := context.WithValue(context.Background(), mcpContext.TokenSourceContextKey, "header")
if got := tokenSourceFromContext(ctx); got != "header" {
t.Fatalf("got %q want header", got)
}
})
}