I want to implement wide logging with Python's structlog. I also want to provide some unit tests for that and I'm really struggling with how to use structlog with underlying stdlib logging. In general what I want to achieve is to have all logs nicely formatted into a simple JSON, with no nested keys, for example:
{
"msg": "some event",
"level": "warning",
"timestamp": "2026-03-09 19:01:20",
"user_id": 123,
"frequency": "some key"
// some other key-value pairs
}
Initial structlog config:
def configure_events() -> None:
processors = [
structlog.contextvars.merge_contextvars,
structlog.processors.add_log_level,
structlog.processors.TimeStamper(fmt="%Y-%m-%d %H:%M:%S", utc=False),
structlog.stdlib.render_to_log_kwargs,
structlog.stdlib.PositionalArgumentsFormatter(),
structlog.processors.JSONRenderer()
]
structlog.configure(
processors=processors,
wrapper_class=structlog.make_filtering_bound_logger("INFO"),
logger_factory=structlog.stdlib.LoggerFactory(),
cache_logger_on_first_use=True,
)
Test config
@pytest.fixture
def capture_logs():
emitted = []
def capture(*args):
event_dict = args[-1]
emitted.append(event_dict)
return event_dict
with patch("structlog.processors.JSONRenderer.__call__", capture):
yield emitted
When I run test like this:
def test_event_emits_structured_wide_event(capture_logs):
configure_events()
logger = structlog.get_logger()
logger.info("some event", user_id=123)
assert len(capture_logs) == 1
log = capture_logs[0]
assert log["msg"] == "some event"
assert log["extra"]["level"] == "info"
assert log["extra"]["user_id"] == 123
the test passes fine, but the level and user_id are under the extra key, which is understandable, considering how logging takes arguments.
But I don't want it this way, I want all keys as a simple JSON. I tried many different approaches, and eventually I came up with adding custom processor, which flattens value of extra key, so after implementing this, my structlog config looks like this:
def configure_events() -> None:
def _flatten_extra(logger, method_name, event_dict):
if "extra" in event_dict:
extra = event_dict.pop("extra")
if not isinstance(extra, dict):
raise ValueError("Value of 'extra' is not of dict type.")
event_dict.update(extra)
return event_dict
processors = [
structlog.contextvars.merge_contextvars,
structlog.processors.add_log_level,
structlog.processors.TimeStamper(fmt="%Y-%m-%d %H:%M:%S", utc=False),
structlog.stdlib.render_to_log_kwargs,
structlog.stdlib.PositionalArgumentsFormatter(),
_flatten_extra,
structlog.processors.JSONRenderer()
]
structlog.configure(
processors=processors,
wrapper_class=structlog.make_filtering_bound_logger("INFO"),
logger_factory=structlog.stdlib.LoggerFactory(),
cache_logger_on_first_use=True,
)
Then after I remove reference to extra in my assertions, test passes nicely.
But this does not work with WARNING. I have a test like this:
def test_event_can_use_warning_level(capture_logs):
configure_events()
logger = structlog.get_logger()
logger.warning("check_failed", user_id=222, reason="timeout")
assert capture_logs[0]["level"] == "warning"
The test fails due to TypeError: Logger._log() got an unexpected keyword argument 'user_id', which is already strange to me why can't I pass arguments the same as for INFO, but ok, here's what I tested:
def test_event_can_use_warning_level(capture_logs):
configure_events()
logger = structlog.get_logger()
extra = {"user_id": 222, "reason": "timeout"}
logger.warning("check_failed", extra=extra)
assert capture_logs[0]["level"] == "warning"
And the result of this test brings me to the main confusion, it fails due to TypeError: Logger._log() got multiple values for argument 'level'. As I understand stdlib logging adds to the log message level keyword derived from the method name, but why does it behave differently between INFO and WARNING???
I'm totally lost here and out of ideas. What is it that I'm missing or misconfiguring?