feat(logging): add structured request/response logging gated on WEBEX_DEBUG

src/webex_bot_mcp/main.py

@@ -61,11 +61,16 @@
     update_webex_webhook, delete_webex_webhook,
 )
 
-# Import version and error handling from common
-from webex_bot_mcp.tools.common import MCP_SERVER_VERSION, MCP_SPEC_VERSION
+# Import version, error handling, and logging setup from common
+from webex_bot_mcp.tools.common import MCP_SERVER_VERSION, MCP_SPEC_VERSION, setup_logging, log_tool_call
+from webex_bot_mcp.config import get_config
 
 webex_access_token = os.getenv("WEBEX_ACCESS_TOKEN")
 
+# Configure logging from environment before any tools run
+_cfg = get_config()
+setup_logging(log_level=_cfg.log_level, log_format=_cfg.log_format, debug=_cfg.debug)
+
 
 class WebexAuthMiddleware(BaseHTTPMiddleware):
     """Enforce Bearer token auth on all MCP requests; expose /health unauthenticated."""
@@ -86,72 +91,76 @@ async def dispatch(self, request, call_next):
 # Initialize FastMCP with a name for the bot
 mcp = FastMCP("Webex Bot MCP")
 
-# Register all tools with FastMCP
+# Register all tools with FastMCP (wrapped with request/response logging)
+def _tool(func):
+    mcp.tool()(log_tool_call(func))
+
+
 # Room management tools
-mcp.tool()(list_webex_rooms)
-mcp.tool()(create_webex_room)
-mcp.tool()(update_webex_room)
-mcp.tool()(get_webex_room)
-mcp.tool()(delete_webex_room)
+_tool(list_webex_rooms)
+_tool(create_webex_room)
+_tool(update_webex_room)
+_tool(get_webex_room)
+_tool(delete_webex_room)
 
 # Space aliases (same functionality as rooms but with "space" terminology)
-mcp.tool()(list_webex_spaces)
-mcp.tool()(create_webex_space)
-mcp.tool()(update_webex_space)
-mcp.tool()(get_webex_space)
-mcp.tool()(delete_webex_space)
+_tool(list_webex_spaces)
+_tool(create_webex_space)
+_tool(update_webex_space)
+_tool(get_webex_space)
+_tool(delete_webex_space)
 
 # Message management tools
-mcp.tool()(send_webex_message)
-mcp.tool()(send_webex_message_with_mentions)
-mcp.tool()(list_webex_messages)
-mcp.tool()(delete_webex_message)
-mcp.tool()(update_webex_message)
-mcp.tool()(get_webex_attachment_action)
+_tool(send_webex_message)
+_tool(send_webex_message_with_mentions)
+_tool(list_webex_messages)
+_tool(delete_webex_message)
+_tool(update_webex_message)
+_tool(get_webex_attachment_action)
 
 # Space message aliases
-mcp.tool()(send_webex_space_message)
-mcp.tool()(list_webex_space_messages)
+_tool(send_webex_space_message)
+_tool(list_webex_space_messages)
 
 # Adaptive card tools
-mcp.tool()(send_webex_adaptive_card)
-mcp.tool()(send_webex_space_adaptive_card)
-mcp.tool()(build_webex_adaptive_card)
+_tool(send_webex_adaptive_card)
+_tool(send_webex_space_adaptive_card)
+_tool(build_webex_adaptive_card)
 
 # Membership management tools
-mcp.tool()(list_webex_memberships)
-mcp.tool()(add_webex_membership)
-mcp.tool()(update_webex_membership)
-mcp.tool()(delete_webex_membership)
+_tool(list_webex_memberships)
+_tool(add_webex_membership)
+_tool(update_webex_membership)
+_tool(delete_webex_membership)
 
 # Space membership aliases
-mcp.tool()(list_webex_space_memberships)
-mcp.tool()(add_webex_space_membership)
+_tool(list_webex_space_memberships)
+_tool(add_webex_space_membership)
 
 # People management tools
-mcp.tool()(get_webex_me)
-mcp.tool()(list_webex_people)
+_tool(get_webex_me)
+_tool(list_webex_people)
 
 # Team management tools
-mcp.tool()(list_webex_teams)
-mcp.tool()(get_webex_team)
-mcp.tool()(update_webex_team)
-mcp.tool()(delete_webex_team)
+_tool(list_webex_teams)
+_tool(get_webex_team)
+_tool(update_webex_team)
+_tool(delete_webex_team)
 
 # Team membership tools
-mcp.tool()(list_webex_team_memberships)
-mcp.tool()(add_webex_team_membership)
-mcp.tool()(delete_webex_team_membership)
+_tool(list_webex_team_memberships)
+_tool(add_webex_team_membership)
+_tool(delete_webex_team_membership)
 
 # Diagnostic tools
-mcp.tool()(webex_health_check)
+_tool(webex_health_check)
 
 # Webhook management tools
-mcp.tool()(list_webex_webhooks)
-mcp.tool()(create_webex_webhook)
-mcp.tool()(get_webex_webhook)
-mcp.tool()(update_webex_webhook)
-mcp.tool()(delete_webex_webhook)
+_tool(list_webex_webhooks)
+_tool(create_webex_webhook)
+_tool(get_webex_webhook)
+_tool(update_webex_webhook)
+_tool(delete_webex_webhook)
 
 
 # ========== RESOURCES ==========

src/webex_bot_mcp/tools/common.py

@@ -1,10 +1,14 @@
 """
 Common utilities and shared components for Webex Bot MCP tools.
 """
+import functools
+import json as _json
+import logging
 import os
+import time
 from datetime import datetime, timezone
 from functools import lru_cache
-from typing import Dict, Any
+from typing import Any, Callable, Dict
 from importlib.metadata import version, PackageNotFoundError
 from webexpythonsdk import WebexAPI
 
@@ -15,6 +19,114 @@
     MCP_SERVER_VERSION = "unknown"
 MCP_SPEC_VERSION = "2024-11-05"
 
+# ---------------------------------------------------------------------------
+# Structured logging
+# ---------------------------------------------------------------------------
+
+logger = logging.getLogger("webex_bot_mcp")
+
+# kwargs that carry entity IDs worth surfacing in every log line
+_TOOL_ID_PARAMS = frozenset({
+    "room_id", "space_id", "team_id", "person_id",
+    "person_email", "membership_id", "message_id", "webhook_id",
+})
+
+# LogRecord fields that belong to the logging framework, not our payload
+_LOG_RECORD_BUILTINS = frozenset(logging.LogRecord("", 0, "", 0, "", (), None).__dict__)
+
+
+class _JsonFormatter(logging.Formatter):
+    """Emit each log record as a single-line JSON object."""
+
+    def format(self, record: logging.LogRecord) -> str:
+        data: Dict[str, Any] = {
+            "timestamp": self.formatTime(record, datefmt="%Y-%m-%dT%H:%M:%S"),
+            "level": record.levelname,
+            "message": record.getMessage(),
+        }
+        for key, value in record.__dict__.items():
+            if key not in _LOG_RECORD_BUILTINS and key not in ("message", "asctime"):
+                data[key] = value
+        if record.exc_info:
+            data["exc_info"] = self.formatException(record.exc_info)
+        return _json.dumps(data)
+
+
+def setup_logging(log_level: str = "INFO", log_format: str = "text", debug: bool = False) -> None:
+    """Configure the webex_bot_mcp logger.
+
+    When debug is True (WEBEX_DEBUG=true) the level is forced to DEBUG so that
+    tool request/response traces are emitted.  Otherwise log_level is used.
+    Calling this a second time is a no-op (handlers already attached).
+    """
+    log = logging.getLogger("webex_bot_mcp")
+
+    if log.handlers:
+        return  # already configured
+
+    effective_level = logging.DEBUG if debug else getattr(logging, log_level.upper(), logging.INFO)
+    log.setLevel(effective_level)
+    log.propagate = False
+
+    handler = logging.StreamHandler()
+    if log_format == "json":
+        handler.setFormatter(_JsonFormatter())
+    else:
+        handler.setFormatter(logging.Formatter(
+            "%(asctime)s %(levelname)-8s %(name)s %(message)s",
+            datefmt="%Y-%m-%dT%H:%M:%S",
+        ))
+    log.addHandler(handler)
+
+
+def _kv(event: str, fields: Dict[str, Any]) -> str:
+    """Render event + fields as 'event key=value …' for human-readable logs."""
+    parts = [event]
+    for k, v in fields.items():
+        parts.append(f"{k}={v!r}" if isinstance(v, str) else f"{k}={v}")
+    return " ".join(parts)
+
+
+def log_tool_call(func: Callable) -> Callable:
+    """Decorator that emits structured request/response log lines for a tool.
+
+    Fields logged on every call: tool, any entity ID kwargs present (room_id,
+    space_id, …), latency_ms, status, and error_code on failure.
+
+    Request/success lines are emitted at DEBUG (visible only when
+    WEBEX_DEBUG=true).  Error lines are emitted at WARNING so they surface in
+    production logs regardless of debug mode.
+    """
+    @functools.wraps(func)
+    def wrapper(*args: Any, **kwargs: Any) -> Any:
+        tool_name = func.__name__
+        start = time.monotonic()
+
+        ctx: Dict[str, Any] = {"tool": tool_name}
+        for param in _TOOL_ID_PARAMS:
+            val = kwargs.get(param)
+            if val:
+                ctx[param] = val
+
+        logger.debug(_kv("tool_request", ctx), extra=ctx)
+
+        result = func(*args, **kwargs)
+
+        ctx["latency_ms"] = round((time.monotonic() - start) * 1000, 2)
+
+        if isinstance(result, dict) and not result.get("success"):
+            ctx["status"] = "error"
+            ctx["error_code"] = result.get("error_code", "unknown")
+            ctx["error_message"] = result.get("message", "")
+            logger.warning(_kv("tool_response", ctx), extra=ctx)
+        else:
+            ctx["status"] = "success"
+            logger.debug(_kv("tool_response", ctx), extra=ctx)
+
+        return result
+
+    return wrapper
+
 # Error codes for structured error handling
 class WebexErrorCodes:
     """Standard error codes for Webex MCP operations."""