feat: Add logging to track MCP tool usage

- Log each tool call with parameters
- Log execution time in milliseconds
- Log result count or error message
- Use WARNING level for business errors

Co-authored-by: Cursor <cursoragent@cursor.com>

src/tools.py

@@ -1,9 +1,63 @@
 """MCP tools for querying territorial ecological indicators."""
 
 import json
-from typing import Any
+import logging
+import time
+from datetime import datetime, timezone
+from functools import wraps
+from typing import Any, Callable
 
 from .api_client import get_client, CubeJsClient, CubeJsClientError
+
+# Configure logging
+logging.basicConfig(
+    level=logging.INFO,
+    format='%(asctime)s | %(levelname)s | %(message)s',
+    datefmt='%Y-%m-%d %H:%M:%S'
+)
+logger = logging.getLogger("mcp_tools")
+
+
+def log_tool_call(func: Callable) -> Callable:
+    """Decorator to log MCP tool calls with timing and parameters."""
+    @wraps(func)
+    async def wrapper(*args, **kwargs):
+        tool_name = func.__name__
+        start_time = time.time()
+        
+        # Log the call
+        params = {k: v for k, v in kwargs.items() if v}  # Only non-empty params
+        logger.info(f"[CALL] {tool_name} | params={params}")
+        
+        try:
+            result = await func(*args, **kwargs)
+            elapsed_ms = int((time.time() - start_time) * 1000)
+            
+            # Parse result to get summary
+            try:
+                result_data = json.loads(result)
+                if "error" in result_data:
+                    logger.warning(f"[ERROR] {tool_name} | {elapsed_ms}ms | error={result_data['error']}")
+                elif "count" in result_data:
+                    logger.info(f"[OK] {tool_name} | {elapsed_ms}ms | count={result_data['count']}")
+                elif "total_count" in result_data:
+                    logger.info(f"[OK] {tool_name} | {elapsed_ms}ms | count={result_data['total_count']}")
+                elif "metadata" in result_data:
+                    ind_id = result_data.get("metadata", {}).get("id", "?")
+                    logger.info(f"[OK] {tool_name} | {elapsed_ms}ms | indicator_id={ind_id}")
+                else:
+                    logger.info(f"[OK] {tool_name} | {elapsed_ms}ms")
+            except json.JSONDecodeError:
+                logger.info(f"[OK] {tool_name} | {elapsed_ms}ms | raw_response")
+            
+            return result
+            
+        except Exception as e:
+            elapsed_ms = int((time.time() - start_time) * 1000)
+            logger.error(f"[EXCEPTION] {tool_name} | {elapsed_ms}ms | {type(e).__name__}: {e}")
+            raise
+    
+    return wrapper
 from .cache import get_cache, initialize_cache, refresh_cache_if_needed
 from .cube_resolver import get_resolver
 from .models import (
@@ -24,6 +78,7 @@ async def _ensure_cache_initialized() -> None:
         await refresh_cache_if_needed()
 
 
+@log_tool_call
 async def list_indicators(
     thematique: str = "",
     maille: str = "",
@@ -77,6 +132,7 @@ async def list_indicators(
     }, ensure_ascii=False, indent=2)
 
 
+@log_tool_call
 async def get_indicator_details(indicator_id: str) -> str:
     """Get detailed information about a specific indicator.
     
@@ -146,6 +202,7 @@ async def get_indicator_details(indicator_id: str) -> str:
     return json.dumps(result, ensure_ascii=False, indent=2)
 
 
+@log_tool_call
 async def query_indicator_data(
     indicator_id: str,
     geographic_level: str,
@@ -305,6 +362,7 @@ async def query_indicator_data(
     }, ensure_ascii=False, indent=2)
 
 
+@log_tool_call
 async def search_indicators(query: str) -> str:
     """Search indicators by keywords in their name or description.