jason/google-mcp
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

logging cleanup

Browse Source
This commit is contained in:
Taylor Wilsdon
2025-08-05 15:58:22 -04:00
parent c861d7484a
commit 2f08cec133
8 changed files with 54 additions and 49 deletions
Download Patch File Download Diff File Expand all files Collapse all files

26
auth/auth_info_middleware.py
View File

@@ -39,17 +39,17 @@ class AuthInfoMiddleware(Middleware):
# Use the new FastMCP method to get HTTP headers
headers = get_http_headers()
if headers:
logger.info(f"Got HTTP headers: {type(headers)}")
logger.debug("Processing HTTP headers for authentication")
# Get the Authorization header
auth_header = headers.get("authorization", "")
if auth_header.startswith("Bearer "):
token_str = auth_header[7:] # Remove "Bearer " prefix
logger.info("Found Bearer token in HTTP request")
logger.debug("Found Bearer token")
# For Google OAuth tokens (ya29.*), we need to verify them differently
if token_str.startswith("ya29."):
logger.info("Detected Google OAuth access token")
logger.debug("Detected Google OAuth access token format")
# Verify the token to get user info
from core.server import get_auth_provider
@@ -95,7 +95,7 @@ class AuthInfoMiddleware(Middleware):
context.fastmcp_context.set_state("authenticated_user_email", user_email)
context.fastmcp_context.set_state("authenticated_via", "bearer_token")
logger.info(f"Stored verified Google OAuth token for user: {user_email}")
logger.info(f"Authenticated via Google OAuth: {user_email}")
else:
logger.error("Failed to verify Google OAuth token")
# Don't set authenticated_user_email if verification failed
@@ -167,7 +167,7 @@ class AuthInfoMiddleware(Middleware):
context.fastmcp_context.set_state("authenticated_user_email", user_email)
context.fastmcp_context.set_state("authenticated_via", "jwt_token")
logger.info("Successfully extracted and stored auth info from HTTP request")
logger.debug("JWT token processed successfully")
except jwt.DecodeError as e:
logger.error(f"Failed to decode JWT: {e}")
@@ -209,7 +209,7 @@ class AuthInfoMiddleware(Middleware):
# Check if user has a recent session
if store.has_session(requested_user):
logger.info(f"User {requested_user} has recent auth session in stdio mode")
logger.debug(f"Using recent stdio session for {requested_user}")
# In stdio mode, we can trust the user has authenticated recently
context.fastmcp_context.set_state("authenticated_user_email", requested_user)
context.fastmcp_context.set_state("authenticated_via", "stdio_session")
@@ -228,7 +228,7 @@ class AuthInfoMiddleware(Middleware):
# Check if this MCP session is bound to a user
bound_user = store.get_user_by_mcp_session(mcp_session_id)
if bound_user:
logger.info(f"MCP session {mcp_session_id} is bound to user {bound_user}")
logger.debug(f"MCP session bound to {bound_user}")
context.fastmcp_context.set_state("authenticated_user_email", bound_user)
context.fastmcp_context.set_state("authenticated_via", "mcp_session_binding")
context.fastmcp_context.set_state("auth_provider_type", "oauth21_session")
@@ -237,14 +237,14 @@ class AuthInfoMiddleware(Middleware):
async def on_call_tool(self, context: MiddlewareContext, call_next):
"""Extract auth info from token and set in context state"""
logger.info("on_call_tool called")
logger.debug("Processing tool call authentication")
try:
await self._process_request_for_auth(context)
logger.info("Calling next middleware/handler")
logger.debug("Passing to next handler")
result = await call_next(context)
logger.info("Successfully completed call_next()")
logger.debug("Handler completed")
return result
except Exception as e:
@@ -257,14 +257,14 @@ class AuthInfoMiddleware(Middleware):
async def on_get_prompt(self, context: MiddlewareContext, call_next):
"""Extract auth info for prompt requests too"""
logger.info("on_get_prompt called")
logger.debug("Processing prompt authentication")
try:
await self._process_request_for_auth(context)
logger.info("Calling next middleware/handler for prompt")
logger.debug("Passing prompt to next handler")
result = await call_next(context)
logger.info("Successfully completed prompt call_next()")
logger.debug("Prompt handler completed")
return result
except Exception as e:

14
auth/google_remote_auth_provider.py
View File

@@ -65,14 +65,14 @@ class GoogleRemoteAuthProvider(RemoteAuthProvider):
self.port = int(os.getenv("PORT", os.getenv("WORKSPACE_MCP_PORT", 8000)))
if not self.client_id:
logger.warning("GOOGLE_OAUTH_CLIENT_ID not set - OAuth 2.1 authentication will not work")
# Still initialize to avoid errors, but auth won't work
logger.error("GOOGLE_OAUTH_CLIENT_ID not set - OAuth 2.1 authentication will not work")
raise ValueError("GOOGLE_OAUTH_CLIENT_ID environment variable is required for OAuth 2.1 authentication")
# Configure JWT verifier for Google tokens
token_verifier = JWTVerifier(
jwks_uri="https://www.googleapis.com/oauth2/v3/certs",
issuer="https://accounts.google.com",
audience=self.client_id or "placeholder", # Use placeholder if not configured
audience=self.client_id, # Always use actual client_id
algorithm="RS256"
)
@@ -84,7 +84,7 @@ class GoogleRemoteAuthProvider(RemoteAuthProvider):
resource_server_url=f"{self.base_url}:{self.port}"
)
logger.info("GoogleRemoteAuthProvider initialized with RemoteAuthProvider pattern")
logger.debug("GoogleRemoteAuthProvider initialized")
def get_routes(self) -> List[Route]:
"""
@@ -97,9 +97,7 @@ class GoogleRemoteAuthProvider(RemoteAuthProvider):
routes = super().get_routes()
# Log what routes we're getting from the parent
logger.info(f"GoogleRemoteAuthProvider: Parent provided {len(routes)} routes")
for route in routes:
logger.info(f" - {route.path} ({', '.join(route.methods)})")
logger.debug(f"Registered {len(routes)} OAuth routes from parent")
# Add our custom proxy endpoints using common handlers
routes.append(Route("/oauth2/authorize", handle_oauth_authorize, methods=["GET", "OPTIONS"]))
@@ -198,7 +196,7 @@ class GoogleRemoteAuthProvider(RemoteAuthProvider):
issuer="https://accounts.google.com"
)
logger.info(f"Successfully verified Google OAuth token for user: {user_email}")
logger.info(f"Verified OAuth token: {user_email}")
return access_token

2
auth/oauth21_integration.py
View File

@@ -176,7 +176,7 @@ def enable_oauth21():
"""
global _oauth21_enabled
_oauth21_enabled = True
logger.info("OAuth 2.1 authentication has been enabled.")
logger.debug("OAuth 2.1 authentication enabled")
async def get_legacy_auth_service(

2
auth/oauth21_session_store.py
View File

@@ -464,7 +464,7 @@ def set_auth_provider(provider):
"""Set the global auth provider instance."""
global _auth_provider
_auth_provider = provider
logger.info("OAuth 2.1 auth provider configured for Google credential bridging")
logger.debug("OAuth 2.1 session store configured")
def get_auth_provider():

6
auth/oauth_common_handlers.py
View File

@@ -136,8 +136,12 @@ async def handle_proxy_token_exchange(request: Request):
issuer="https://accounts.google.com"
)
user_email = id_token_claims.get("email")
email_verified = id_token_claims.get("email_verified")
if user_email:
if not email_verified:
logger.error(f"Email address for user {user_email} is not verified by Google. Aborting session creation.")
return Response(content="Email address not verified", status_code=403)
elif user_email:
# Try to get FastMCP session ID from request context for binding
mcp_session_id = None
try:

25
auth/service_decorator.py
View File

@@ -66,7 +66,7 @@ async def get_authenticated_google_service_oauth21(
# Build service
service = build(service_name, version, credentials=credentials)
logger.info(f"[{tool_name}] Successfully authenticated {service_name} service using OAuth 2.1 for user: {user_google_email}")
logger.info(f"[{tool_name}] Authenticated {service_name} for {user_google_email}")
return service, user_google_email
@@ -329,20 +329,17 @@ def require_google_service(
from core.context import set_fastmcp_session_id
set_fastmcp_session_id(mcp_session_id)
logger.info(f"[{tool_name}] Authentication from middleware: user={authenticated_user}, method={auth_method}")
logger.debug(f"[{tool_name}] Auth from middleware: {authenticated_user} via {auth_method}")
except Exception as e:
logger.debug(f"[{tool_name}] Could not get FastMCP context: {e}")
# Log authentication status
logger.info(f"[{tool_name}] Authentication Status:"
f" Method={auth_method or 'none'},"
f" User={authenticated_user or 'none'},"
f" MCPSessionID={mcp_session_id or 'none'}")
logger.debug(f"[{tool_name}] Auth: {authenticated_user or 'none'} via {auth_method or 'none'} (session: {mcp_session_id[:8] if mcp_session_id else 'none'})")
from auth.oauth21_integration import is_oauth21_enabled
if is_oauth21_enabled():
logger.debug(f"[{tool_name}] Attempting OAuth 2.1 authentication flow.")
logger.debug(f"[{tool_name}] Using OAuth 2.1 flow")
# The downstream get_authenticated_google_service_oauth21 will handle
# whether the user's token is valid for the requested resource.
# This decorator should not block the call here.
@@ -358,7 +355,7 @@ def require_google_service(
)
else:
# If OAuth 2.1 is not enabled, always use the legacy authentication method.
logger.debug(f"[{tool_name}] Using legacy authentication flow (OAuth 2.1 disabled).")
logger.debug(f"[{tool_name}] Using legacy OAuth flow")
service, actual_user_email = await get_authenticated_google_service(
service_name=service_name,
version=service_version,
@@ -371,7 +368,12 @@ def require_google_service(
if cache_enabled:
cache_key = _get_cache_key(user_google_email, service_name, service_version, resolved_scopes)
_cache_service(cache_key, service, actual_user_email)
except GoogleAuthenticationError:
except GoogleAuthenticationError as e:
logger.error(
f"[{tool_name}] GoogleAuthenticationError during authentication. "
f"Method={auth_method or 'none'}, User={authenticated_user or 'none'}, "
f"Service={service_name} v{service_version}, MCPSessionID={mcp_session_id or 'none'}: {e}"
)
# Re-raise the original error without wrapping it
raise
@@ -493,7 +495,10 @@ def require_multiple_services(service_configs: List[Dict[str, Any]]):
# Inject service with specified parameter name
kwargs[param_name] = service
except GoogleAuthenticationError:
except GoogleAuthenticationError as e:
logger.error(
f"[{tool_name}] GoogleAuthenticationError for service '{service_type}' (user: {user_google_email}): {e}"
)
# Re-raise the original error without wrapping it
raise