Skip to content

Commit 3cf094c

Browse files
claudeclaude
committed
feat(logging): add structured request/response logging gated on WEBEX_DEBUG
Adds a log_tool_call() decorator and setup_logging() to tools/common.py. Every tool registration in main.py is now wrapped with the decorator so that each invocation emits: • DEBUG tool_request – tool name + entity ID kwargs (room_id, space_id, …) • DEBUG tool_response – same fields + latency_ms + status=success • WARNING tool_response – same fields + error_code + error_message on failure When WEBEX_DEBUG=true the logger is forced to DEBUG so request/response traces appear. Without it the logger honours LOG_LEVEL (default INFO), suppressing the DEBUG lines while leaving WARNING errors visible. LOG_FORMAT=json switches the handler to a single-line JSON formatter; LOG_FORMAT=text (default) produces human-readable key=value output. setup_logging() is idempotent (second call is a no-op), and functools.wraps preserves the original function's __name__/__doc__/__annotations__ so FastMCP tool registration is unaffected. Adds 18 unit tests covering setup_logging, _JsonFormatter, _kv, and log_tool_call across success, error, and metadata-capture cases.
1 parent 2412623 commit 3cf094c

3 files changed

Lines changed: 447 additions & 46 deletions

File tree

‎src/webex_bot_mcp/main.py‎

Lines changed: 54 additions & 45 deletions
Original file line numberDiff line numberDiff line change
@@ -61,11 +61,16 @@
6161
update_webex_webhook, delete_webex_webhook,
6262
)
6363

64-
# Import version and error handling from common
65-
from webex_bot_mcp.tools.common import MCP_SERVER_VERSION, MCP_SPEC_VERSION
64+
# Import version, error handling, and logging setup from common
65+
from webex_bot_mcp.tools.common import MCP_SERVER_VERSION, MCP_SPEC_VERSION, setup_logging, log_tool_call
66+
from webex_bot_mcp.config import get_config
6667

6768
webex_access_token = os.getenv("WEBEX_ACCESS_TOKEN")
6869

70+
# Configure logging from environment before any tools run
71+
_cfg = get_config()
72+
setup_logging(log_level=_cfg.log_level, log_format=_cfg.log_format, debug=_cfg.debug)
73+
6974

7075
class WebexAuthMiddleware(BaseHTTPMiddleware):
7176
"""Enforce Bearer token auth on all MCP requests; expose /health unauthenticated."""
@@ -86,72 +91,76 @@ async def dispatch(self, request, call_next):
8691
# Initialize FastMCP with a name for the bot
8792
mcp = FastMCP("Webex Bot MCP")
8893

89-
# Register all tools with FastMCP
94+
# Register all tools with FastMCP (wrapped with request/response logging)
95+
def _tool(func):
96+
mcp.tool()(log_tool_call(func))
97+
98+
9099
# Room management tools
91-
mcp.tool()(list_webex_rooms)
92-
mcp.tool()(create_webex_room)
93-
mcp.tool()(update_webex_room)
94-
mcp.tool()(get_webex_room)
95-
mcp.tool()(delete_webex_room)
100+
_tool(list_webex_rooms)
101+
_tool(create_webex_room)
102+
_tool(update_webex_room)
103+
_tool(get_webex_room)
104+
_tool(delete_webex_room)
96105

97106
# Space aliases (same functionality as rooms but with "space" terminology)
98-
mcp.tool()(list_webex_spaces)
99-
mcp.tool()(create_webex_space)
100-
mcp.tool()(update_webex_space)
101-
mcp.tool()(get_webex_space)
102-
mcp.tool()(delete_webex_space)
107+
_tool(list_webex_spaces)
108+
_tool(create_webex_space)
109+
_tool(update_webex_space)
110+
_tool(get_webex_space)
111+
_tool(delete_webex_space)
103112

104113
# Message management tools
105-
mcp.tool()(send_webex_message)
106-
mcp.tool()(send_webex_message_with_mentions)
107-
mcp.tool()(list_webex_messages)
108-
mcp.tool()(delete_webex_message)
109-
mcp.tool()(update_webex_message)
110-
mcp.tool()(get_webex_attachment_action)
114+
_tool(send_webex_message)
115+
_tool(send_webex_message_with_mentions)
116+
_tool(list_webex_messages)
117+
_tool(delete_webex_message)
118+
_tool(update_webex_message)
119+
_tool(get_webex_attachment_action)
111120

112121
# Space message aliases
113-
mcp.tool()(send_webex_space_message)
114-
mcp.tool()(list_webex_space_messages)
122+
_tool(send_webex_space_message)
123+
_tool(list_webex_space_messages)
115124

116125
# Adaptive card tools
117-
mcp.tool()(send_webex_adaptive_card)
118-
mcp.tool()(send_webex_space_adaptive_card)
119-
mcp.tool()(build_webex_adaptive_card)
126+
_tool(send_webex_adaptive_card)
127+
_tool(send_webex_space_adaptive_card)
128+
_tool(build_webex_adaptive_card)
120129

121130
# Membership management tools
122-
mcp.tool()(list_webex_memberships)
123-
mcp.tool()(add_webex_membership)
124-
mcp.tool()(update_webex_membership)
125-
mcp.tool()(delete_webex_membership)
131+
_tool(list_webex_memberships)
132+
_tool(add_webex_membership)
133+
_tool(update_webex_membership)
134+
_tool(delete_webex_membership)
126135

127136
# Space membership aliases
128-
mcp.tool()(list_webex_space_memberships)
129-
mcp.tool()(add_webex_space_membership)
137+
_tool(list_webex_space_memberships)
138+
_tool(add_webex_space_membership)
130139

131140
# People management tools
132-
mcp.tool()(get_webex_me)
133-
mcp.tool()(list_webex_people)
141+
_tool(get_webex_me)
142+
_tool(list_webex_people)
134143

135144
# Team management tools
136-
mcp.tool()(list_webex_teams)
137-
mcp.tool()(get_webex_team)
138-
mcp.tool()(update_webex_team)
139-
mcp.tool()(delete_webex_team)
145+
_tool(list_webex_teams)
146+
_tool(get_webex_team)
147+
_tool(update_webex_team)
148+
_tool(delete_webex_team)
140149

141150
# Team membership tools
142-
mcp.tool()(list_webex_team_memberships)
143-
mcp.tool()(add_webex_team_membership)
144-
mcp.tool()(delete_webex_team_membership)
151+
_tool(list_webex_team_memberships)
152+
_tool(add_webex_team_membership)
153+
_tool(delete_webex_team_membership)
145154

146155
# Diagnostic tools
147-
mcp.tool()(webex_health_check)
156+
_tool(webex_health_check)
148157

149158
# Webhook management tools
150-
mcp.tool()(list_webex_webhooks)
151-
mcp.tool()(create_webex_webhook)
152-
mcp.tool()(get_webex_webhook)
153-
mcp.tool()(update_webex_webhook)
154-
mcp.tool()(delete_webex_webhook)
159+
_tool(list_webex_webhooks)
160+
_tool(create_webex_webhook)
161+
_tool(get_webex_webhook)
162+
_tool(update_webex_webhook)
163+
_tool(delete_webex_webhook)
155164

156165

157166
# ========== RESOURCES ==========

‎src/webex_bot_mcp/tools/common.py‎

Lines changed: 113 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,10 +1,14 @@
11
"""
22
Common utilities and shared components for Webex Bot MCP tools.
33
"""
4+
import functools
5+
import json as _json
6+
import logging
47
import os
8+
import time
59
from datetime import datetime, timezone
610
from functools import lru_cache
7-
from typing import Dict, Any
11+
from typing import Any, Callable, Dict
812
from importlib.metadata import version, PackageNotFoundError
913
from webexpythonsdk import WebexAPI
1014

@@ -15,6 +19,114 @@
1519
MCP_SERVER_VERSION = "unknown"
1620
MCP_SPEC_VERSION = "2024-11-05"
1721

22+
# ---------------------------------------------------------------------------
23+
# Structured logging
24+
# ---------------------------------------------------------------------------
25+
26+
logger = logging.getLogger("webex_bot_mcp")
27+
28+
# kwargs that carry entity IDs worth surfacing in every log line
29+
_TOOL_ID_PARAMS = frozenset({
30+
"room_id", "space_id", "team_id", "person_id",
31+
"person_email", "membership_id", "message_id", "webhook_id",
32+
})
33+
34+
# LogRecord fields that belong to the logging framework, not our payload
35+
_LOG_RECORD_BUILTINS = frozenset(logging.LogRecord("", 0, "", 0, "", (), None).__dict__)
36+
37+
38+
class _JsonFormatter(logging.Formatter):
39+
"""Emit each log record as a single-line JSON object."""
40+
41+
def format(self, record: logging.LogRecord) -> str:
42+
data: Dict[str, Any] = {
43+
"timestamp": self.formatTime(record, datefmt="%Y-%m-%dT%H:%M:%S"),
44+
"level": record.levelname,
45+
"message": record.getMessage(),
46+
}
47+
for key, value in record.__dict__.items():
48+
if key not in _LOG_RECORD_BUILTINS and key not in ("message", "asctime"):
49+
data[key] = value
50+
if record.exc_info:
51+
data["exc_info"] = self.formatException(record.exc_info)
52+
return _json.dumps(data)
53+
54+
55+
def setup_logging(log_level: str = "INFO", log_format: str = "text", debug: bool = False) -> None:
56+
"""Configure the webex_bot_mcp logger.
57+
58+
When debug is True (WEBEX_DEBUG=true) the level is forced to DEBUG so that
59+
tool request/response traces are emitted. Otherwise log_level is used.
60+
Calling this a second time is a no-op (handlers already attached).
61+
"""
62+
log = logging.getLogger("webex_bot_mcp")
63+
64+
if log.handlers:
65+
return # already configured
66+
67+
effective_level = logging.DEBUG if debug else getattr(logging, log_level.upper(), logging.INFO)
68+
log.setLevel(effective_level)
69+
log.propagate = False
70+
71+
handler = logging.StreamHandler()
72+
if log_format == "json":
73+
handler.setFormatter(_JsonFormatter())
74+
else:
75+
handler.setFormatter(logging.Formatter(
76+
"%(asctime)s %(levelname)-8s %(name)s %(message)s",
77+
datefmt="%Y-%m-%dT%H:%M:%S",
78+
))
79+
log.addHandler(handler)
80+
81+
82+
def _kv(event: str, fields: Dict[str, Any]) -> str:
83+
"""Render event + fields as 'event key=value …' for human-readable logs."""
84+
parts = [event]
85+
for k, v in fields.items():
86+
parts.append(f"{k}={v!r}" if isinstance(v, str) else f"{k}={v}")
87+
return " ".join(parts)
88+
89+
90+
def log_tool_call(func: Callable) -> Callable:
91+
"""Decorator that emits structured request/response log lines for a tool.
92+
93+
Fields logged on every call: tool, any entity ID kwargs present (room_id,
94+
space_id, …), latency_ms, status, and error_code on failure.
95+
96+
Request/success lines are emitted at DEBUG (visible only when
97+
WEBEX_DEBUG=true). Error lines are emitted at WARNING so they surface in
98+
production logs regardless of debug mode.
99+
"""
100+
@functools.wraps(func)
101+
def wrapper(*args: Any, **kwargs: Any) -> Any:
102+
tool_name = func.__name__
103+
start = time.monotonic()
104+
105+
ctx: Dict[str, Any] = {"tool": tool_name}
106+
for param in _TOOL_ID_PARAMS:
107+
val = kwargs.get(param)
108+
if val:
109+
ctx[param] = val
110+
111+
logger.debug(_kv("tool_request", ctx), extra=ctx)
112+
113+
result = func(*args, **kwargs)
114+
115+
ctx["latency_ms"] = round((time.monotonic() - start) * 1000, 2)
116+
117+
if isinstance(result, dict) and not result.get("success"):
118+
ctx["status"] = "error"
119+
ctx["error_code"] = result.get("error_code", "unknown")
120+
ctx["error_message"] = result.get("message", "")
121+
logger.warning(_kv("tool_response", ctx), extra=ctx)
122+
else:
123+
ctx["status"] = "success"
124+
logger.debug(_kv("tool_response", ctx), extra=ctx)
125+
126+
return result
127+
128+
return wrapper
129+
18130
# Error codes for structured error handling
19131
class WebexErrorCodes:
20132
"""Standard error codes for Webex MCP operations."""

0 commit comments

Comments
 (0)