diff --git a/microbootstrap/config/litestar.py b/microbootstrap/config/litestar.py index cf23b9b..ec9afc1 100644 --- a/microbootstrap/config/litestar.py +++ b/microbootstrap/config/litestar.py @@ -3,6 +3,7 @@ import typing from litestar.config.app import AppConfig +from litestar.logging import LoggingConfig if typing.TYPE_CHECKING: @@ -12,3 +13,9 @@ @dataclasses.dataclass class LitestarConfig(AppConfig): on_app_init: typing.Sequence[OnAppInitHandler] | None = None + logging_config: LoggingConfig = dataclasses.field( + default_factory=lambda: LoggingConfig( + # required for foreign logs json formatting + configure_root_logger=False, + ) + ) diff --git a/microbootstrap/granian_server.py b/microbootstrap/granian_server.py index 99a6158..567a3a2 100644 --- a/microbootstrap/granian_server.py +++ b/microbootstrap/granian_server.py @@ -8,6 +8,8 @@ if typing.TYPE_CHECKING: + from granian.server.common import AbstractServer as GranianServer + from microbootstrap.settings import ServerConfig @@ -26,8 +28,8 @@ def create_granian_server( target: str, settings: ServerConfig, **granian_options: typing.Any, # noqa: ANN401 -) -> granian.Granian: # type: ignore[name-defined] - return granian.Granian( # type: ignore[attr-defined] +) -> GranianServer[typing.Any]: + return granian.Granian( target=target, address=settings.server_host, port=settings.server_port, diff --git a/microbootstrap/instruments/logging_instrument.py b/microbootstrap/instruments/logging_instrument.py index 9d047a6..03c2878 100644 --- a/microbootstrap/instruments/logging_instrument.py +++ b/microbootstrap/instruments/logging_instrument.py @@ -1,6 +1,7 @@ from __future__ import annotations import logging import logging.handlers +import sys import time import typing import urllib.parse @@ -71,7 +72,7 @@ def tracer_injection(_: WrappedLogger, __: str, event_dict: EventDict) -> EventD return event_dict -DEFAULT_STRUCTLOG_PROCESSORS: typing.Final[list[typing.Any]] = [ +STRUCTLOG_PRE_CHAIN_PROCESSORS: typing.Final[list[typing.Any]] = [ structlog.stdlib.filter_by_level, structlog.stdlib.add_log_level, structlog.stdlib.add_logger_name, @@ -88,7 +89,7 @@ def _serialize_log_with_orjson_to_string(value: typing.Any, **kwargs: typing.Any return orjson.dumps(value, **kwargs).decode() -DEFAULT_STRUCTLOG_FORMATTER_PROCESSOR: typing.Final = structlog.processors.JSONRenderer( +STRUCTLOG_FORMATTER_PROCESSOR: typing.Final = structlog.processors.JSONRenderer( serializer=_serialize_log_with_orjson_to_string ) @@ -154,15 +155,16 @@ def is_ready(self) -> bool: def teardown(self) -> None: structlog.reset_defaults() - def bootstrap(self) -> None: + def _unset_handlers(self) -> None: for unset_handlers_logger in self.instrument_config.logging_unset_handlers: logging.getLogger(unset_handlers_logger).handlers = [] + def _configure_structlog_loggers(self) -> None: structlog.configure( processors=[ - *DEFAULT_STRUCTLOG_PROCESSORS, + *STRUCTLOG_PRE_CHAIN_PROCESSORS, *self.instrument_config.logging_extra_processors, - DEFAULT_STRUCTLOG_FORMATTER_PROCESSOR, + STRUCTLOG_FORMATTER_PROCESSOR, ], context_class=dict, logger_factory=MemoryLoggerFactory( @@ -174,6 +176,27 @@ def bootstrap(self) -> None: cache_logger_on_first_use=True, ) + def _configure_foreign_loggers(self) -> None: + root_logger: typing.Final = logging.getLogger() + stream_handler: typing.Final = logging.StreamHandler(sys.stdout) + stream_handler.setFormatter( + structlog.stdlib.ProcessorFormatter( + foreign_pre_chain=STRUCTLOG_PRE_CHAIN_PROCESSORS, + processors=[ + structlog.stdlib.ProcessorFormatter.remove_processors_meta, + STRUCTLOG_FORMATTER_PROCESSOR, + ], + logger=root_logger, + ) + ) + root_logger.addHandler(stream_handler) + root_logger.setLevel(self.instrument_config.logging_log_level) + + def bootstrap(self) -> None: + self._unset_handlers() + self._configure_structlog_loggers() + self._configure_foreign_loggers() + @classmethod def get_config_type(cls) -> type[LoggingConfig]: return LoggingConfig diff --git a/tests/instruments/test_logging.py b/tests/instruments/test_logging.py index b29ef35..0e988d9 100644 --- a/tests/instruments/test_logging.py +++ b/tests/instruments/test_logging.py @@ -7,15 +7,20 @@ import litestar import pytest from fastapi.testclient import TestClient as FastAPITestClient +from faststream.redis import RedisBroker, TestRedisBroker from litestar.testing import TestClient as LitestarTestClient from opentelemetry import trace from opentelemetry.sdk.trace import TracerProvider from opentelemetry.sdk.trace.export import ConsoleSpanExporter, SimpleSpanProcessor from microbootstrap import LoggingConfig -from microbootstrap.bootstrappers.fastapi import FastApiLoggingInstrument -from microbootstrap.bootstrappers.litestar import LitestarLoggingInstrument +from microbootstrap.bootstrappers.fastapi import FastApiBootstrapper, FastApiLoggingInstrument +from microbootstrap.bootstrappers.faststream import FastStreamBootstrapper +from microbootstrap.bootstrappers.litestar import LitestarBootstrapper, LitestarLoggingInstrument +from microbootstrap.config.faststream import FastStreamConfig +from microbootstrap.config.litestar import LitestarConfig from microbootstrap.instruments.logging_instrument import LoggingInstrument, MemoryLoggerFactory +from microbootstrap.settings import FastApiSettings, FastStreamSettings, LitestarSettings def test_logging_is_ready(minimal_logging_config: LoggingConfig) -> None: @@ -47,10 +52,10 @@ def test_logging_teardown( def test_litestar_logging_bootstrap(minimal_logging_config: LoggingConfig) -> None: logging_instrument: typing.Final = LitestarLoggingInstrument(minimal_logging_config) logging_instrument.bootstrap() - bootsrap_result: typing.Final = logging_instrument.bootstrap_before() - assert "middleware" in bootsrap_result - assert isinstance(bootsrap_result["middleware"], list) - assert len(bootsrap_result["middleware"]) == 1 + bootstrap_result: typing.Final = logging_instrument.bootstrap_before() + assert "middleware" in bootstrap_result + assert isinstance(bootstrap_result["middleware"], list) + assert len(bootstrap_result["middleware"]) == 1 def test_litestar_logging_bootstrap_working( @@ -188,3 +193,62 @@ def test_fastapi_logging_bootstrap_ignores_health( test_client.get("/health") assert fill_log_mock.call_count == 0 + + +class TestForeignLogs: + def test_litestar(self, capsys: pytest.CaptureFixture[str]) -> None: + logger = logging.getLogger() + + @litestar.get() + async def greet() -> str: + logger.info("said hi") + return "hi" + + application = ( + LitestarBootstrapper(LitestarSettings(service_debug=False, logging_buffer_capacity=0)) + .configure_application(LitestarConfig(route_handlers=[greet])) + .bootstrap() + ) + with LitestarTestClient(application) as test_client: + test_client.get("/") + + stdout = capsys.readouterr().out + assert '{"event":"said hi","level":"info","logger":"root"' in stdout + assert stdout.count("said hi") == 1 + + def test_fastapi(self, capsys: pytest.CaptureFixture[str]) -> None: + logger = logging.getLogger() + application = FastApiBootstrapper(FastApiSettings(service_debug=False, logging_buffer_capacity=0)).bootstrap() + + @application.get("/") + async def greet() -> str: + logger.info("said hi") + return "hi" + + with FastAPITestClient(application) as test_client: + test_client.get("/") + + stdout = capsys.readouterr().out + assert '{"event":"said hi","level":"info","logger":"root"' in stdout + assert stdout.count("said hi") == 1 + + async def test_faststream(self, capsys: pytest.CaptureFixture[str]) -> None: + logger = logging.getLogger() + broker = RedisBroker() + + @broker.subscriber("greetings") + async def greet() -> None: + logger.info("said hi") + + ( + FastStreamBootstrapper(FastStreamSettings(service_debug=False, logging_buffer_capacity=0)) + .configure_application(FastStreamConfig(broker=broker)) + .bootstrap() + ) + + async with TestRedisBroker(broker): + await broker.publish(message="hello", channel="greetings") + + stdout = capsys.readouterr().out + assert '{"event":"said hi","level":"info","logger":"root"' in stdout + assert stdout.count("said hi") == 1 diff --git a/tests/test_granian_server.py b/tests/test_granian_server.py index d0c64f7..323c174 100644 --- a/tests/test_granian_server.py +++ b/tests/test_granian_server.py @@ -5,4 +5,4 @@ def test_granian_server(minimal_server_config: ServerConfig) -> None: - assert isinstance(create_granian_server("some:app", minimal_server_config), granian.Granian) # type: ignore[attr-defined] + assert isinstance(create_granian_server("some:app", minimal_server_config), granian.Granian)