diff --git a/nextcloud_mcp_server/auth/oauth_routes.py b/nextcloud_mcp_server/auth/oauth_routes.py index f3bb43d..cf5fff8 100644 --- a/nextcloud_mcp_server/auth/oauth_routes.py +++ b/nextcloud_mcp_server/auth/oauth_routes.py @@ -493,14 +493,22 @@ async def oauth_callback_nextcloud(request: Request): id_token = token_data.get("id_token") # Decode ID token to get user info + logger.info("=" * 60) + logger.info("oauth_callback_nextcloud: Extracting user_id from ID token") + logger.info("=" * 60) try: userinfo = jwt.decode(id_token, options={"verify_signature": False}) user_id = userinfo.get("sub") username = userinfo.get("preferred_username") or userinfo.get("email") + logger.info(" ✓ ID token decode SUCCESSFUL") + logger.info(f" Extracted user_id: {user_id}") + logger.info(f" Username: {username}") + logger.info(f" ID token payload keys: {list(userinfo.keys())}") logger.info(f"Flow 2: User {username} provisioned resource access") except Exception as e: - logger.warning(f"Failed to decode ID token: {e}") + logger.error(f" ✗ ID token decode FAILED: {type(e).__name__}: {e}") user_id = "unknown" + logger.error(f" Using fallback user_id: {user_id}") # Store master refresh token for Flow 2 if refresh_token: @@ -509,6 +517,13 @@ async def oauth_callback_nextcloud(request: Request): token_data.get("scope", "").split() if token_data.get("scope") else None ) + logger.info("Storing refresh token:") + logger.info(f" user_id: {user_id}") + logger.info(" flow_type: flow2") + logger.info(" token_audience: nextcloud") + logger.info(f" provisioning_client_id: {state[:16]}...") + logger.info(f" scopes: {granted_scopes}") + await storage.store_refresh_token( user_id=user_id, refresh_token=refresh_token, @@ -518,7 +533,8 @@ async def oauth_callback_nextcloud(request: Request): scopes=granted_scopes, expires_at=None, # Refresh tokens typically don't expire ) - logger.info(f"Stored Flow 2 master refresh token for user {user_id}") + logger.info(f"✓ Stored Flow 2 master refresh token for user {user_id}") + logger.info("=" * 60) # Return success HTML page success_html = """ diff --git a/nextcloud_mcp_server/server/oauth_tools.py b/nextcloud_mcp_server/server/oauth_tools.py index fafdcd3..1fd6e94 100644 --- a/nextcloud_mcp_server/server/oauth_tools.py +++ b/nextcloud_mcp_server/server/oauth_tools.py @@ -11,16 +11,88 @@ import secrets from typing import Optional from urllib.parse import urlencode +import httpx +from mcp.server.auth.middleware.auth_context import get_access_token +from mcp.server.auth.provider import AccessToken from mcp.server.fastmcp import Context from pydantic import BaseModel, Field from nextcloud_mcp_server.auth import require_scopes from nextcloud_mcp_server.auth.refresh_token_storage import RefreshTokenStorage from nextcloud_mcp_server.auth.token_broker import TokenBrokerService +from nextcloud_mcp_server.auth.userinfo_routes import _query_idp_userinfo logger = logging.getLogger(__name__) +async def extract_user_id_from_token(ctx: Context) -> str: + """Extract user_id from the MCP access token (Flow 1). + + Handles both JWT and opaque tokens: + - JWT: Decode and extract 'sub' claim + - Opaque: Call userinfo endpoint to get 'sub' + + Args: + ctx: MCP context with access token + + Returns: + user_id extracted from token, or "default_user" as fallback + """ + # Use MCP SDK's get_access_token() which uses contextvars + access_token: AccessToken | None = get_access_token() + + if not access_token or not access_token.token: + logger.warning(" ✗ No access token found via get_access_token()") + return "default_user" + + token = access_token.token + is_jwt = "." in token and token.count(".") >= 2 + logger.info(f" Token type: {'JWT' if is_jwt else 'Opaque'}") + + # Try JWT decode first + if is_jwt: + try: + import jwt + + payload = jwt.decode(token, options={"verify_signature": False}) + user_id = payload.get("sub", "unknown") + logger.info(f" ✓ JWT decode successful: user_id={user_id}") + return user_id + except Exception as e: + logger.error(f" ✗ JWT decode failed: {type(e).__name__}: {e}") + + # Opaque token - call userinfo endpoint + logger.info(" Opaque token detected, calling userinfo endpoint...") + try: + # Get userinfo endpoint from OIDC discovery + oidc_discovery_uri = os.getenv( + "OIDC_DISCOVERY_URI", + "http://localhost:8080/.well-known/openid-configuration", + ) + async with httpx.AsyncClient() as http_client: + discovery_response = await http_client.get(oidc_discovery_uri) + discovery_response.raise_for_status() + discovery = discovery_response.json() + userinfo_endpoint = discovery.get("userinfo_endpoint") + + if userinfo_endpoint: + userinfo = await _query_idp_userinfo(token, userinfo_endpoint) + if userinfo: + user_id = userinfo.get("sub", "unknown") + logger.info(f" ✓ Userinfo query successful: user_id={user_id}") + return user_id + else: + logger.error(" ✗ Userinfo query failed") + else: + logger.error(" ✗ No userinfo_endpoint available") + except Exception as e: + logger.error(f" ✗ Userinfo query failed: {type(e).__name__}: {e}") + + # Fallback + logger.warning(" Using fallback user_id: default_user") + return "default_user" + + class ProvisioningStatus(BaseModel): """Status of Nextcloud provisioning for a user.""" @@ -80,14 +152,28 @@ async def get_provisioning_status(ctx: Context, user_id: str) -> ProvisioningSta Returns: ProvisioningStatus with current provisioning state """ + logger.info( + f" get_provisioning_status: Looking up refresh token for user_id={user_id}" + ) storage = RefreshTokenStorage.from_env() await storage.initialize() token_data = await storage.get_refresh_token(user_id) if not token_data: + logger.info( + f" get_provisioning_status: ✗ No refresh token found for user_id={user_id}" + ) return ProvisioningStatus(is_provisioned=False) + logger.info( + f" get_provisioning_status: ✓ Refresh token FOUND for user_id={user_id}" + ) + logger.info(f" flow_type: {token_data.get('flow_type')}") + logger.info( + f" provisioning_client_id: {token_data.get('provisioning_client_id', 'N/A')}" + ) + # Convert timestamp to ISO format if present provisioned_at_str = None if token_data.get("provisioned_at"): @@ -313,13 +399,11 @@ async def revoke_nextcloud_access( RevocationResult with status """ try: - # Get user ID from context if not provided + # Get user ID from token if not provided if not user_id: - user_id = ( - ctx.context.get("user_id", "default_user") # type: ignore - if hasattr(ctx, "context") - else "default_user" - ) + logger.info("Extracting user_id from access token for revoke...") + user_id = await extract_user_id_from_token(ctx) + logger.info(f" Revoke using user_id: {user_id}") # Check current status status = await get_provisioning_status(ctx, user_id) @@ -419,28 +503,29 @@ async def check_logged_in(ctx: Context, user_id: Optional[str] = None) -> str: """ try: # Extract user ID from the MCP access token (Flow 1 token) - if not user_id: - # Get the authorization token from context - if hasattr(ctx, "authorization") and ctx.authorization: - token = ctx.authorization.token # type: ignore - # Decode token to get user info - try: - import jwt + logger.info("=" * 60) + logger.info("check_logged_in: Starting user_id extraction") + logger.info("=" * 60) - payload = jwt.decode(token, options={"verify_signature": False}) - user_id = payload.get("sub", "unknown") - logger.info(f"Extracted user_id from Flow 1 token: {user_id}") - except Exception as e: - logger.warning(f"Failed to decode token: {e}") - user_id = "default_user" - else: - user_id = "default_user" + if not user_id: + user_id = await extract_user_id_from_token(ctx) + logger.info(f" Final user_id for check_logged_in: {user_id}") + else: + logger.info(f" user_id provided as argument: {user_id}") # Check if already logged in + logger.info(f"Checking provisioning status for user_id: {user_id}") status = await get_provisioning_status(ctx, user_id) + logger.info(f" Provisioning status: is_provisioned={status.is_provisioned}") + if status.is_provisioned: + logger.info(f"✓ User {user_id} is already logged in - returning 'yes'") + logger.info("=" * 60) return "yes" + logger.info(f"✗ User {user_id} is NOT logged in - triggering elicitation") + logger.info("=" * 60) + # Not logged in - generate OAuth URL for Flow 2 enable_offline_access = ( os.getenv("ENABLE_OFFLINE_ACCESS", "false").lower() == "true" diff --git a/tests/conftest.py b/tests/conftest.py index b98e5bb..4a00380 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -8,7 +8,9 @@ import httpx import pytest from httpx import HTTPStatusError from mcp import ClientSession +from mcp.client.session import RequestContext from mcp.client.streamable_http import streamablehttp_client +from mcp.types import ElicitRequestParams, ElicitResult, ErrorData from nextcloud_mcp_server.client import NextcloudClient @@ -110,6 +112,7 @@ async def create_mcp_client_session( url: str, token: str | None = None, client_name: str = "MCP", + elicitation_callback: Any = None, ) -> AsyncGenerator[ClientSession, Any]: """ Factory function to create an MCP client session with proper lifecycle management. @@ -127,6 +130,8 @@ async def create_mcp_client_session( url: MCP server URL (e.g., "http://localhost:8000/mcp") token: Optional OAuth access token for Bearer authentication client_name: Client name for logging (e.g., "OAuth MCP (Playwright)") + elicitation_callback: Optional callback for handling elicitation requests. + Should match signature: async def callback(context: RequestContext, params: ElicitRequestParams) -> ElicitResult | ErrorData Yields: Initialized MCP ClientSession @@ -149,7 +154,9 @@ async def create_mcp_client_session( write_stream, _, ): - async with ClientSession(read_stream, write_stream) as session: + async with ClientSession( + read_stream, write_stream, elicitation_callback=elicitation_callback + ) as session: await session.initialize() logger.info(f"{client_name} client session initialized successfully") yield session @@ -251,6 +258,132 @@ async def nc_mcp_oauth_jwt_client( yield session +@pytest.fixture +async def nc_mcp_oauth_client_with_elicitation( + anyio_backend, + playwright_oauth_token: str, + browser, +) -> AsyncGenerator[ClientSession, Any]: + """ + Fixture to create an MCP client session with elicitation callback support. + + This fixture enables REAL elicitation testing by providing a callback that: + 1. Extracts OAuth URL from elicitation message + 2. Uses Playwright to complete OAuth flow automatically + 3. Returns acceptance to confirm completion + + This allows testing the complete login elicitation flow (ADR-006) end-to-end, + verifying that: + - The check_logged_in tool triggers elicitation for unauthenticated users + - The OAuth flow completes successfully via automated browser + - Refresh token is stored after OAuth completion + - The tool returns "yes" after successful login + + Uses function scope to allow each test to have independent elicitation state. + """ + # Get credentials from environment + username = os.getenv("NEXTCLOUD_USERNAME") + password = os.getenv("NEXTCLOUD_PASSWORD") + + if not all([username, password]): + pytest.skip( + "Elicitation test requires NEXTCLOUD_USERNAME and NEXTCLOUD_PASSWORD" + ) + + # Track whether elicitation was triggered (for test validation) + elicitation_triggered = {"count": 0} + + async def elicitation_callback( + context: RequestContext[ClientSession, Any], + params: ElicitRequestParams, + ) -> ElicitResult | ErrorData: + """Handle elicitation by completing OAuth flow with Playwright.""" + elicitation_triggered["count"] += 1 + + logger.info("🎯 Elicitation callback invoked!") + logger.info(f" Message: {params.message[:100]}...") + logger.info(f" Schema: {params.schema}") + + # Extract OAuth URL from elicitation message + import re + + url_pattern = r"https?://[^\s]+" + urls = re.findall(url_pattern, params.message) + + if not urls: + error_msg = "No URL found in elicitation message" + logger.error(f"❌ {error_msg}") + return ErrorData(code=-32602, message=error_msg) + + oauth_url = urls[0] + logger.info(f" Extracted URL: {oauth_url}") + + # Complete OAuth flow with Playwright + page = await browser.new_page() + try: + logger.info("🌐 Navigating to OAuth URL...") + await page.goto(oauth_url, timeout=60000) + + current_url = page.url + logger.info(f" Current URL after navigation: {current_url}") + + # Handle login form if present + if "/login" in current_url or "/index.php/login" in current_url: + logger.info("🔐 Login page detected, filling credentials...") + await page.wait_for_selector('input[name="user"]', timeout=10000) + await page.fill('input[name="user"]', username) + await page.fill('input[name="password"]', password) + await page.click('button[type="submit"]') + await page.wait_for_load_state("networkidle", timeout=60000) + logger.info(" ✓ Login completed") + + # Handle consent screen if present + try: + consent_handled = await _handle_oauth_consent_screen(page, username) + if consent_handled: + logger.info(" ✓ Consent granted") + except Exception as e: + logger.debug(f" No consent screen: {e}") + + # Wait for OAuth callback completion (redirect to success page or callback URL) + # The MCP server's callback endpoint will handle token exchange + await page.wait_for_load_state("networkidle", timeout=30000) + final_url = page.url + logger.info(f" Final URL: {final_url}") + + # Return success - user "accepted" the elicitation + logger.info("✅ OAuth flow completed, returning accept") + return ElicitResult(action="accept", content={"acknowledged": True}) + + except Exception as e: + logger.error(f"❌ Elicitation OAuth flow failed: {e}") + # Take screenshot for debugging + try: + screenshot_path = f"/tmp/elicitation_oauth_failure_{uuid.uuid4()}.png" + await page.screenshot(path=screenshot_path) + logger.error(f" Screenshot saved: {screenshot_path}") + except Exception: + pass + + return ErrorData( + code=-32603, message=f"Failed to complete OAuth flow: {str(e)}" + ) + + finally: + await page.close() + + # Create client session with elicitation callback + async for session in create_mcp_client_session( + url="http://localhost:8001/mcp", + token=playwright_oauth_token, + client_name="OAuth MCP with Elicitation", + elicitation_callback=elicitation_callback, + ): + # Attach elicitation metadata for test validation + session.elicitation_triggered = elicitation_triggered + yield session + + @pytest.fixture(scope="session") async def nc_mcp_oauth_client_read_only( anyio_backend, diff --git a/tests/server/oauth/test_elicitation_integration.py b/tests/server/oauth/test_elicitation_integration.py new file mode 100644 index 0000000..dfec2a7 --- /dev/null +++ b/tests/server/oauth/test_elicitation_integration.py @@ -0,0 +1,206 @@ +"""Integration tests for login elicitation with real MCP client callback support. + +These tests verify the complete end-to-end login elicitation flow (ADR-006) +using the python-sdk MCP client with actual elicitation callback implementation. + +Unlike test_login_elicitation.py which validates response formats, these tests +exercise the REAL elicitation protocol: +1. MCP client with elicitation callback connects to server +2. Tool triggers elicitation (ctx.elicit()) +3. Client callback receives elicitation request +4. Callback completes OAuth flow via Playwright automation +5. Client returns acceptance +6. Tool proceeds with authenticated operation + +This validates that: +- python-sdk MCP client can handle elicitation requests +- OAuth flow completion via callback works end-to-end +- Refresh tokens are properly stored after elicitation +- check_logged_in returns "yes" after successful OAuth +""" + +import logging + +import pytest + +logger = logging.getLogger(__name__) + +pytestmark = [pytest.mark.integration, pytest.mark.oauth] + + +async def revoke_refresh_tokens(client): + """Helper to revoke all refresh tokens from MCP server. + + This forces check_logged_in to trigger elicitation by removing + any existing refresh tokens via the revoke_nextcloud_access tool. + """ + logger.info("Revoking refresh tokens via revoke_nextcloud_access tool...") + + result = await client.call_tool("revoke_nextcloud_access", arguments={}) + + logger.info(f"Revoke result: isError={result.isError}") + if not result.isError: + logger.info(f"✓ Revoke response: {result.content[0].text}") + else: + logger.warning(f"Revoke failed: {result.content}") + + +async def test_check_logged_in_with_real_elicitation_callback( + nc_mcp_oauth_client_with_elicitation, +): + """Test check_logged_in with actual elicitation callback that completes OAuth. + + This test validates the COMPLETE elicitation flow: + 1. Call check_logged_in tool (which triggers elicitation) + 2. Elicitation callback extracts OAuth URL + 3. Playwright automation completes OAuth flow + 4. Callback returns acceptance + 5. Tool returns "yes" (logged in) + 6. Refresh token is stored + + This is the ONLY test that exercises the real MCP elicitation protocol + with python-sdk's ClientSession elicitation callback support. + """ + client = nc_mcp_oauth_client_with_elicitation + + logger.info("=" * 80) + logger.info("TEST: Real elicitation callback with OAuth completion") + logger.info("=" * 80) + + # Revoke refresh tokens to force elicitation + await revoke_refresh_tokens(client) + + # Call check_logged_in - this should trigger elicitation + logger.info("Calling check_logged_in tool...") + result = await client.call_tool("check_logged_in", arguments={}) + + logger.info("Tool execution completed") + logger.info(f" Is error: {result.isError}") + if result.content: + response_text = result.content[0].text + logger.info(f" Response: {response_text}") + else: + logger.warning(" No content in response") + + # Validate tool execution succeeded + assert result.isError is False, f"Tool execution failed: {result.content}" + assert result.content is not None, "No content in tool response" + + response_text = result.content[0].text.lower() + + # Validate elicitation was triggered + elicitation_count = client.elicitation_triggered["count"] + logger.info(f"✓ Elicitation triggered {elicitation_count} time(s)") + assert elicitation_count >= 1, ( + "Elicitation callback should have been invoked at least once" + ) + + # Validate OAuth completed successfully and tool returned "yes" + assert "yes" in response_text, ( + f"Expected 'yes' after successful OAuth via elicitation, got: {response_text}" + ) + + logger.info("✅ Test passed: Real elicitation callback completed OAuth flow") + logger.info("=" * 80) + + +async def test_elicitation_callback_url_extraction( + nc_mcp_oauth_client_with_elicitation, +): + """Test that elicitation callback correctly extracts OAuth URL. + + This validates the URL extraction logic in the callback by examining + the elicitation message format returned by check_logged_in. + """ + client = nc_mcp_oauth_client_with_elicitation + + logger.info("Testing OAuth URL extraction from elicitation message...") + + # Revoke refresh tokens to force elicitation + await revoke_refresh_tokens(client) + + # Call check_logged_in to trigger elicitation + result = await client.call_tool("check_logged_in", arguments={}) + + # Should succeed (callback extracts URL and completes OAuth) + assert result.isError is False + assert "yes" in result.content[0].text.lower() + + # Elicitation should have been triggered + assert client.elicitation_triggered["count"] >= 1 + + logger.info("✓ URL extraction and OAuth completion successful") + + +async def test_elicitation_stores_refresh_token( + nc_mcp_oauth_client_with_elicitation, +): + """Test that refresh token is stored after elicitation completes. + + Validates that after successful OAuth via elicitation: + 1. check_logged_in returns "yes" + 2. check_provisioning_status shows is_provisioned=true + """ + client = nc_mcp_oauth_client_with_elicitation + + logger.info("Testing refresh token storage after elicitation...") + + # Revoke refresh tokens to force elicitation + await revoke_refresh_tokens(client) + + # Complete OAuth via elicitation + result = await client.call_tool("check_logged_in", arguments={}) + assert result.isError is False + assert "yes" in result.content[0].text.lower() + + # Verify refresh token was stored + logger.info("Checking provisioning status...") + status_result = await client.call_tool("check_provisioning_status", arguments={}) + + assert status_result.isError is False + status_text = status_result.content[0].text.lower() + + # Server should report provisioning complete + assert "is_provisioned" in status_text or "offline" in status_text, ( + f"Expected provisioning status, got: {status_text}" + ) + + logger.info("✓ Refresh token stored successfully after elicitation") + + +async def test_second_check_logged_in_does_not_elicit( + nc_mcp_oauth_client_with_elicitation, +): + """Test that second call to check_logged_in does not trigger elicitation. + + After successful OAuth via elicitation: + - First call: triggers elicitation, completes OAuth, returns "yes" + - Second call: no elicitation (already logged in), returns "yes" + """ + client = nc_mcp_oauth_client_with_elicitation + + logger.info("Testing that already-logged-in users don't get elicited...") + + # First call: triggers elicitation + result1 = await client.call_tool("check_logged_in", arguments={}) + assert result1.isError is False + assert "yes" in result1.content[0].text.lower() + + elicitation_count_after_first = client.elicitation_triggered["count"] + logger.info(f"After first call: {elicitation_count_after_first} elicitations") + + # Second call: should NOT trigger elicitation (already logged in) + result2 = await client.call_tool("check_logged_in", arguments={}) + assert result2.isError is False + assert "yes" in result2.content[0].text.lower() + + elicitation_count_after_second = client.elicitation_triggered["count"] + logger.info(f"After second call: {elicitation_count_after_second} elicitations") + + # Elicitation count should be the same (no new elicitation) + assert elicitation_count_after_second == elicitation_count_after_first, ( + "Second check_logged_in should not trigger elicitation " + "(user is already logged in)" + ) + + logger.info("✓ Already-logged-in users don't get redundant elicitations")