Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 4 additions & 1 deletion docs/introduction/configuration.md
Original file line number Diff line number Diff line change
Expand Up @@ -348,7 +348,7 @@ Additional parameters:
- `logging_enabled` - whether to configure structlog (default: `True`).
- `logging_log_level`
- `logging_extra_processors`
- `logging_unset_handlers`
- `logging_unset_handlers` - logger names whose handlers are cleared at bootstrap. These removals are permanent.
- `logging_record_filters` - standard-library `logging.Filter` instances to attach to named loggers (see below).
- `logging_time_stamper` - a `structlog.processors.TimeStamper` instance controlling timestamp format (default: `TimeStamper(fmt="iso")`). Pass a custom instance to change the format or enable UTC:

Expand All @@ -361,6 +361,9 @@ config = FastAPIConfig(
)
```

Teardown removes and closes the root handler installed by lite-bootstrap and restores the root
logger level from before bootstrap. Other root handlers stay attached.

### Filtering standard-library log records

`logging_record_filters` attaches `logging.Filter` instances to loggers by name. A filter sees every
Expand Down
29 changes: 16 additions & 13 deletions lite_bootstrap/instruments/logging_instrument.py
Original file line number Diff line number Diff line change
Expand Up @@ -83,6 +83,8 @@ class LoggingConfig(BaseConfig):
class LoggingInstrument(BaseInstrument[LoggingConfigT]):
not_configured_reason = "logging_enabled is False"
missing_dependency_message = "structlog is not installed"
_root_handler: logging.Handler | None = dataclasses.field(default=None, init=False, repr=False, compare=False)
_previous_root_level: int | None = dataclasses.field(default=None, init=False, repr=False, compare=False)
_attached_filters: list[tuple[logging.Logger, logging.Filter]] = dataclasses.field(
default_factory=list, init=False, repr=False, compare=False
)
Expand Down Expand Up @@ -180,7 +182,9 @@ def _configure_foreign_loggers(self) -> None:
logger=root_logger,
)
)
self._previous_root_level = root_logger.level
root_logger.addHandler(stream_handler)
self._root_handler = stream_handler
root_logger.setLevel(self.bootstrap_config.logging_log_level)

def _attach_record_filters(self) -> None:
Expand All @@ -204,24 +208,23 @@ def bootstrap(self) -> None:
self._attach_record_filters()

def teardown(self) -> None:
"""Reset structlog and root logger.
"""Reset structlog, remove the installed handler and filters, and restore the root level.

Root logger level is unconditionally set to WARNING; pre-existing user configuration is overwritten.
Filters from ``logging_record_filters`` are removed one pair at a time, so a filter the
application or another library put on the same logger survives.

Best-effort cleanup: errors from individual ``handler.close()`` calls are collected and
re-raised together via :class:`~lite_bootstrap.exceptions.TeardownError` after the rest of
teardown completes, so no single misbehaving handler keeps the others open.
Handler removals configured through ``logging_unset_handlers`` are permanent.
Errors from closing the installed handler are reported after the rest of teardown.
"""
structlog.reset_defaults()
root_logger = logging.getLogger()
with collect_teardown_errors() as teardown_errors:
try:
for h in root_logger.handlers[:]:
root_logger.removeHandler(h)
with teardown_errors.capture(type(h).__name__):
h.close()
root_logger.setLevel(logging.WARNING)
if self._root_handler is not None:
handler = self._root_handler
self._root_handler = None
root_logger.removeHandler(handler)
with teardown_errors.capture(type(handler).__name__):
handler.close()
if self._previous_root_level is not None:
root_logger.setLevel(self._previous_root_level)
self._previous_root_level = None
finally:
self._detach_record_filters()
40 changes: 31 additions & 9 deletions tests/instruments/test_logging_instrument.py
Original file line number Diff line number Diff line change
Expand Up @@ -112,17 +112,41 @@ def test_logging_instrument_lifecycle_replay(logging_mock: LoggingMock) -> None:
instrument.teardown()


def test_logging_instrument_teardown_restores_root_logger() -> None:
root_logger = logging.getLogger()
original_handlers = root_logger.handlers[:]
original_level = root_logger.level
existing_handler = logging.StreamHandler(StringIO())
root_logger.addHandler(existing_handler)
root_logger.setLevel(logging.DEBUG)
instrument = LoggingInstrument(bootstrap_config=LoggingConfig())
try:
instrument.bootstrap()
(owned_handler,) = set(root_logger.handlers) - {*original_handlers, existing_handler}
with patch.object(existing_handler, "close", wraps=existing_handler.close) as close:
instrument.teardown()
close.assert_not_called()

assert existing_handler in root_logger.handlers
assert root_logger.level == logging.DEBUG
assert owned_handler not in root_logger.handlers
finally:
for handler in original_handlers:
root_logger.addHandler(handler)
root_logger.removeHandler(existing_handler)
existing_handler.close()
root_logger.setLevel(original_level)


def test_logging_instrument_teardown_aggregates_handler_close_errors() -> None:
instrument = LoggingInstrument(
bootstrap_config=LoggingConfig(),
)
instrument.bootstrap()
root_logger = logging.getLogger()

# Find the StreamHandler added by _configure_foreign_loggers and patch its close.
bootstrap_added = [h for h in root_logger.handlers if isinstance(h, logging.StreamHandler)]
assert bootstrap_added, "bootstrap should have added at least one StreamHandler to root"
target_handler = bootstrap_added[0]
previous_level = root_logger.level
existing_handlers = set(root_logger.handlers)
instrument.bootstrap()
(target_handler,) = set(root_logger.handlers) - existing_handlers

with (
patch.object(target_handler, "close", side_effect=RuntimeError("boom")),
Expand All @@ -132,9 +156,7 @@ def test_logging_instrument_teardown_aggregates_handler_close_errors() -> None:
assert isinstance(excinfo.value.__cause__, RuntimeError)
assert any("boom" in str(err) for _, err in excinfo.value.errors)

# After teardown despite the raise, post-loop cleanup must have completed:
assert root_logger.level == logging.WARNING
# And the broken handler must have been removed from root despite raising.
assert root_logger.level == previous_level
assert target_handler not in root_logger.handlers


Expand Down
27 changes: 6 additions & 21 deletions tests/instruments/test_logging_record_filters.py
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
import logging
import re
import typing
from unittest.mock import patch

import faststream.asgi
import pytest
Expand Down Expand Up @@ -284,34 +285,18 @@ def test_teardown_removes_filters_even_when_a_handler_close_fails() -> None:
configured_filter = RecordingFilter()
target_logger = logging.getLogger("teardown_despite_error.target")

class ExplodingHandler(logging.Handler):
exploded = False

def emit(self, record: logging.LogRecord) -> None:
"""Never called: this handler exists only to fail on close."""

def close(self) -> None:
"""Fail the first close only: a later logging.shutdown still reaches this handler until it is collected."""
super().close()
if not self.exploded:
self.exploded = True
msg = "boom"
raise RuntimeError(msg)

instrument = LoggingInstrument(
bootstrap_config=LoggingConfig(
logging_record_filters={"teardown_despite_error.target": (configured_filter,)},
),
)
root_logger = logging.getLogger()
existing_handlers = set(root_logger.handlers)
instrument.bootstrap()
exploding_handler = ExplodingHandler()
logging.getLogger().addHandler(exploding_handler)
(owned_handler,) = set(root_logger.handlers) - existing_handlers

try:
with pytest.raises(TeardownError):
instrument.teardown()
finally:
logging.getLogger().removeHandler(exploding_handler)
with patch.object(owned_handler, "close", side_effect=RuntimeError("boom")), pytest.raises(TeardownError):
instrument.teardown()

assert target_logger.filters == []

Expand Down
Loading