ceos/fastmcp
1
0
Fork 0
mirror of https://github.com/PrefectHQ/fastmcp.git synced 2026-08-20 20:44:17 +02:00
Code Issues Projects Releases Packages Wiki Activity

Also push client messages (info/warn/debug) to server debug log (#2063)

Browse source 
Co-authored-by: William Easton <strawgate@users.noreply.github.com>
Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>
Co-authored-by: claude[bot] <41898282+claude[bot]@users.noreply.github.com>
Co-authored-by: Jeremiah Lowin <153965+jlowin@users.noreply.github.com>
This commit is contained in:
William Easton 2025-10-14 13:38:26 -05:00 • committed by GitHub
commit 1ec2bd7d92
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
6 changed files with 223 additions and 43 deletions
Download patch file Download diff file Expand all files Collapse all files

29
docs/servers/logging.mdx
View file

@ -1,5 +1,5 @@
---
title: Server Logging
title: Client Logging
sidebarTitle: Logging
description: Send log messages back to MCP clients through the context.
icon: receipt
@ -71,12 +71,25 @@ async def process_transaction(transaction_id: str, amount: float, ctx: Context):
# ... processing logic ...
```
## Server Logs
Client Logging in the form of `ctx.log()` and its convenience methods (`debug`, `info`, `warning`, `error`) are meant for sending messages to the MCP clients. Messages sent to clients are also logged to the server's log at `DEBUG` level. Enable debug logging on the server or enable debug logging on the `fastmcp.server.context.to_client` logger to see these messages in the server's log.
```python
import logging
from fastmcp.utilities.logging import get_logger
to_client_logger = get_logger(name="fastmcp.server.context.to_client")
to_client_logger.setLevel(level=logging.DEBUG)
```
## Logging Methods
<Card icon="code" title="Context Logging Methods">
<ResponseField name="ctx.debug" type="async method">
Send debug-level messages for detailed execution information
<Expandable title="parameters">
<ResponseField name="message" type="str">
The debug message to send to the client
@ -89,7 +102,7 @@ async def process_transaction(transaction_id: str, amount: float, ctx: Context):
<ResponseField name="ctx.info" type="async method">
Send informational messages about normal execution
<Expandable title="parameters">
<ResponseField name="message" type="str">
The information message to send to the client
@ -102,7 +115,7 @@ async def process_transaction(transaction_id: str, amount: float, ctx: Context):
<ResponseField name="ctx.warning" type="async method">
Send warning messages for potential issues that didn't prevent execution
<Expandable title="parameters">
<ResponseField name="message" type="str">
The warning message to send to the client
@ -115,7 +128,7 @@ async def process_transaction(transaction_id: str, amount: float, ctx: Context):
<ResponseField name="ctx.error" type="async method">
Send error messages for problems that occurred during execution
<Expandable title="parameters">
<ResponseField name="message" type="str">
The error message to send to the client
@ -128,16 +141,16 @@ async def process_transaction(transaction_id: str, amount: float, ctx: Context):
<ResponseField name="ctx.log" type="async method">
Generic logging method with custom level and logger name
<Expandable title="parameters">
<ResponseField name="level" type="Literal['debug', 'info', 'warning', 'error']">
The log level for the message
</ResponseField>
<ResponseField name="message" type="str">
The message to send to the client
</ResponseField>
<ResponseField name="logger_name" type="str | None" default="None">
Optional custom logger name for categorizing messages
</ResponseField>

26
src/fastmcp/client/logging.py
View file

@ -1,4 +1,5 @@
from collections.abc import Awaitable, Callable
from logging import Logger
from typing import TypeAlias
from mcp.client.session import LoggingFnT
@ -6,7 +7,8 @@ from mcp.types import LoggingMessageNotificationParams
from fastmcp.utilities.logging import get_logger
logger = get_logger(__name__)
logger: Logger = get_logger(name=__name__)
from_server_logger: Logger = get_logger(name="fastmcp.client.from_server")
LogMessage: TypeAlias = LoggingMessageNotificationParams
LogHandler: TypeAlias = Callable[[LogMessage], Awaitable[None]]
@ -19,25 +21,27 @@ async def default_log_handler(message: LogMessage) -> None:
# Map MCP log levels to Python logging levels
level_map = {
"debug": logger.debug,
"info": logger.info,
"notice": logger.info, # Python doesn't have 'notice', map to info
"warning": logger.warning,
"error": logger.error,
"critical": logger.critical,
"alert": logger.critical, # Map alert to critical
"emergency": logger.critical, # Map emergency to critical
"debug": from_server_logger.debug,
"info": from_server_logger.info,
"notice": from_server_logger.info, # Python doesn't have 'notice', map to info
"warning": from_server_logger.warning,
"error": from_server_logger.error,
"critical": from_server_logger.critical,
"alert": from_server_logger.critical, # Map alert to critical
"emergency": from_server_logger.critical, # Map emergency to critical
}
# Get the appropriate logging function based on the message level
log_fn = level_map.get(message.level.lower(), logger.info)
# Include logger name if available
msg_prefix: str = f"Received {message.level.upper()} from server"
if message.logger:
msg = f"[{message.logger}] {msg}"
msg_prefix += f" ({message.logger})"
# Log with appropriate level and extra data
log_fn(f"Server log: {msg}", extra=extra)
log_fn(msg=f"{msg_prefix}: {msg}", extra=extra)
def create_log_callback(handler: LogHandler | None = None) -> LoggingFnT:

104
src/fastmcp/server/context.py
View file

@ -3,13 +3,16 @@ from __future__ import annotations
import asyncio
import copy
import inspect
import logging
import warnings
import weakref
from asyncio.locks import Lock
from collections.abc import Generator, Mapping, Sequence
from contextlib import contextmanager
from contextvars import ContextVar, Token
from dataclasses import dataclass
from enum import Enum
from logging import Logger
from typing import Any, Literal, cast, get_origin, overload
from mcp import LoggingLevel, ServerSession
@ -44,14 +47,21 @@ from fastmcp.server.elicitation import (
get_elicitation_schema,
)
from fastmcp.server.server import FastMCP
from fastmcp.utilities.logging import get_logger
from fastmcp.utilities.logging import _clamp_logger, get_logger
from fastmcp.utilities.types import get_cached_typeadapter
logger = get_logger(__name__)
logger: Logger = get_logger(name=__name__)
to_client_logger: Logger = logger.getChild(suffix="to_client")
# Convert all levels of server -> client messages to debug level
# This clamp can be undone at runtime by calling `_unclamp_logger` or calling
# `_clamp_logger` with a different max level.
_clamp_logger(logger=to_client_logger, max_level="DEBUG")
T = TypeVar("T", default=Any)
_current_context: ContextVar[Context | None] = ContextVar("context", default=None) # type: ignore[assignment]
_flush_lock = asyncio.Lock()
_flush_lock: Lock = asyncio.Lock()
@dataclass
@ -66,6 +76,18 @@ class LogData:
extra: Mapping[str, Any] | None = None
_mcp_level_to_python_level = {
"debug": logging.DEBUG,
"info": logging.INFO,
"notice": logging.INFO,
"warning": logging.WARNING,
"error": logging.ERROR,
"critical": logging.CRITICAL,
"alert": logging.CRITICAL,
"emergency": logging.CRITICAL,
}
@contextmanager
def set_context(context: Context) -> Generator[Context, None, None]:
token = _current_context.set(context)
@ -216,6 +238,8 @@ class Context:
) -> None:
"""Send a log message to the client.
Messages sent to Clients are also logged to the `fastmcp.server.context.to_client` logger with a level of `DEBUG`.
Args:
message: Log message
level: Optional log level. One of "debug", "info", "notice", "warning", "error", "critical",
@ -223,13 +247,13 @@ class Context:
logger_name: Optional logger name
extra: Optional mapping for additional arguments
"""
if level is None:
level = "info"
data = LogData(msg=message, extra=extra)
await self.session.send_log_message(
level=level,
await _log_to_server_and_client(
data=data,
logger=logger_name,
session=self.session,
level=level or "info",
logger_name=logger_name,
related_request_id=self.request_id,
)
@ -303,9 +327,14 @@ class Context:
logger_name: str | None = None,
extra: Mapping[str, Any] | None = None,
) -> None:
"""Send a debug log message."""
"""Send a `DEBUG`-level message to the connected MCP Client.
Messages sent to Clients are also logged to the `fastmcp.server.context.to_client` logger with a level of `DEBUG`."""
await self.log(
level="debug", message=message, logger_name=logger_name, extra=extra
level="debug",
message=message,
logger_name=logger_name,
extra=extra,
)
async def info(
@ -314,9 +343,14 @@ class Context:
logger_name: str | None = None,
extra: Mapping[str, Any] | None = None,
) -> None:
"""Send an info log message."""
"""Send a `INFO`-level message to the connected MCP Client.
Messages sent to Clients are also logged to the `fastmcp.server.context.to_client` logger with a level of `DEBUG`."""
await self.log(
level="info", message=message, logger_name=logger_name, extra=extra
level="info",
message=message,
logger_name=logger_name,
extra=extra,
)
async def warning(
@ -325,9 +359,14 @@ class Context:
logger_name: str | None = None,
extra: Mapping[str, Any] | None = None,
) -> None:
"""Send a warning log message."""
"""Send a `WARNING`-level message to the connected MCP Client.
Messages sent to Clients are also logged to the `fastmcp.server.context.to_client` logger with a level of `DEBUG`."""
await self.log(
level="warning", message=message, logger_name=logger_name, extra=extra
level="warning",
message=message,
logger_name=logger_name,
extra=extra,
)
async def error(
@ -336,9 +375,14 @@ class Context:
logger_name: str | None = None,
extra: Mapping[str, Any] | None = None,
) -> None:
"""Send an error log message."""
"""Send a `ERROR`-level message to the connected MCP Client.
Messages sent to Clients are also logged to the `fastmcp.server.context.to_client` logger with a level of `DEBUG`."""
await self.log(
level="error", message=message, logger_name=logger_name, extra=extra
level="error",
message=message,
logger_name=logger_name,
extra=extra,
)
async def list_roots(self) -> list[Root]:
@ -675,3 +719,31 @@ def _parse_model_preferences(
raise ValueError(
"model_preferences must be one of: ModelPreferences, str, list[str], or None."
)
async def _log_to_server_and_client(
data: LogData,
session: ServerSession,
level: LoggingLevel,
logger_name: str | None = None,
related_request_id: str | None = None,
) -> None:
"""Log a message to the server and client."""
msg_prefix = f"Sending {level.upper()} to client"
if logger_name:
msg_prefix += f" ({logger_name})"
to_client_logger.log(
level=_mcp_level_to_python_level[level],
msg=f"{msg_prefix}: {data.msg}",
extra=data.extra,
)
await session.send_log_message(
level=level,
data=data,
logger=logger_name,
related_request_id=related_request_id,
)

89
src/fastmcp/utilities/logging.py
View file

@ -6,6 +6,7 @@ from typing import Any, Literal, cast
from rich.console import Console
from rich.logging import RichHandler
from typing_extensions import override
import fastmcp
@ -19,7 +20,10 @@ def get_logger(name: str) -> logging.Logger:
Returns:
a configured logger instance
"""
return logging.getLogger(f"fastmcp.{name}")
if name.startswith("fastmcp."):
return logging.getLogger(name=name)
return logging.getLogger(name=f"fastmcp.{name}")
def configure_logging(
@ -141,3 +145,86 @@ def temporary_log_level(
)
else:
yield
class _ClampedLogFilter(logging.Filter):
min_level: tuple[int, str] | None
max_level: tuple[int, str] | None
def __init__(
self,
min_level: Literal["DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL"]
| None = None,
max_level: Literal["DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL"]
| None = None,
):
self.min_level = None
self.max_level = None
if min_level_no := self._level_to_no(level=min_level):
self.min_level = (min_level_no, str(min_level))
if max_level_no := self._level_to_no(level=max_level):
self.max_level = (max_level_no, str(max_level))
super().__init__()
def _level_to_no(
self, level: Literal["DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL"] | None
) -> int | None:
if level == "DEBUG":
return logging.DEBUG
elif level == "INFO":
return logging.INFO
elif level == "WARNING":
return logging.WARNING
elif level == "ERROR":
return logging.ERROR
elif level == "CRITICAL":
return logging.CRITICAL
else:
return None
@override
def filter(self, record: logging.LogRecord) -> bool:
if self.max_level:
max_level_no, max_level_name = self.max_level
if record.levelno > max_level_no:
record.levelno = max_level_no
record.levelname = max_level_name
return True
if self.min_level:
min_level_no, min_level_name = self.min_level
if record.levelno < min_level_no:
record.levelno = min_level_no
record.levelname = min_level_name
return True
return True
def _clamp_logger(
logger: logging.Logger,
min_level: Literal["DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL"] | None = None,
max_level: Literal["DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL"] | None = None,
) -> None:
"""Clamp the logger to a minimum and maximum level.
If min_level is provided, messages logged at a lower level than `min_level` will have their level increased to `min_level`.
If max_level is provided, messages logged at a higher level than `max_level` will have their level decreased to `max_level`.
Args:
min_level: The lower bound of the clamp
max_level: The upper bound of the clamp
"""
_unclamp_logger(logger=logger)
logger.addFilter(filter=_ClampedLogFilter(min_level=min_level, max_level=max_level))
def _unclamp_logger(logger: logging.Logger) -> None:
"""Remove all clamped log filters from the logger."""
for filter in logger.filters[:]:
if isinstance(filter, _ClampedLogFilter):
logger.removeFilter(filter)

13
tests/client/test_logs.py
View file

@ -101,7 +101,7 @@ class TestDefaultLogHandler:
from fastmcp.client.logging import default_log_handler
with patch("fastmcp.client.logging.logger") as mock_logger:
with patch("fastmcp.client.logging.from_server_logger") as mock_logger:
# Set up mock methods
mock_logger.debug = MagicMock()
mock_logger.info = MagicMock()
@ -141,7 +141,8 @@ class TestDefaultLogHandler:
# Verify correct method was called
expected_method.assert_called_once_with(
f"Server log: [test.logger] {msg}", extra={"test_key": "test_value"}
msg=f"Received {level.upper()} from server (test.logger): {msg}",
extra={"test_key": "test_value"},
)
async def test_default_handler_without_logger_name(self):
@ -152,7 +153,7 @@ class TestDefaultLogHandler:
from fastmcp.client.logging import default_log_handler
with patch("fastmcp.client.logging.logger") as mock_logger:
with patch("fastmcp.client.logging.from_server_logger") as mock_logger:
mock_logger.info = MagicMock()
log_msg = LoggingMessageNotificationParams(
@ -164,7 +165,7 @@ class TestDefaultLogHandler:
await default_log_handler(log_msg)
mock_logger.info.assert_called_once_with(
"Server log: Message without logger", extra={}
msg="Received INFO from server: Message without logger", extra={}
)
async def test_default_handler_with_missing_msg(self):
@ -175,7 +176,7 @@ class TestDefaultLogHandler:
from fastmcp.client.logging import default_log_handler
with patch("fastmcp.client.logging.logger") as mock_logger:
with patch("fastmcp.client.logging.from_server_logger") as mock_logger:
mock_logger.info = MagicMock()
log_msg = LoggingMessageNotificationParams(
@ -189,5 +190,5 @@ class TestDefaultLogHandler:
# Should use str(message) as fallback
mock_logger.info.assert_called_once()
call_args = mock_logger.info.call_args
assert "Server log:" in call_args[0][0]
assert "Received INFO from server" in call_args[1]["msg"]
assert call_args[1]["extra"] == {"key": "value"}

5
tests/server/test_context.py
View file

@ -5,7 +5,10 @@ import pytest
from mcp.types import ModelPreferences
from starlette.requests import Request
from fastmcp.server.context import Context, _parse_model_preferences
from fastmcp.server.context import (
Context,
_parse_model_preferences,
)
from fastmcp.server.server import FastMCP