From 41d6b6fc1505ef51aef2df37237763aba6fa891f Mon Sep 17 00:00:00 2001 From: Vincent Liu <128127889+vl-kp@users.noreply.github.com> Date: Tue, 26 Aug 2025 13:30:21 +0800 Subject: [PATCH 01/10] fix: fix StructuredLoggingMiddleware payload serialization --- src/fastmcp/server/middleware/logging.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/fastmcp/server/middleware/logging.py b/src/fastmcp/server/middleware/logging.py index f770e2faa..0e0390385 100644 --- a/src/fastmcp/server/middleware/logging.py +++ b/src/fastmcp/server/middleware/logging.py @@ -152,7 +152,7 @@ class StructuredLoggingMiddleware(Middleware): if self.methods and context.method not in self.methods: return await call_next(context) - self.logger.log(self.log_level, json.dumps(start_entry)) + self.logger.log(self.log_level, json.dumps(start_entry, default=str)) try: result = await call_next(context) @@ -162,7 +162,7 @@ class StructuredLoggingMiddleware(Middleware): "request_success", result_type=type(result).__name__ if result else None, ) - self.logger.log(self.log_level, json.dumps(success_entry)) + self.logger.log(self.log_level, json.dumps(success_entry, default=str)) return result except Exception as e: @@ -172,5 +172,5 @@ class StructuredLoggingMiddleware(Middleware): error_type=type(e).__name__, error_message=str(e), ) - self.logger.log(logging.ERROR, json.dumps(error_entry)) + self.logger.log(logging.ERROR, json.dumps(error_entry, default=str)) raise From 0e849021561118e7377619c0e70fd95c7fd69447 Mon Sep 17 00:00:00 2001 From: vincent Date: Tue, 26 Aug 2025 13:55:24 +0800 Subject: [PATCH 02/10] chore: add test --- tests/server/middleware/test_logging.py | 51 +++++++++++++++++++++++++ 1 file changed, 51 insertions(+) diff --git a/tests/server/middleware/test_logging.py b/tests/server/middleware/test_logging.py index 9217bb485..4bb0b98ac 100644 --- a/tests/server/middleware/test_logging.py +++ b/tests/server/middleware/test_logging.py @@ -191,6 +191,57 @@ class TestStructuredLoggingMiddleware: assert error_entry["error_type"] == "ValueError" assert error_entry["error_message"] == "test error" + async def test_on_message_with_pydantic_types_in_payload( + self, mock_context, mock_call_next, caplog + ): + """Ensure Pydantic AnyUrl in payload serializes correctly when include_payloads=True.""" + from pydantic import AnyUrl + + mock_context.message.__dict__["url"] = AnyUrl("test://example/1") + + middleware = StructuredLoggingMiddleware(include_payloads=True) + + with caplog.at_level(logging.INFO): + result = await middleware.on_message(mock_context, mock_call_next) + + assert result == "test_result" + + log_lines = [record.message for record in caplog.records] + assert len(log_lines) == 2 + start_entry = json.loads(log_lines[0]) + + assert start_entry["event"] == "request_start" + assert start_entry["payload"]["url"] == "test://example/1" + + async def test_on_message_with_resource_template_in_payload( + self, mock_context, mock_call_next, caplog + ): + """Ensure ResourceTemplate in payload serializes via default=str without errors.""" + from fastmcp.resources import ResourceTemplate + + template = ResourceTemplate( + name="tmpl", + uri_template="tmpl://{id}", + parameters={"id": {"type": "string"}}, + ) + + mock_context.message.__dict__["template"] = template + + middleware = StructuredLoggingMiddleware(include_payloads=True) + + with caplog.at_level(logging.INFO): + result = await middleware.on_message(mock_context, mock_call_next) + + assert result == "test_result" + + log_lines = [record.message for record in caplog.records] + assert len(log_lines) == 2 + start_entry = json.loads(log_lines[0]) + assert start_entry["event"] == "request_start" + assert "template" in start_entry["payload"] + # After json.loads, default=str ensures complex object became a JSON string + assert isinstance(start_entry["payload"]["template"], str) + @pytest.fixture def logging_server(): From e03061d79ac8da1f4eb51eff5e78edc17a5e31f1 Mon Sep 17 00:00:00 2001 From: vincent Date: Tue, 26 Aug 2025 22:01:11 +0800 Subject: [PATCH 03/10] chore: add configurable serializer --- src/fastmcp/server/middleware/logging.py | 38 +++++++++++++-- tests/server/middleware/test_logging.py | 61 ++++++++++++++++++++++-- 2 files changed, 93 insertions(+), 6 deletions(-) diff --git a/src/fastmcp/server/middleware/logging.py b/src/fastmcp/server/middleware/logging.py index 0e0390385..7fcfe37f8 100644 --- a/src/fastmcp/server/middleware/logging.py +++ b/src/fastmcp/server/middleware/logging.py @@ -2,8 +2,11 @@ import json import logging +from collections.abc import Callable from typing import Any +import pydantic_core + from .middleware import CallNext, Middleware, MiddlewareContext @@ -111,6 +114,7 @@ class StructuredLoggingMiddleware(Middleware): log_level: int = logging.INFO, include_payloads: bool = False, methods: list[str] | None = None, + serializer: Callable[[Any], Any] | None = None, ): """Initialize structured logging middleware. @@ -119,11 +123,33 @@ class StructuredLoggingMiddleware(Middleware): log_level: Log level for messages (default: INFO) include_payloads: Whether to include message payloads in logs methods: List of methods to log. If None, logs all methods. + serializer: Optional callable to convert objects to JSON-serializable + values when logging. Defaults to a safe converter that tries + pydantic_core.to_jsonable_python and falls back to str. """ self.logger = logger or logging.getLogger("fastmcp.structured") self.log_level = log_level self.include_payloads = include_payloads self.methods = methods + self.serializer = serializer + + def _json_default(self, obj: Any) -> Any: + """Default converter for json.dumps to handle non-serializable objects. + + Tries a user-provided serializer first, then pydantic conversion, then str. + """ + if self.serializer is not None: + try: + return self.serializer(obj) + except Exception: + pass + try: + return pydantic_core.to_jsonable_python(obj) + except Exception: + try: + return str(obj) + except Exception: + return "" def _create_log_entry( self, context: MiddlewareContext, event: str, **extra_fields @@ -152,7 +178,9 @@ class StructuredLoggingMiddleware(Middleware): if self.methods and context.method not in self.methods: return await call_next(context) - self.logger.log(self.log_level, json.dumps(start_entry, default=str)) + self.logger.log( + self.log_level, json.dumps(start_entry, default=self._json_default) + ) try: result = await call_next(context) @@ -162,7 +190,9 @@ class StructuredLoggingMiddleware(Middleware): "request_success", result_type=type(result).__name__ if result else None, ) - self.logger.log(self.log_level, json.dumps(success_entry, default=str)) + self.logger.log( + self.log_level, json.dumps(success_entry, default=self._json_default) + ) return result except Exception as e: @@ -172,5 +202,7 @@ class StructuredLoggingMiddleware(Middleware): error_type=type(e).__name__, error_message=str(e), ) - self.logger.log(logging.ERROR, json.dumps(error_entry, default=str)) + self.logger.log( + logging.ERROR, json.dumps(error_entry, default=self._json_default) + ) raise diff --git a/tests/server/middleware/test_logging.py b/tests/server/middleware/test_logging.py index 4bb0b98ac..46c84cf00 100644 --- a/tests/server/middleware/test_logging.py +++ b/tests/server/middleware/test_logging.py @@ -216,7 +216,7 @@ class TestStructuredLoggingMiddleware: async def test_on_message_with_resource_template_in_payload( self, mock_context, mock_call_next, caplog ): - """Ensure ResourceTemplate in payload serializes via default=str without errors.""" + """Ensure ResourceTemplate in payload serializes via pydantic conversion without errors.""" from fastmcp.resources import ResourceTemplate template = ResourceTemplate( @@ -239,8 +239,63 @@ class TestStructuredLoggingMiddleware: start_entry = json.loads(log_lines[0]) assert start_entry["event"] == "request_start" assert "template" in start_entry["payload"] - # After json.loads, default=str ensures complex object became a JSON string - assert isinstance(start_entry["payload"]["template"], str) + # With pydantic conversion, complex object becomes a JSONable dict + assert isinstance(start_entry["payload"]["template"], dict) + assert start_entry["payload"]["template"]["uri_template"] == "tmpl://{id}" + + async def test_on_message_with_nonserializable_payload_falls_back_to_str( + self, mock_context, mock_call_next, caplog + ): + """Ensure non-JSONable objects fall back to string serialization in payload.""" + + class NonSerializable: + def __str__(self) -> str: + return "NON_SERIALIZABLE" + + mock_context.message.__dict__["obj"] = NonSerializable() + + middleware = StructuredLoggingMiddleware(include_payloads=True) + + with caplog.at_level(logging.INFO): + result = await middleware.on_message(mock_context, mock_call_next) + + assert result == "test_result" + + log_lines = [record.message for record in caplog.records] + assert len(log_lines) >= 2 + start_entry = json.loads(log_lines[0]) + assert start_entry["event"] == "request_start" + assert start_entry["payload"]["obj"] == "NON_SERIALIZABLE" + + async def test_on_message_with_custom_serializer_applied( + self, mock_context, mock_call_next, caplog + ): + """Ensure a custom serializer is used for non-JSONable payloads.""" + + class CustomType: + pass + + def custom_serializer(o): + if isinstance(o, CustomType): + return "CUSTOM:CustomType" + raise TypeError("unsupported") + + mock_context.message.__dict__["special"] = CustomType() + + middleware = StructuredLoggingMiddleware( + include_payloads=True, serializer=custom_serializer + ) + + with caplog.at_level(logging.INFO): + result = await middleware.on_message(mock_context, mock_call_next) + + assert result == "test_result" + + log_lines = [record.message for record in caplog.records] + assert len(log_lines) >= 2 + start_entry = json.loads(log_lines[0]) + assert start_entry["event"] == "request_start" + assert start_entry["payload"]["special"] == "CUSTOM:CustomType" @pytest.fixture From 0822093f4693408b8d338adb5d310945d669c0ce Mon Sep 17 00:00:00 2001 From: Vincent Liu <128127889+vl-kp@users.noreply.github.com> Date: Tue, 26 Aug 2025 13:30:21 +0800 Subject: [PATCH 04/10] fix: fix StructuredLoggingMiddleware payload serialization --- src/fastmcp/server/middleware/logging.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/fastmcp/server/middleware/logging.py b/src/fastmcp/server/middleware/logging.py index f770e2faa..0e0390385 100644 --- a/src/fastmcp/server/middleware/logging.py +++ b/src/fastmcp/server/middleware/logging.py @@ -152,7 +152,7 @@ class StructuredLoggingMiddleware(Middleware): if self.methods and context.method not in self.methods: return await call_next(context) - self.logger.log(self.log_level, json.dumps(start_entry)) + self.logger.log(self.log_level, json.dumps(start_entry, default=str)) try: result = await call_next(context) @@ -162,7 +162,7 @@ class StructuredLoggingMiddleware(Middleware): "request_success", result_type=type(result).__name__ if result else None, ) - self.logger.log(self.log_level, json.dumps(success_entry)) + self.logger.log(self.log_level, json.dumps(success_entry, default=str)) return result except Exception as e: @@ -172,5 +172,5 @@ class StructuredLoggingMiddleware(Middleware): error_type=type(e).__name__, error_message=str(e), ) - self.logger.log(logging.ERROR, json.dumps(error_entry)) + self.logger.log(logging.ERROR, json.dumps(error_entry, default=str)) raise From 76a0ed89541d0bd6f1f6557a69daac50124ec8f6 Mon Sep 17 00:00:00 2001 From: vincent Date: Tue, 26 Aug 2025 13:55:24 +0800 Subject: [PATCH 05/10] chore: add test --- tests/server/middleware/test_logging.py | 51 +++++++++++++++++++++++++ 1 file changed, 51 insertions(+) diff --git a/tests/server/middleware/test_logging.py b/tests/server/middleware/test_logging.py index 9217bb485..4bb0b98ac 100644 --- a/tests/server/middleware/test_logging.py +++ b/tests/server/middleware/test_logging.py @@ -191,6 +191,57 @@ class TestStructuredLoggingMiddleware: assert error_entry["error_type"] == "ValueError" assert error_entry["error_message"] == "test error" + async def test_on_message_with_pydantic_types_in_payload( + self, mock_context, mock_call_next, caplog + ): + """Ensure Pydantic AnyUrl in payload serializes correctly when include_payloads=True.""" + from pydantic import AnyUrl + + mock_context.message.__dict__["url"] = AnyUrl("test://example/1") + + middleware = StructuredLoggingMiddleware(include_payloads=True) + + with caplog.at_level(logging.INFO): + result = await middleware.on_message(mock_context, mock_call_next) + + assert result == "test_result" + + log_lines = [record.message for record in caplog.records] + assert len(log_lines) == 2 + start_entry = json.loads(log_lines[0]) + + assert start_entry["event"] == "request_start" + assert start_entry["payload"]["url"] == "test://example/1" + + async def test_on_message_with_resource_template_in_payload( + self, mock_context, mock_call_next, caplog + ): + """Ensure ResourceTemplate in payload serializes via default=str without errors.""" + from fastmcp.resources import ResourceTemplate + + template = ResourceTemplate( + name="tmpl", + uri_template="tmpl://{id}", + parameters={"id": {"type": "string"}}, + ) + + mock_context.message.__dict__["template"] = template + + middleware = StructuredLoggingMiddleware(include_payloads=True) + + with caplog.at_level(logging.INFO): + result = await middleware.on_message(mock_context, mock_call_next) + + assert result == "test_result" + + log_lines = [record.message for record in caplog.records] + assert len(log_lines) == 2 + start_entry = json.loads(log_lines[0]) + assert start_entry["event"] == "request_start" + assert "template" in start_entry["payload"] + # After json.loads, default=str ensures complex object became a JSON string + assert isinstance(start_entry["payload"]["template"], str) + @pytest.fixture def logging_server(): From 36975a518282601a964e7ce92bc998df5d4abecc Mon Sep 17 00:00:00 2001 From: vincent Date: Tue, 26 Aug 2025 22:01:11 +0800 Subject: [PATCH 06/10] chore: add configurable serializer --- src/fastmcp/server/middleware/logging.py | 38 +++++++++++++-- tests/server/middleware/test_logging.py | 61 ++++++++++++++++++++++-- 2 files changed, 93 insertions(+), 6 deletions(-) diff --git a/src/fastmcp/server/middleware/logging.py b/src/fastmcp/server/middleware/logging.py index 0e0390385..7fcfe37f8 100644 --- a/src/fastmcp/server/middleware/logging.py +++ b/src/fastmcp/server/middleware/logging.py @@ -2,8 +2,11 @@ import json import logging +from collections.abc import Callable from typing import Any +import pydantic_core + from .middleware import CallNext, Middleware, MiddlewareContext @@ -111,6 +114,7 @@ class StructuredLoggingMiddleware(Middleware): log_level: int = logging.INFO, include_payloads: bool = False, methods: list[str] | None = None, + serializer: Callable[[Any], Any] | None = None, ): """Initialize structured logging middleware. @@ -119,11 +123,33 @@ class StructuredLoggingMiddleware(Middleware): log_level: Log level for messages (default: INFO) include_payloads: Whether to include message payloads in logs methods: List of methods to log. If None, logs all methods. + serializer: Optional callable to convert objects to JSON-serializable + values when logging. Defaults to a safe converter that tries + pydantic_core.to_jsonable_python and falls back to str. """ self.logger = logger or logging.getLogger("fastmcp.structured") self.log_level = log_level self.include_payloads = include_payloads self.methods = methods + self.serializer = serializer + + def _json_default(self, obj: Any) -> Any: + """Default converter for json.dumps to handle non-serializable objects. + + Tries a user-provided serializer first, then pydantic conversion, then str. + """ + if self.serializer is not None: + try: + return self.serializer(obj) + except Exception: + pass + try: + return pydantic_core.to_jsonable_python(obj) + except Exception: + try: + return str(obj) + except Exception: + return "" def _create_log_entry( self, context: MiddlewareContext, event: str, **extra_fields @@ -152,7 +178,9 @@ class StructuredLoggingMiddleware(Middleware): if self.methods and context.method not in self.methods: return await call_next(context) - self.logger.log(self.log_level, json.dumps(start_entry, default=str)) + self.logger.log( + self.log_level, json.dumps(start_entry, default=self._json_default) + ) try: result = await call_next(context) @@ -162,7 +190,9 @@ class StructuredLoggingMiddleware(Middleware): "request_success", result_type=type(result).__name__ if result else None, ) - self.logger.log(self.log_level, json.dumps(success_entry, default=str)) + self.logger.log( + self.log_level, json.dumps(success_entry, default=self._json_default) + ) return result except Exception as e: @@ -172,5 +202,7 @@ class StructuredLoggingMiddleware(Middleware): error_type=type(e).__name__, error_message=str(e), ) - self.logger.log(logging.ERROR, json.dumps(error_entry, default=str)) + self.logger.log( + logging.ERROR, json.dumps(error_entry, default=self._json_default) + ) raise diff --git a/tests/server/middleware/test_logging.py b/tests/server/middleware/test_logging.py index 4bb0b98ac..46c84cf00 100644 --- a/tests/server/middleware/test_logging.py +++ b/tests/server/middleware/test_logging.py @@ -216,7 +216,7 @@ class TestStructuredLoggingMiddleware: async def test_on_message_with_resource_template_in_payload( self, mock_context, mock_call_next, caplog ): - """Ensure ResourceTemplate in payload serializes via default=str without errors.""" + """Ensure ResourceTemplate in payload serializes via pydantic conversion without errors.""" from fastmcp.resources import ResourceTemplate template = ResourceTemplate( @@ -239,8 +239,63 @@ class TestStructuredLoggingMiddleware: start_entry = json.loads(log_lines[0]) assert start_entry["event"] == "request_start" assert "template" in start_entry["payload"] - # After json.loads, default=str ensures complex object became a JSON string - assert isinstance(start_entry["payload"]["template"], str) + # With pydantic conversion, complex object becomes a JSONable dict + assert isinstance(start_entry["payload"]["template"], dict) + assert start_entry["payload"]["template"]["uri_template"] == "tmpl://{id}" + + async def test_on_message_with_nonserializable_payload_falls_back_to_str( + self, mock_context, mock_call_next, caplog + ): + """Ensure non-JSONable objects fall back to string serialization in payload.""" + + class NonSerializable: + def __str__(self) -> str: + return "NON_SERIALIZABLE" + + mock_context.message.__dict__["obj"] = NonSerializable() + + middleware = StructuredLoggingMiddleware(include_payloads=True) + + with caplog.at_level(logging.INFO): + result = await middleware.on_message(mock_context, mock_call_next) + + assert result == "test_result" + + log_lines = [record.message for record in caplog.records] + assert len(log_lines) >= 2 + start_entry = json.loads(log_lines[0]) + assert start_entry["event"] == "request_start" + assert start_entry["payload"]["obj"] == "NON_SERIALIZABLE" + + async def test_on_message_with_custom_serializer_applied( + self, mock_context, mock_call_next, caplog + ): + """Ensure a custom serializer is used for non-JSONable payloads.""" + + class CustomType: + pass + + def custom_serializer(o): + if isinstance(o, CustomType): + return "CUSTOM:CustomType" + raise TypeError("unsupported") + + mock_context.message.__dict__["special"] = CustomType() + + middleware = StructuredLoggingMiddleware( + include_payloads=True, serializer=custom_serializer + ) + + with caplog.at_level(logging.INFO): + result = await middleware.on_message(mock_context, mock_call_next) + + assert result == "test_result" + + log_lines = [record.message for record in caplog.records] + assert len(log_lines) >= 2 + start_entry = json.loads(log_lines[0]) + assert start_entry["event"] == "request_start" + assert start_entry["payload"]["special"] == "CUSTOM:CustomType" @pytest.fixture From 5419176e842ac6fc5a5f8fe8e07d651fc6a1f43d Mon Sep 17 00:00:00 2001 From: vincent Date: Wed, 27 Aug 2025 09:38:50 +0800 Subject: [PATCH 07/10] chore: move serializer into _create_log_entry --- src/fastmcp/server/middleware/logging.py | 58 ++++++++++++++---------- 1 file changed, 35 insertions(+), 23 deletions(-) diff --git a/src/fastmcp/server/middleware/logging.py b/src/fastmcp/server/middleware/logging.py index 7fcfe37f8..bf57233db 100644 --- a/src/fastmcp/server/middleware/logging.py +++ b/src/fastmcp/server/middleware/logging.py @@ -133,23 +133,38 @@ class StructuredLoggingMiddleware(Middleware): self.methods = methods self.serializer = serializer - def _json_default(self, obj: Any) -> Any: - """Default converter for json.dumps to handle non-serializable objects. + def _normalize(self, value: Any) -> Any: + """Normalize a Python object to a JSON-serializable value. - Tries a user-provided serializer first, then pydantic conversion, then str. + Order: custom serializer → primitives → mappings/sequences (recursive) + → pydantic conversion → str fallback. """ if self.serializer is not None: try: - return self.serializer(obj) + value = self.serializer(value) except Exception: pass + + if value is None or isinstance(value, (str, int, float, bool)): # noqa: UP038 + return value + + if isinstance(value, dict): + return {str(k): self._normalize(v) for k, v in value.items()} + + if isinstance(value, (list, tuple, set)): # noqa: UP038 + return [self._normalize(v) for v in list(value)] + try: - return pydantic_core.to_jsonable_python(obj) + converted = pydantic_core.to_jsonable_python(value) + if converted is not value: + return self._normalize(converted) except Exception: - try: - return str(obj) - except Exception: - return "" + pass + + try: + return str(value) + except Exception: + return "" def _create_log_entry( self, context: MiddlewareContext, event: str, **extra_fields @@ -164,11 +179,14 @@ class StructuredLoggingMiddleware(Middleware): **extra_fields, } - if self.include_payloads and hasattr(context.message, "__dict__"): - try: - entry["payload"] = context.message.__dict__ - except (TypeError, ValueError): - entry["payload"] = "" + if self.include_payloads: + payload_obj = ( + context.message.__dict__ + if hasattr(context.message, "__dict__") + else context.message + ) + + entry["payload"] = self._normalize(payload_obj) return entry @@ -178,9 +196,7 @@ class StructuredLoggingMiddleware(Middleware): if self.methods and context.method not in self.methods: return await call_next(context) - self.logger.log( - self.log_level, json.dumps(start_entry, default=self._json_default) - ) + self.logger.log(self.log_level, json.dumps(start_entry)) try: result = await call_next(context) @@ -190,9 +206,7 @@ class StructuredLoggingMiddleware(Middleware): "request_success", result_type=type(result).__name__ if result else None, ) - self.logger.log( - self.log_level, json.dumps(success_entry, default=self._json_default) - ) + self.logger.log(self.log_level, json.dumps(success_entry)) return result except Exception as e: @@ -202,7 +216,5 @@ class StructuredLoggingMiddleware(Middleware): error_type=type(e).__name__, error_message=str(e), ) - self.logger.log( - logging.ERROR, json.dumps(error_entry, default=self._json_default) - ) + self.logger.log(logging.ERROR, json.dumps(error_entry)) raise From f763a4a31be1b6d7fc34143e1627170653ce4828 Mon Sep 17 00:00:00 2001 From: vincent Date: Wed, 27 Aug 2025 09:58:27 +0800 Subject: [PATCH 08/10] chore: use default_serializer --- src/fastmcp/server/middleware/logging.py | 51 +++++------------------- tests/server/middleware/test_logging.py | 33 ++++++++------- 2 files changed, 27 insertions(+), 57 deletions(-) diff --git a/src/fastmcp/server/middleware/logging.py b/src/fastmcp/server/middleware/logging.py index bf57233db..0f24c7fd0 100644 --- a/src/fastmcp/server/middleware/logging.py +++ b/src/fastmcp/server/middleware/logging.py @@ -5,7 +5,7 @@ import logging from collections.abc import Callable from typing import Any -import pydantic_core +from fastmcp.tools.tool import default_serializer from .middleware import CallNext, Middleware, MiddlewareContext @@ -114,7 +114,7 @@ class StructuredLoggingMiddleware(Middleware): log_level: int = logging.INFO, include_payloads: bool = False, methods: list[str] | None = None, - serializer: Callable[[Any], Any] | None = None, + serializer: Callable[[Any], str] | None = None, ): """Initialize structured logging middleware. @@ -123,48 +123,14 @@ class StructuredLoggingMiddleware(Middleware): log_level: Log level for messages (default: INFO) include_payloads: Whether to include message payloads in logs methods: List of methods to log. If None, logs all methods. - serializer: Optional callable to convert objects to JSON-serializable - values when logging. Defaults to a safe converter that tries - pydantic_core.to_jsonable_python and falls back to str. + serializer: Callable that converts objects to a JSON string for the + payload. If not provided, uses FastMCP's default tool serializer. """ self.logger = logger or logging.getLogger("fastmcp.structured") self.log_level = log_level self.include_payloads = include_payloads self.methods = methods - self.serializer = serializer - - def _normalize(self, value: Any) -> Any: - """Normalize a Python object to a JSON-serializable value. - - Order: custom serializer → primitives → mappings/sequences (recursive) - → pydantic conversion → str fallback. - """ - if self.serializer is not None: - try: - value = self.serializer(value) - except Exception: - pass - - if value is None or isinstance(value, (str, int, float, bool)): # noqa: UP038 - return value - - if isinstance(value, dict): - return {str(k): self._normalize(v) for k, v in value.items()} - - if isinstance(value, (list, tuple, set)): # noqa: UP038 - return [self._normalize(v) for v in list(value)] - - try: - converted = pydantic_core.to_jsonable_python(value) - if converted is not value: - return self._normalize(converted) - except Exception: - pass - - try: - return str(value) - except Exception: - return "" + self.serializer = serializer or default_serializer def _create_log_entry( self, context: MiddlewareContext, event: str, **extra_fields @@ -186,7 +152,12 @@ class StructuredLoggingMiddleware(Middleware): else context.message ) - entry["payload"] = self._normalize(payload_obj) + try: + payload_str = self.serializer(payload_obj) + except Exception: + payload_str = default_serializer(payload_obj) + + entry["payload"] = payload_str return entry diff --git a/tests/server/middleware/test_logging.py b/tests/server/middleware/test_logging.py index 46c84cf00..a465e5281 100644 --- a/tests/server/middleware/test_logging.py +++ b/tests/server/middleware/test_logging.py @@ -2,6 +2,7 @@ import json import logging +from typing import Any from unittest.mock import AsyncMock, MagicMock import pytest @@ -137,8 +138,8 @@ class TestStructuredLoggingMiddleware: """Test creating log entry with payload.""" middleware = StructuredLoggingMiddleware(include_payloads=True) entry = middleware._create_log_entry(mock_context, "test_event") - - assert entry["payload"] == {"param": "value"} + assert isinstance(entry["payload"], str) + assert json.loads(entry["payload"]) == {"param": "value"} def test_create_log_entry_with_extra_fields(self, mock_context): """Test creating log entry with extra fields.""" @@ -211,7 +212,8 @@ class TestStructuredLoggingMiddleware: start_entry = json.loads(log_lines[0]) assert start_entry["event"] == "request_start" - assert start_entry["payload"]["url"] == "test://example/1" + payload = json.loads(start_entry["payload"]) + assert payload["url"] == "test://example/1" async def test_on_message_with_resource_template_in_payload( self, mock_context, mock_call_next, caplog @@ -238,10 +240,10 @@ class TestStructuredLoggingMiddleware: assert len(log_lines) == 2 start_entry = json.loads(log_lines[0]) assert start_entry["event"] == "request_start" - assert "template" in start_entry["payload"] - # With pydantic conversion, complex object becomes a JSONable dict - assert isinstance(start_entry["payload"]["template"], dict) - assert start_entry["payload"]["template"]["uri_template"] == "tmpl://{id}" + payload = json.loads(start_entry["payload"]) + assert "template" in payload + assert isinstance(payload["template"], dict) + assert payload["template"]["uri_template"] == "tmpl://{id}" async def test_on_message_with_nonserializable_payload_falls_back_to_str( self, mock_context, mock_call_next, caplog @@ -265,22 +267,19 @@ class TestStructuredLoggingMiddleware: assert len(log_lines) >= 2 start_entry = json.loads(log_lines[0]) assert start_entry["event"] == "request_start" - assert start_entry["payload"]["obj"] == "NON_SERIALIZABLE" + payload = json.loads(start_entry["payload"]) + assert payload["obj"] == "NON_SERIALIZABLE" async def test_on_message_with_custom_serializer_applied( self, mock_context, mock_call_next, caplog ): """Ensure a custom serializer is used for non-JSONable payloads.""" - class CustomType: - pass + # Provide a serializer that replaces entire payload with a fixed string + def custom_serializer(_: Any) -> str: + return "CUSTOM_PAYLOAD" - def custom_serializer(o): - if isinstance(o, CustomType): - return "CUSTOM:CustomType" - raise TypeError("unsupported") - - mock_context.message.__dict__["special"] = CustomType() + mock_context.message.__dict__["special"] = object() middleware = StructuredLoggingMiddleware( include_payloads=True, serializer=custom_serializer @@ -295,7 +294,7 @@ class TestStructuredLoggingMiddleware: assert len(log_lines) >= 2 start_entry = json.loads(log_lines[0]) assert start_entry["event"] == "request_start" - assert start_entry["payload"]["special"] == "CUSTOM:CustomType" + assert start_entry["payload"] == "CUSTOM_PAYLOAD" @pytest.fixture From 27401a3d5f578e57f5584236df8b315fd5ed3aa0 Mon Sep 17 00:00:00 2001 From: William Easton Date: Tue, 26 Aug 2025 23:54:34 -0500 Subject: [PATCH 09/10] Refactor logging middleware --- src/fastmcp/server/middleware/logging.py | 93 +++--- tests/server/middleware/test_logging.py | 348 ++++++++++++++++------- 2 files changed, 303 insertions(+), 138 deletions(-) diff --git a/src/fastmcp/server/middleware/logging.py b/src/fastmcp/server/middleware/logging.py index 0f24c7fd0..03f9b2936 100644 --- a/src/fastmcp/server/middleware/logging.py +++ b/src/fastmcp/server/middleware/logging.py @@ -3,13 +3,19 @@ import json import logging from collections.abc import Callable +from logging import Logger from typing import Any -from fastmcp.tools.tool import default_serializer +import pydantic_core from .middleware import CallNext, Middleware, MiddlewareContext +def default_serializer(data: Any) -> str: + """The default serializer for Payloads in the logging middleware.""" + return pydantic_core.to_json(data, fallback=str).decode() + + class LoggingMiddleware(Middleware): """Middleware that provides comprehensive request and response logging. @@ -36,6 +42,7 @@ class LoggingMiddleware(Middleware): include_payloads: bool = False, max_payload_length: int = 1000, methods: list[str] | None = None, + payload_serializer: Callable[[Any], str] | None = None, ): """Initialize logging middleware. @@ -46,13 +53,14 @@ class LoggingMiddleware(Middleware): max_payload_length: Maximum length of payload to log (prevents huge logs) methods: List of methods to log. If None, logs all methods. """ - self.logger = logger or logging.getLogger("fastmcp.requests") - self.log_level = log_level - self.include_payloads = include_payloads - self.max_payload_length = max_payload_length - self.methods = methods + self.logger: Logger = logger or logging.getLogger("fastmcp.requests") + self.log_level: int = log_level + self.include_payloads: bool = include_payloads + self.max_payload_length: int = max_payload_length + self.methods: list[str] | None = methods + self.payload_serializer: Callable[[Any], str] | None = payload_serializer - def _format_message(self, context: MiddlewareContext) -> str: + def _format_message(self, context: MiddlewareContext[Any]) -> str: """Format a message for logging.""" parts = [ f"source={context.source}", @@ -60,18 +68,29 @@ class LoggingMiddleware(Middleware): f"method={context.method or 'unknown'}", ] - if self.include_payloads and hasattr(context.message, "__dict__"): - try: - payload = json.dumps(context.message.__dict__, default=str) - if len(payload) > self.max_payload_length: - payload = payload[: self.max_payload_length] + "..." - parts.append(f"payload={payload}") - except (TypeError, ValueError): - parts.append("payload=") + if self.include_payloads: + payload: str + if not self.payload_serializer: + payload = default_serializer(context.message) + else: + try: + payload = self.payload_serializer(context.message) + except Exception as e: + self.logger.warning( + f"Failed {str(e)} to serialize payload: {context.type} {context.method} {context.source}." + ) + payload = default_serializer(context.message) + + if len(payload) > self.max_payload_length: + payload = payload[: self.max_payload_length] + "..." + + parts.append(f"payload={payload}") return " ".join(parts) - async def on_message(self, context: MiddlewareContext, call_next: CallNext) -> Any: + async def on_message( + self, context: MiddlewareContext[Any], call_next: CallNext[Any, Any] + ) -> Any: """Log all messages.""" message_info = self._format_message(context) if self.methods and context.method not in self.methods: @@ -114,7 +133,7 @@ class StructuredLoggingMiddleware(Middleware): log_level: int = logging.INFO, include_payloads: bool = False, methods: list[str] | None = None, - serializer: Callable[[Any], str] | None = None, + payload_serializer: Callable[[Any], str] | None = None, ): """Initialize structured logging middleware. @@ -126,15 +145,15 @@ class StructuredLoggingMiddleware(Middleware): serializer: Callable that converts objects to a JSON string for the payload. If not provided, uses FastMCP's default tool serializer. """ - self.logger = logger or logging.getLogger("fastmcp.structured") - self.log_level = log_level - self.include_payloads = include_payloads - self.methods = methods - self.serializer = serializer or default_serializer + self.logger: Logger = logger or logging.getLogger("fastmcp.structured") + self.log_level: int = log_level + self.include_payloads: bool = include_payloads + self.methods: list[str] | None = methods + self.payload_serializer: Callable[[Any], str] | None = payload_serializer def _create_log_entry( - self, context: MiddlewareContext, event: str, **extra_fields - ) -> dict: + self, context: MiddlewareContext[Any], event: str, **extra_fields: Any + ) -> dict[str, Any]: """Create a structured log entry.""" entry = { "event": event, @@ -146,22 +165,26 @@ class StructuredLoggingMiddleware(Middleware): } if self.include_payloads: - payload_obj = ( - context.message.__dict__ - if hasattr(context.message, "__dict__") - else context.message - ) + payload: str - try: - payload_str = self.serializer(payload_obj) - except Exception: - payload_str = default_serializer(payload_obj) + if not self.payload_serializer: + payload = default_serializer(context.message) + else: + try: + payload = self.payload_serializer(context.message) + except Exception as e: + self.logger.warning( + f"Failed {str(e)} to serialize payload: {context.type} {context.method} {context.source}." + ) + payload = default_serializer(context.message) - entry["payload"] = payload_str + entry["payload"] = payload return entry - async def on_message(self, context: MiddlewareContext, call_next: CallNext) -> Any: + async def on_message( + self, context: MiddlewareContext[Any], call_next: CallNext[Any, Any] + ) -> Any: """Log structured message information.""" start_entry = self._create_log_entry(context, "request_start") if self.methods and context.method not in self.methods: diff --git a/tests/server/middleware/test_logging.py b/tests/server/middleware/test_logging.py index a465e5281..d0118f219 100644 --- a/tests/server/middleware/test_logging.py +++ b/tests/server/middleware/test_logging.py @@ -1,31 +1,58 @@ """Tests for logging middleware.""" +import datetime import json import logging -from typing import Any +from typing import Any, Literal, TypeVar from unittest.mock import AsyncMock, MagicMock +import mcp import pytest +from inline_snapshot import snapshot +from pydantic import AnyUrl +from fastmcp.resources.template import ResourceTemplate from fastmcp.server.middleware.logging import ( LoggingMiddleware, StructuredLoggingMiddleware, ) -from fastmcp.server.middleware.middleware import MiddlewareContext +from fastmcp.server.middleware.middleware import CallNext, MiddlewareContext +from fastmcp.server.server import FastMCP + +FIXED_DATE = datetime.datetime(2023, 1, 1, tzinfo=datetime.timezone.utc) + +T = TypeVar("T") + + +def new_mock_context( + message: T, + method: str | None = None, + source: Literal["server", "client"] | None = None, + type: Literal["request", "notification"] | None = None, +) -> MiddlewareContext[T]: + """Create a new mock middleware context.""" + context = MagicMock(spec=MiddlewareContext[T]) + context.method = method or "test_method" + context.source = source or "client" + context.type = type or "request" + context.message = message + context.timestamp = FIXED_DATE + return context @pytest.fixture def mock_context(): """Create a mock middleware context.""" - context = MagicMock(spec=MiddlewareContext) - context.method = "test_method" - context.source = "client" - context.type = "request" - context.message = MagicMock() - context.message.__dict__ = {"param": "value"} - context.timestamp = MagicMock() - context.timestamp.isoformat.return_value = "2023-01-01T00:00:00Z" - return context + + return new_mock_context( + message=mcp.types.CallToolRequest( + method="tools/call", + params=mcp.types.CallToolRequestParams( + name="test_method", + arguments={"param": "value"}, + ), + ) + ) @pytest.fixture @@ -59,7 +86,9 @@ class TestLoggingMiddleware: assert middleware.include_payloads is True assert middleware.max_payload_length == 500 - def test_format_message_without_payloads(self, mock_context): + def test_format_message_without_payloads( + self, mock_context: MiddlewareContext[Any] + ): """Test message formatting without payloads.""" middleware = LoggingMiddleware() formatted = middleware._format_message(mock_context) @@ -69,17 +98,16 @@ class TestLoggingMiddleware: assert "method=test_method" in formatted assert "payload=" not in formatted - def test_format_message_with_payloads(self, mock_context): + def test_format_message_with_payloads(self, mock_context: MiddlewareContext[Any]): """Test message formatting with payloads.""" middleware = LoggingMiddleware(include_payloads=True) formatted = middleware._format_message(mock_context) - assert "source=client" in formatted - assert "type=request" in formatted - assert "method=test_method" in formatted - assert 'payload={"param": "value"}' in formatted + assert formatted == snapshot( + 'source=client type=request method=test_method payload={"method":"tools/call","params":{"_meta":null,"name":"test_method","arguments":{"param":"value"}}}' + ) - def test_format_message_long_payload(self, mock_context): + def test_format_message_long_payload(self, mock_context: MiddlewareContext[Any]): """Test message formatting with long payload truncation.""" middleware = LoggingMiddleware(include_payloads=True, max_payload_length=10) formatted = middleware._format_message(mock_context) @@ -87,7 +115,12 @@ class TestLoggingMiddleware: assert "payload=" in formatted assert "..." in formatted - async def test_on_message_success(self, mock_context, mock_call_next, caplog): + async def test_on_message_success( + self, + mock_context: MiddlewareContext[Any], + mock_call_next: CallNext[Any, Any], + caplog: pytest.LogCaptureFixture, + ): """Test logging successful messages.""" middleware = LoggingMiddleware() @@ -99,7 +132,9 @@ class TestLoggingMiddleware: assert "Processing message:" in caplog.text assert "Completed message: test_method" in caplog.text - async def test_on_message_failure(self, mock_context, caplog): + async def test_on_message_failure( + self, mock_context: MiddlewareContext[Any], caplog: pytest.LogCaptureFixture + ): """Test logging failed messages.""" middleware = LoggingMiddleware() mock_call_next = AsyncMock(side_effect=ValueError("test error")) @@ -122,26 +157,40 @@ class TestStructuredLoggingMiddleware: assert middleware.log_level == logging.INFO assert middleware.include_payloads is False - def test_create_log_entry_basic(self, mock_context): + def test_create_log_entry_basic(self, mock_context: MiddlewareContext[Any]): """Test creating basic log entry.""" middleware = StructuredLoggingMiddleware() entry = middleware._create_log_entry(mock_context, "test_event") - assert entry["event"] == "test_event" - assert entry["timestamp"] == "2023-01-01T00:00:00Z" - assert entry["source"] == "client" - assert entry["type"] == "request" - assert entry["method"] == "test_method" - assert "payload" not in entry + assert entry == snapshot( + { + "event": "test_event", + "timestamp": "2023-01-01T00:00:00+00:00", + "source": "client", + "type": "request", + "method": "test_method", + } + ) - def test_create_log_entry_with_payload(self, mock_context): + def test_create_log_entry_with_payload(self, mock_context: MiddlewareContext[Any]): """Test creating log entry with payload.""" middleware = StructuredLoggingMiddleware(include_payloads=True) entry = middleware._create_log_entry(mock_context, "test_event") - assert isinstance(entry["payload"], str) - assert json.loads(entry["payload"]) == {"param": "value"} - def test_create_log_entry_with_extra_fields(self, mock_context): + assert entry == snapshot( + { + "event": "test_event", + "timestamp": "2023-01-01T00:00:00+00:00", + "source": "client", + "type": "request", + "method": "test_method", + "payload": '{"method":"tools/call","params":{"_meta":null,"name":"test_method","arguments":{"param":"value"}}}', + } + ) + + def test_create_log_entry_with_extra_fields( + self, mock_context: MiddlewareContext[Any] + ): """Test creating log entry with extra fields.""" middleware = StructuredLoggingMiddleware() entry = middleware._create_log_entry( @@ -150,7 +199,12 @@ class TestStructuredLoggingMiddleware: assert entry["extra_field"] == "extra_value" - async def test_on_message_success(self, mock_context, mock_call_next, caplog): + async def test_on_message_success( + self, + mock_context: MiddlewareContext[Any], + mock_call_next: CallNext[Any, Any], + caplog: pytest.LogCaptureFixture, + ): """Test structured logging of successful messages.""" middleware = StructuredLoggingMiddleware() @@ -161,17 +215,33 @@ class TestStructuredLoggingMiddleware: # Check that we have structured JSON logs log_lines = [record.message for record in caplog.records] + assert len(log_lines) == 2 # start and success entries - start_entry = json.loads(log_lines[0]) - assert start_entry["event"] == "request_start" - assert start_entry["method"] == "test_method" + assert json.loads(log_lines[0]) == snapshot( + { + "event": "request_start", + "timestamp": "2023-01-01T00:00:00+00:00", + "source": "client", + "type": "request", + "method": "test_method", + } + ) - success_entry = json.loads(log_lines[1]) - assert success_entry["event"] == "request_success" - assert success_entry["result_type"] == "str" + assert json.loads(log_lines[1]) == snapshot( + { + "event": "request_success", + "timestamp": "2023-01-01T00:00:00+00:00", + "source": "client", + "type": "request", + "method": "test_method", + "result_type": "str", + } + ) - async def test_on_message_failure(self, mock_context, caplog): + async def test_on_message_failure( + self, mock_context: MiddlewareContext[Any], caplog: pytest.LogCaptureFixture + ): """Test structured logging of failed messages.""" middleware = StructuredLoggingMiddleware() mock_call_next = AsyncMock(side_effect=ValueError("test error")) @@ -187,47 +257,80 @@ class TestStructuredLoggingMiddleware: start_entry = json.loads(log_lines[0]) assert start_entry["event"] == "request_start" - error_entry = json.loads(log_lines[1]) - assert error_entry["event"] == "request_error" - assert error_entry["error_type"] == "ValueError" - assert error_entry["error_message"] == "test error" - - async def test_on_message_with_pydantic_types_in_payload( - self, mock_context, mock_call_next, caplog - ): - """Ensure Pydantic AnyUrl in payload serializes correctly when include_payloads=True.""" - from pydantic import AnyUrl - - mock_context.message.__dict__["url"] = AnyUrl("test://example/1") - - middleware = StructuredLoggingMiddleware(include_payloads=True) - - with caplog.at_level(logging.INFO): - result = await middleware.on_message(mock_context, mock_call_next) - - assert result == "test_result" - - log_lines = [record.message for record in caplog.records] - assert len(log_lines) == 2 - start_entry = json.loads(log_lines[0]) - - assert start_entry["event"] == "request_start" - payload = json.loads(start_entry["payload"]) - assert payload["url"] == "test://example/1" - - async def test_on_message_with_resource_template_in_payload( - self, mock_context, mock_call_next, caplog - ): - """Ensure ResourceTemplate in payload serializes via pydantic conversion without errors.""" - from fastmcp.resources import ResourceTemplate - - template = ResourceTemplate( - name="tmpl", - uri_template="tmpl://{id}", - parameters={"id": {"type": "string"}}, + assert json.loads(log_lines[1]) == snapshot( + { + "event": "request_error", + "timestamp": "2023-01-01T00:00:00+00:00", + "source": "client", + "type": "request", + "method": "test_method", + "error_type": "ValueError", + "error_message": "test error", + } ) - mock_context.message.__dict__["template"] = template + async def test_on_message_with_pydantic_types_in_payload( + self, + mock_call_next: CallNext[Any, Any], + caplog: pytest.LogCaptureFixture, + ): + """Ensure Pydantic AnyUrl in payload serializes correctly when include_payloads=True.""" + + mock_context = new_mock_context( + message=mcp.types.ReadResourceRequest( + method="resources/read", + params=mcp.types.ReadResourceRequestParams( + uri=AnyUrl("test://example/1"), + ), + ) + ) + + middleware = StructuredLoggingMiddleware(include_payloads=True) + + with caplog.at_level(logging.INFO): + result = await middleware.on_message(mock_context, mock_call_next) + + assert result == "test_result" + + log_lines = [record.message for record in caplog.records] + + assert len(log_lines) == 2 + assert json.loads(log_lines[0]) == snapshot( + { + "event": "request_start", + "timestamp": "2023-01-01T00:00:00+00:00", + "source": "client", + "type": "request", + "method": "test_method", + "payload": '{"method":"resources/read","params":{"_meta":null,"uri":"test://example/1"}}', + } + ) + assert json.loads(log_lines[1]) == snapshot( + { + "event": "request_success", + "timestamp": "2023-01-01T00:00:00+00:00", + "source": "client", + "type": "request", + "method": "test_method", + "result_type": "str", + "payload": '{"method":"resources/read","params":{"_meta":null,"uri":"test://example/1"}}', + } + ) + + async def test_on_message_with_resource_template_in_payload( + self, + mock_call_next: CallNext[Any, Any], + caplog: pytest.LogCaptureFixture, + ): + """Ensure ResourceTemplate in payload serializes via pydantic conversion without errors.""" + + mock_context = new_mock_context( + message=ResourceTemplate( + name="tmpl", + uri_template="tmpl://{id}", + parameters={"id": {"type": "string"}}, + ) + ) middleware = StructuredLoggingMiddleware(include_payloads=True) @@ -238,15 +341,19 @@ class TestStructuredLoggingMiddleware: log_lines = [record.message for record in caplog.records] assert len(log_lines) == 2 - start_entry = json.loads(log_lines[0]) - assert start_entry["event"] == "request_start" - payload = json.loads(start_entry["payload"]) - assert "template" in payload - assert isinstance(payload["template"], dict) - assert payload["template"]["uri_template"] == "tmpl://{id}" + assert json.loads(log_lines[0]) == snapshot( + { + "event": "request_start", + "timestamp": "2023-01-01T00:00:00+00:00", + "source": "client", + "type": "request", + "method": "test_method", + "payload": '{"name":"tmpl","title":null,"description":null,"tags":[],"meta":null,"enabled":true,"uri_template":"tmpl://{id}","mime_type":"text/plain","parameters":{"id":{"type":"string"}},"annotations":null}', + } + ) async def test_on_message_with_nonserializable_payload_falls_back_to_str( - self, mock_context, mock_call_next, caplog + self, mock_call_next: CallNext[Any, Any], caplog: pytest.LogCaptureFixture ): """Ensure non-JSONable objects fall back to string serialization in payload.""" @@ -254,7 +361,15 @@ class TestStructuredLoggingMiddleware: def __str__(self) -> str: return "NON_SERIALIZABLE" - mock_context.message.__dict__["obj"] = NonSerializable() + mock_context = new_mock_context( + message=mcp.types.CallToolRequest( + method="tools/call", + params=mcp.types.CallToolRequestParams( + name="test_method", + arguments={"obj": NonSerializable()}, + ), + ) + ) middleware = StructuredLoggingMiddleware(include_payloads=True) @@ -265,13 +380,19 @@ class TestStructuredLoggingMiddleware: log_lines = [record.message for record in caplog.records] assert len(log_lines) >= 2 - start_entry = json.loads(log_lines[0]) - assert start_entry["event"] == "request_start" - payload = json.loads(start_entry["payload"]) - assert payload["obj"] == "NON_SERIALIZABLE" + assert json.loads(log_lines[0]) == snapshot( + { + "event": "request_start", + "timestamp": "2023-01-01T00:00:00+00:00", + "source": "client", + "type": "request", + "method": "test_method", + "payload": '{"method":"tools/call","params":{"_meta":null,"name":"test_method","arguments":{"obj":"NON_SERIALIZABLE"}}}', + } + ) async def test_on_message_with_custom_serializer_applied( - self, mock_context, mock_call_next, caplog + self, mock_call_next: CallNext[Any, Any], caplog: pytest.LogCaptureFixture ): """Ensure a custom serializer is used for non-JSONable payloads.""" @@ -279,10 +400,18 @@ class TestStructuredLoggingMiddleware: def custom_serializer(_: Any) -> str: return "CUSTOM_PAYLOAD" - mock_context.message.__dict__["special"] = object() + mock_context = new_mock_context( + message=mcp.types.CallToolRequest( + method="tools/call", + params=mcp.types.CallToolRequestParams( + name="test_method", + arguments={"obj": "OBJECT"}, + ), + ) + ) middleware = StructuredLoggingMiddleware( - include_payloads=True, serializer=custom_serializer + include_payloads=True, payload_serializer=custom_serializer ) with caplog.at_level(logging.INFO): @@ -292,9 +421,16 @@ class TestStructuredLoggingMiddleware: log_lines = [record.message for record in caplog.records] assert len(log_lines) >= 2 - start_entry = json.loads(log_lines[0]) - assert start_entry["event"] == "request_start" - assert start_entry["payload"] == "CUSTOM_PAYLOAD" + assert json.loads(log_lines[0]) == snapshot( + { + "event": "request_start", + "timestamp": "2023-01-01T00:00:00+00:00", + "source": "client", + "type": "request", + "method": "test_method", + "payload": "CUSTOM_PAYLOAD", + } + ) @pytest.fixture @@ -338,7 +474,7 @@ class TestLoggingMiddlewareIntegration: """Integration tests for logging middleware with real FastMCP server.""" async def test_logging_middleware_logs_successful_operations( - self, logging_server, caplog + self, logging_server: FastMCP, caplog: pytest.LogCaptureFixture ): """Test that logging middleware captures successful operations.""" from fastmcp.client import Client @@ -364,7 +500,9 @@ class TestLoggingMiddlewareIntegration: assert processing_count == 2 assert completion_count == 2 - async def test_logging_middleware_logs_failures(self, logging_server, caplog): + async def test_logging_middleware_logs_failures( + self, logging_server: FastMCP, caplog: pytest.LogCaptureFixture + ): """Test that logging middleware captures failed operations.""" from fastmcp.client import Client @@ -384,7 +522,9 @@ class TestLoggingMiddlewareIntegration: assert "Processing message:" in log_text assert "Failed message: tools/call" in log_text - async def test_logging_middleware_with_payloads(self, logging_server, caplog): + async def test_logging_middleware_with_payloads( + self, logging_server: FastMCP, caplog: pytest.LogCaptureFixture + ): """Test logging middleware when configured to include payloads.""" from fastmcp.client import Client @@ -405,7 +545,7 @@ class TestLoggingMiddlewareIntegration: assert "payload=" in log_text async def test_structured_logging_middleware_produces_json( - self, logging_server, caplog + self, logging_server: FastMCP, caplog: pytest.LogCaptureFixture ): """Test that structured logging middleware produces parseable JSON logs.""" import json @@ -439,7 +579,7 @@ class TestLoggingMiddlewareIntegration: assert "method" in log_entry async def test_structured_logging_middleware_handles_errors( - self, logging_server, caplog + self, logging_server: FastMCP, caplog: pytest.LogCaptureFixture ): """Test structured logging of errors with JSON format.""" import json @@ -480,7 +620,7 @@ class TestLoggingMiddlewareIntegration: assert "error_message" in error_entry async def test_logging_middleware_with_different_operations( - self, logging_server, caplog + self, logging_server: FastMCP, caplog: pytest.LogCaptureFixture ): """Test logging middleware with various MCP operations.""" from fastmcp.client import Client @@ -515,7 +655,9 @@ class TestLoggingMiddlewareIntegration: assert processing_count == 4 assert completion_count == 4 - async def test_logging_middleware_custom_configuration(self, logging_server): + async def test_logging_middleware_custom_configuration( + self, logging_server: FastMCP + ): """Test logging middleware with custom logger configuration.""" import io import logging From ac8caca269b708930d9e8f6ea99f5850f8f6b366 Mon Sep 17 00:00:00 2001 From: William Easton Date: Wed, 27 Aug 2025 08:03:16 -0500 Subject: [PATCH 10/10] PR Feedback --- src/fastmcp/server/middleware/logging.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/fastmcp/server/middleware/logging.py b/src/fastmcp/server/middleware/logging.py index 03f9b2936..3511a3388 100644 --- a/src/fastmcp/server/middleware/logging.py +++ b/src/fastmcp/server/middleware/logging.py @@ -78,7 +78,7 @@ class LoggingMiddleware(Middleware): payload = self.payload_serializer(context.message) except Exception as e: self.logger.warning( - f"Failed {str(e)} to serialize payload: {context.type} {context.method} {context.source}." + f"Failed {e} to serialize payload: {context.type} {context.method} {context.source}." ) payload = default_serializer(context.message)