fix(security): redact the request path on the MCP and OAuth-callback log lines

internal/oauth/callback_path_redaction_test.go

@@ -0,0 +1,111 @@
+package oauth
+
+import (
+	"net/http"
+	"net/http/httptest"
+	"testing"
+
+	"github.com/stretchr/testify/require"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zaptest/observer"
+)
+
+// SEC-01 follow-up. The OAuth loopback callback listener redacted its QUERY
+// (LogSafeCallbackQuery, issue #1158) but logged `zap.String("path",
+// r.URL.Path)` verbatim at INFO, in two places: the listener's own handler and
+// handleCallback below it.
+//
+// The callback path is normally a fixed operator-configured value, so this is
+// consistency work rather than a demonstrated leak of the user's own admin key.
+// It is still a real client-controlled sink: the handler is a bare
+// http.HandlerFunc with no mux in front of it (deliberately — see the comment
+// in StartCallbackServer), so EVERY path reaches the log line, including the
+// ones that fall through to the debug page; the listener is a plain loopback
+// HTTP server that any local process or any page in the user's browser can
+// reach for the whole login window; and r.URL.Path arrives percent-decoded, so
+// `%3Fapikey%3D` and `Bearer%20` land here as the real thing.
+//
+// Every other field on these two lines already goes through this package's
+// redactors. The path was the one that did not.
+
+// newObservedCallbackServerAtPath builds a CallbackServer wired to an
+// in-memory log sink and serving `path`, so the fall-through (debug page)
+// branch of handleRequest can be exercised.
+func newObservedCallbackServerAtPath(t *testing.T, path string) (*CallbackServer, *observer.ObservedLogs) {
+	t.Helper()
+	core, logs := observer.New(zap.DebugLevel)
+	return &CallbackServer{
+		ServerName: "alpha",
+		Path:       path,
+		Port:       53682,
+		logger:     zap.New(core),
+		waiters:    make(map[string]chan map[string]string),
+	}, logs
+}
+
+// callbackKeyInPath is the shape an `?apikey=` credential takes once it has
+// been percent-decoded into r.URL.Path. 64 hex characters is what
+// cmd/mcpproxy generates for the admin key.
+const callbackKeyInPath = "4f3c2b1a9e8d7c6b5a4f3e2d1c0b9a8f7e6d5c4b3a2f1e0d9c8b7a6f5e4d3c2b"
+
+func TestCallbackListenerRedactsACredentialInTheRequestPath(t *testing.T) {
+	cs, logs := newObservedCallbackServerAtPath(t, DefaultRedirectPath)
+
+	cs.handleRequest(httptest.NewRecorder(),
+		httptest.NewRequest(http.MethodGet, "/probe/apikey="+callbackKeyInPath, nil))
+
+	out := renderedLines(logs)
+	require.NotEmpty(t, out, "the handler must still log — a fix that deletes the line is not the fix")
+	require.Contains(t, out, "/probe/", "the diagnostic part of the path must survive redaction")
+	assertNoRun(t, out, callbackKeyInPath, 12)
+}
+
+func TestHandleCallbackRedactsACredentialInTheRequestPath(t *testing.T) {
+	cs, logs := newObservedCallbackServerAtPath(t, DefaultRedirectPath)
+
+	cs.handleCallback(httptest.NewRecorder(),
+		httptest.NewRequest(http.MethodGet,
+			DefaultRedirectPath+"/apikey="+callbackKeyInPath+"?error=access_denied", nil))
+
+	assertNoRun(t, renderedLines(logs), callbackKeyInPath, 12)
+}
+
+// r.URL.Path arrives percent-decoded, so `Bearer%20<token>` reaches this log
+// field as a real `Bearer <token>` — a shape no `name=value` rule can see.
+func TestCallbackListenerRedactsABearerTokenInTheRequestPath(t *testing.T) {
+	const agentToken = "mcp_agt_Zt7Qv2Lm9XbR4pWc8HsKd3Ng6JyF1aUe"
+
+	cs, logs := newObservedCallbackServerAtPath(t, DefaultRedirectPath)
+
+	cs.handleRequest(httptest.NewRecorder(),
+		httptest.NewRequest(http.MethodGet, "/probe/Bearer%20"+agentToken, nil))
+
+	assertNoRun(t, renderedLines(logs), agentToken, 12)
+}
+
+// TestLogSafeRequestPathRedactsAnEncodedQueryInsideThePath covers the shape
+// that makes the two path sinks a LIVE-credential risk rather than a purely
+// theoretical one, and that LogSafeRequestPath did not handle.
+//
+// `?apikey=<KEY>` is the credential form mcpproxy's own Connect wizard and Web
+// UI hand out, and a client that percent-encodes its URL suffix sends
+// `/mcp/%3Fapikey%3D<KEY>` — which net/http decodes into
+// r.URL.Path == "/mcp/?apikey=<KEY>" before any handler sees it. ServeMux
+// matches that against the `/mcp/` SUBTREE pattern, so it reaches the handler,
+// and the log field gets the decoded form.
+//
+// logSafeURLComponent split only on '/', so the segment handed to the name rule
+// was "?apikey=<KEY>" — whose parameter name reads as "?apikey", which matches
+// nothing — and the value is plain hex, under the entropy detector's threshold.
+// The credential went to disk in the clear. A path segment carries `k=v` pairs
+// after a '?' exactly as a fragment does, and logSafeFragment already accounted
+// for that; the path did not.
+func TestLogSafeRequestPathRedactsAnEncodedQueryInsideThePath(t *testing.T) {
+	r := httptest.NewRequest(http.MethodGet, "/mcp/%3Fapikey%3D"+callbackKeyInPath, nil)
+	require.Equal(t, "/mcp/?apikey="+callbackKeyInPath, r.URL.Path,
+		"net/http must still hand the handler a DECODED path — the premise of this test")
+
+	rendered := LogSafeRequestPath(r.URL.Path)
+	require.Contains(t, rendered, "/mcp/", "the diagnostic part of the path must survive redaction")
+	assertNoRun(t, rendered, callbackKeyInPath, 12)
+}

internal/oauth/config.go

@@ -1550,34 +1550,7 @@ func (m *CallbackServerManager) StartCallbackServerOnHost(serverName string, bin
 	//     redirected instead of delivered, and the login hangs.
 	// A raw handler function receives r.URL.Path exactly as net/http parsed
 	// it, with neither risk.
-	handler := http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
-		callbackServer.logger.Info("📥 HTTP request received on callback server",
-			zap.String("method", r.Method),
-			zap.String("path", r.URL.Path),
-			zap.String("query", LogSafeCallbackQuery(r.URL.RawQuery)),
-			zap.String("user_agent", r.UserAgent()),
-			zap.String("remote_addr", r.RemoteAddr))
-
-		if r.URL.Path == path {
-			callbackServer.handleCallback(w, r)
-		} else {
-			w.Header().Set("Content-Type", "text/html")
-			debugPage := fmt.Sprintf(`
-				<html>
-					<body>
-						<h1>OAuth Callback Server Debug</h1>
-						<p>Path: %s</p>
-						<p>Expected: %s</p>
-						<p>Server: %s</p>
-						<p>Port: %d</p>
-					</body>
-				</html>
-			`, html.EscapeString(r.URL.Path), html.EscapeString(path), html.EscapeString(serverName), port)
-			if _, err := w.Write([]byte(debugPage)); err != nil {
-				callbackServer.logger.Error("Error writing debug page", zap.Error(err))
-			}
-		}
-	})
+	handler := http.HandlerFunc(callbackServer.handleRequest)
 
 	server := &http.Server{
 		Addr:              listenAddr,
@@ -1726,11 +1699,56 @@ func callbackPage(title, message string) string {
 	`, html.EscapeString(title), html.EscapeString(message), closeScript)
 }
 
+// handleRequest is the callback listener's only handler: it logs the request,
+// then either delivers a real callback or renders the debug page. A method
+// rather than a closure in StartCallbackServerOnHost so the log fields it
+// writes are reachable from a test without binding a listener; it reads c.Path,
+// c.ServerName and c.Port, which are exactly the values the closure captured.
+//
+// SEC-01 follow-up: `path` goes through LogSafeRequestPath like every other
+// field on this line. The callback path is normally a fixed, operator-
+// configured value, so this closes an inconsistency rather than a demonstrated
+// leak — but there is no mux in front of this handler (deliberately, see
+// StartCallbackServer), so EVERY path reaches the log line including the ones
+// that fall through to the debug page; the listener is a plain loopback HTTP
+// server any local process can reach for the whole login window; and
+// r.URL.Path arrives percent-DECODED, so an encoded `?apikey=<KEY>` or
+// `Bearer <token>` in the request target lands here as the real thing.
+func (c *CallbackServer) handleRequest(w http.ResponseWriter, r *http.Request) {
+	c.logger.Info("📥 HTTP request received on callback server",
+		zap.String("method", r.Method),
+		zap.String("path", LogSafeRequestPath(r.URL.Path)),
+		zap.String("query", LogSafeCallbackQuery(r.URL.RawQuery)),
+		zap.String("user_agent", r.UserAgent()),
+		zap.String("remote_addr", r.RemoteAddr))
+
+	if r.URL.Path == c.Path {
+		c.handleCallback(w, r)
+		return
+	}
+
+	w.Header().Set("Content-Type", "text/html")
+	debugPage := fmt.Sprintf(`
+		<html>
+			<body>
+				<h1>OAuth Callback Server Debug</h1>
+				<p>Path: %s</p>
+				<p>Expected: %s</p>
+				<p>Server: %s</p>
+				<p>Port: %d</p>
+			</body>
+		</html>
+	`, html.EscapeString(r.URL.Path), html.EscapeString(c.Path), html.EscapeString(c.ServerName), c.Port)
+	if _, err := w.Write([]byte(debugPage)); err != nil {
+		c.logger.Error("Error writing debug page", zap.Error(err))
+	}
+}
+
 // handleCallback handles OAuth callback requests
 func (c *CallbackServer) handleCallback(w http.ResponseWriter, r *http.Request) {
 	c.logger.Info("🎯 OAuth callback received",
 		zap.String("method", r.Method),
-		zap.String("path", r.URL.Path),
+		zap.String("path", LogSafeRequestPath(r.URL.Path)),
 		zap.String("query", LogSafeCallbackQuery(r.URL.RawQuery)),
 		zap.String("remote_addr", r.RemoteAddr),
 		zap.String("user_agent", r.UserAgent()))

internal/oauth/logging.go

@@ -1248,11 +1248,40 @@ func logSafeURLComponent(s string) string {
 	s = tokenPattern.ReplaceAllString(redactURLUserinfo(s), "${1}"+redactedMarker)
 	segments := strings.Split(s, "/")
 	for i, segment := range segments {
-		segments[i] = LogSafeQueryString(segment)
+		segments[i] = logSafePathSegment(segment)
 	}
 	return MaskDetectedSecrets(strings.Join(segments, "/"))
 }
 
+// logSafePathSegment applies the name rule to ONE path segment, treating
+// anything after a '?' inside it as a query of its own.
+//
+// The '?' split is not hypothetical tidying. r.URL.Path is what net/http hands
+// a handler and it arrives percent-DECODED, so a client that encodes its URL
+// suffix — `GET /mcp/%3Fapikey%3D<KEY>`, which ServeMux still matches against
+// the `/mcp/` subtree pattern — produces the path `/mcp/?apikey=<KEY>`.
+// Splitting on '/' alone left the segment `?apikey=<KEY>`, whose parameter name
+// reads as "?apikey" and so matches no name rule, and whose plain-hex value is
+// under the entropy detector's threshold: the live admin key reached the log
+// field in the clear. logSafeFragment already made exactly this allowance for a
+// fragment; a decoded path needs it for the same reason.
+//
+// Every '?'-delimited piece is redacted, not just the first: a second '?' is
+// otherwise swallowed into a parameter VALUE, where the name rule stops
+// looking. The cost stays bounded by the caller's input cap — the pieces
+// partition the segment, so the total work over a path is still linear in its
+// (capped) length.
+func logSafePathSegment(segment string) string {
+	if !strings.Contains(segment, "?") {
+		return LogSafeQueryString(segment)
+	}
+	pieces := strings.Split(segment, "?")
+	for i, piece := range pieces {
+		pieces[i] = LogSafeQueryString(piece)
+	}
+	return strings.Join(pieces, "?")
+}
+
 // logSafeFragment redacts a URL fragment. No URL renderer applies the name rule
 // there, but a fragment carries `k=v` pairs as readily as a query does — hash
 // routing puts a whole path and query after the '#' — so the same rule runs over

internal/server/mcp_logging_path_redaction_test.go

@@ -0,0 +1,125 @@
+package server
+
+import (
+	"fmt"
+	"net/http"
+	"net/http/httptest"
+	"strings"
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zaptest/observer"
+)
+
+// SEC-01 follow-up. PR #1350 routed every `path` log field in internal/httpapi
+// through oauth.LogSafeRequestPath. The MCP mux's own logging wrapper was left
+// behind: it wrote `zap.String("path", r.URL.Path)` verbatim, three times per
+// request (Debug on arrival, then Debug or Warn on completion).
+//
+// That is a live sink for a client-controlled string. `/mcp/` and `/mcp/p/` are
+// registered as SUBTREE patterns, so every byte after the prefix is whatever
+// the caller sent; `ExtractToken` accepts `?apikey=<KEY>` on this very
+// endpoint, so a client configured with the key in the wrong part of the URL is
+// not a hypothetical shape; and r.URL.Path arrives percent-DECODED, so
+// `%3Fapikey%3D` and `Bearer%20<token>` both land here as the real thing. The
+// completion line is logged at Warn on any >=400 response, which is on at the
+// DEFAULT log level — no debug flag involved.
+//
+// The oracle is the one issue #1158 settled on: no RUN of the credential's
+// bytes may survive anywhere in the rendered line. A whole-string containment
+// check passes against a half-mask.
+func assertNoCredentialRun(t *testing.T, rendered, secret string, minRun int) {
+	t.Helper()
+	for i := 0; i+minRun <= len(secret); i++ {
+		assert.NotContains(t, rendered, secret[i:i+minRun],
+			"a %d-byte run of the credential survived into %q", minRun, rendered)
+	}
+}
+
+func renderObservedLines(logs *observer.ObservedLogs) string {
+	var b strings.Builder
+	for _, entry := range logs.All() {
+		b.WriteString(entry.Message)
+		for k, v := range entry.ContextMap() {
+			fmt.Fprintf(&b, " %s=%v", k, v)
+		}
+		b.WriteString("\n")
+	}
+	return b.String()
+}
+
+// newObservedMCPLoggingHandler builds the MCP logging wrapper against an
+// in-memory log sink. mcpLoggingHandler reads nothing from Server but the
+// logger, so no runtime, storage or listener is needed.
+func newObservedMCPLoggingHandler(t *testing.T, status int) (http.Handler, *observer.ObservedLogs) {
+	t.Helper()
+	core, logs := observer.New(zap.DebugLevel)
+	s := &Server{logger: zap.New(core)}
+	return s.mcpLoggingHandler(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
+		w.WriteHeader(status)
+	})), logs
+}
+
+// adminKeyInPath is the shape an `?apikey=` credential takes once it has been
+// percent-decoded into r.URL.Path, or typed into the path by a
+// misconfigured client. 64 hex characters is what cmd/mcpproxy generates.
+const adminKeyInPath = "4f3c2b1a9e8d7c6b5a4f3e2d1c0b9a8f7e6d5c4b3a2f1e0d9c8b7a6f5e4d3c2b"
+
+func TestMCPLoggingHandlerRedactsANamedCredentialInThePath(t *testing.T) {
+	handler, logs := newObservedMCPLoggingHandler(t, http.StatusOK)
+
+	handler.ServeHTTP(httptest.NewRecorder(),
+		httptest.NewRequest(http.MethodGet, "/mcp/apikey="+adminKeyInPath, nil))
+
+	out := renderObservedLines(logs)
+	require.NotEmpty(t, out, "the handler must still log — a fix that deletes the line is not the fix")
+	require.Contains(t, out, "/mcp/", "the diagnostic part of the path must survive redaction")
+	assertNoCredentialRun(t, out, adminKeyInPath, 12)
+}
+
+// The completion line at Warn is the one that fires at the DEFAULT log level,
+// so it is the one that actually writes to main.log on a stock install.
+func TestMCPLoggingHandlerRedactsThePathOnTheWarnCompletionLine(t *testing.T) {
+	handler, logs := newObservedMCPLoggingHandler(t, http.StatusNotFound)
+
+	handler.ServeHTTP(httptest.NewRecorder(),
+		httptest.NewRequest(http.MethodGet, "/mcp/p/apikey="+adminKeyInPath, nil))
+
+	warnLines := logs.FilterLevelExact(zap.WarnLevel).All()
+	require.NotEmpty(t, warnLines, "a >=400 response must still be logged at Warn")
+	assertNoCredentialRun(t, renderObservedLines(logs), adminKeyInPath, 12)
+}
+
+// r.URL.Path arrives percent-decoded, so `Bearer%20<token>` in the request
+// target reaches this log field as a real `Bearer <token>` — a shape no
+// `name=value` rule can see. LogSafeRequestPath applies the token rule for it.
+func TestMCPLoggingHandlerRedactsABearerTokenInThePath(t *testing.T) {
+	const agentToken = "mcp_agt_Zt7Qv2Lm9XbR4pWc8HsKd3Ng6JyF1aUe"
+
+	handler, logs := newObservedMCPLoggingHandler(t, http.StatusOK)
+
+	handler.ServeHTTP(httptest.NewRecorder(),
+		httptest.NewRequest(http.MethodGet, "/mcp/Bearer%20"+agentToken, nil))
+
+	assertNoCredentialRun(t, renderObservedLines(logs), agentToken, 12)
+}
+
+// The realistic delivery vehicle for the LIVE admin key. `?apikey=<KEY>` is the
+// credential form mcpproxy's own Connect wizard and Web UI hand out, and
+// net/http hands the handler a percent-DECODED r.URL.Path — so a client that
+// encodes its URL suffix turns `GET /mcp/%3Fapikey%3D<KEY>` into the path
+// `/mcp/?apikey=<KEY>`, which ServeMux still matches against the `/mcp/`
+// subtree pattern and which this log field then received verbatim.
+func TestMCPLoggingHandlerRedactsAnEncodedQueryInsideThePath(t *testing.T) {
+	handler, logs := newObservedMCPLoggingHandler(t, http.StatusOK)
+
+	req := httptest.NewRequest(http.MethodGet, "/mcp/%3Fapikey%3D"+adminKeyInPath, nil)
+	require.Equal(t, "/mcp/?apikey="+adminKeyInPath, req.URL.Path,
+		"net/http must still hand the handler a DECODED path — the premise of this test")
+
+	handler.ServeHTTP(httptest.NewRecorder(), req)
+
+	assertNoCredentialRun(t, renderObservedLines(logs), adminKeyInPath, 12)
+}