Skip to content
Closed
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
20 changes: 20 additions & 0 deletions shared/logging/src/airflow_shared/logging/structlog.py
Original file line number Diff line number Diff line change
Expand Up @@ -211,6 +211,25 @@ def redact_jwt(logger: Any, method_name: str, event_dict: EventDict) -> EventDic
return event_dict


def _normalize_positional_args(logger: Any, method_name: Any, event_dict: EventDict) -> EventDict:
"""
Re-wrap dict positional_args back into a tuple.

CPython's ``LogRecord.__init__`` unwraps a single-dict args tuple into a bare dict
(to support ``logging.debug("%(key)s", {"key": val})`` style formatting).
When ``pass_foreign_args=True``, structlog's ``ProcessorFormatter`` passes this bare dict
as ``positional_args``, but ``PositionalArgumentsFormatter`` expects a tuple and crashes
with ``KeyError`` when trying ``args[0]`` on a dict.

This processor normalizes the args back to a tuple so downstream processors handle them
correctly.
"""
args = event_dict.get("positional_args")
if isinstance(args, Mapping):
event_dict["positional_args"] = (args,)
return event_dict


def drop_positional_args(logger: Any, method_name: Any, event_dict: EventDict) -> EventDict:
event_dict.pop("positional_args", None)
return event_dict
Expand Down Expand Up @@ -253,6 +272,7 @@ def structlog_processors(
timestamper,
structlog.contextvars.merge_contextvars,
structlog.processors.add_log_level,
_normalize_positional_args,
structlog.stdlib.PositionalArgumentsFormatter(),
logger_name,
redact_jwt,
Expand Down
45 changes: 45 additions & 0 deletions shared/logging/tests/logging/test_structlog.py
Original file line number Diff line number Diff line change
Expand Up @@ -380,3 +380,48 @@ def test_logger_respects_configured_level(structlog_config):

written = sio.getvalue()
assert "[my_logger] Debug message\n" in written


class TestStdlibDictArgs:
"""Test that stdlib logging with dict args works correctly through structlog.

CPython's LogRecord.__init__ unwraps a single-dict args tuple into a bare dict.
When pass_foreign_args=True, structlog receives this bare dict as positional_args.
These tests verify the _normalize_positional_args processor handles this correctly.
See: https://github.com/apache/airflow/issues/62201
"""

def test_stdlib_dict_arg_with_percent_s(self, structlog_config):
"""Single dict arg with %s should format the dict as a string."""
with structlog_config(colors=False, log_format="%(message)s") as sio:
logging.getLogger("test").warning("Info message %s", {"a": 10})

assert "Info message {'a': 10}\n" == sio.getvalue()

def test_stdlib_dict_arg_with_named_format(self, structlog_config):
"""Single dict arg with %(name) formatting should use dict keys."""
with structlog_config(colors=False, log_format="%(message)s") as sio:
logging.getLogger("test").warning("a=%(a)d b=%(b)s", {"a": 1, "b": 2})

assert "a=1 b=2\n" == sio.getvalue()

def test_stdlib_empty_dict_arg(self, structlog_config):
"""Empty dict arg should be formatted as a string without error."""
with structlog_config(colors=False, log_format="%(message)s") as sio:
logging.getLogger("test").warning("Empty %s", {})

assert "Empty {}\n" == sio.getvalue()

def test_stdlib_multi_key_dict_arg(self, structlog_config):
"""Multi-key dict arg with %s should format the dict as a string."""
with structlog_config(colors=False, log_format="%(message)s") as sio:
logging.getLogger("test").warning("Dict %s", {"a": 10, "b": 20})

assert "Dict {'a': 10, 'b': 20}\n" == sio.getvalue()

def test_stdlib_normal_positional_args(self, structlog_config):
"""Normal positional args should continue to work."""
with structlog_config(colors=False, log_format="%(message)s") as sio:
logging.getLogger("test").warning("Hello %s %s", "world", "!")

assert "Hello world !\n" == sio.getvalue()