mcp_auth: INFO-level bearer extraction diagnostics
Temporarily instrument MCPAuthMiddleware to emit one log line per on_call_tool and one per _extract_token. Needed to diagnose why workspace-scoped JWTs forwarded by Pallas land on tool calls with 'Authentication required. Provide a Bearer token.' Logs include header names, auth-header length+prefix, and the request URL so we can tell in one turn whether the header is missing, present but rejected, or get_http_request() raised. Also adds lowercase-bearer tolerance for clients that normalize to lowercase. Demote to DEBUG once the end-to-end path is green.
This commit is contained in:
@@ -207,7 +207,14 @@ class MCPAuthMiddleware(Middleware):
|
|||||||
async def on_call_tool(self, context: MiddlewareContext, call_next):
|
async def on_call_tool(self, context: MiddlewareContext, call_next):
|
||||||
require_auth = getattr(settings, "MCP_REQUIRE_AUTH", True)
|
require_auth = getattr(settings, "MCP_REQUIRE_AUTH", True)
|
||||||
|
|
||||||
if require_auth and self._extract_tool_name(context) in self._PUBLIC_TOOLS:
|
tool_name = self._extract_tool_name(context)
|
||||||
|
logger.info(
|
||||||
|
"mcp_auth.on_call_tool tool=%s require_auth=%s",
|
||||||
|
tool_name,
|
||||||
|
require_auth,
|
||||||
|
)
|
||||||
|
|
||||||
|
if require_auth and tool_name in self._PUBLIC_TOOLS:
|
||||||
return await call_next(context)
|
return await call_next(context)
|
||||||
|
|
||||||
token_string = self._extract_token()
|
token_string = self._extract_token()
|
||||||
@@ -257,13 +264,46 @@ class MCPAuthMiddleware(Middleware):
|
|||||||
|
|
||||||
@staticmethod
|
@staticmethod
|
||||||
def _extract_token() -> str | None:
|
def _extract_token() -> str | None:
|
||||||
|
"""Pull the Bearer token off the current HTTP request, if any.
|
||||||
|
|
||||||
|
The MCP SDK stores the Starlette ``Request`` on ``request_ctx`` for
|
||||||
|
every tool-call dispatch (including follow-up calls on a stateful
|
||||||
|
session), so ``get_http_request()`` should succeed here. If it
|
||||||
|
*doesn't* — e.g. because we're in a background task or pre-session
|
||||||
|
initialize hook — we return ``None`` and let the caller decide.
|
||||||
|
|
||||||
|
INFO-level logging is intentional until bearer-forwarding from
|
||||||
|
Daedalus/Pallas is fully shaken out; demote to DEBUG once green.
|
||||||
|
"""
|
||||||
try:
|
try:
|
||||||
request = get_http_request()
|
request = get_http_request()
|
||||||
except RuntimeError:
|
except RuntimeError as exc:
|
||||||
|
logger.warning(
|
||||||
|
"mcp_auth.extract outcome=no_http_request reason=%r",
|
||||||
|
str(exc),
|
||||||
|
)
|
||||||
return None
|
return None
|
||||||
|
|
||||||
|
# Header lookup is case-insensitive on Starlette ``Headers`` but
|
||||||
|
# different proxies normalize case differently — belt and braces.
|
||||||
auth_header = request.headers.get("Authorization", "")
|
auth_header = request.headers.get("Authorization", "")
|
||||||
|
if not auth_header:
|
||||||
|
auth_header = request.headers.get("authorization", "")
|
||||||
|
|
||||||
|
header_names = sorted(request.headers.keys())
|
||||||
|
logger.info(
|
||||||
|
"mcp_auth.extract outcome=%s len=%d prefix=%r path=%s header_names=%s",
|
||||||
|
"present" if auth_header else "missing",
|
||||||
|
len(auth_header),
|
||||||
|
auth_header[:16] if auth_header else "",
|
||||||
|
str(getattr(request, "url", "")),
|
||||||
|
header_names,
|
||||||
|
)
|
||||||
|
|
||||||
if auth_header.startswith("Bearer "):
|
if auth_header.startswith("Bearer "):
|
||||||
return auth_header[7:].strip() or None
|
return auth_header[7:].strip() or None
|
||||||
|
if auth_header.startswith("bearer "): # some clients lowercase
|
||||||
|
return auth_header[7:].strip() or None
|
||||||
return None
|
return None
|
||||||
|
|
||||||
@staticmethod
|
@staticmethod
|
||||||
|
|||||||
Reference in New Issue
Block a user