From 345ef82864a032b032408a1e91a9ac6cd474c4be Mon Sep 17 00:00:00 2001 From: rob dailey Date: Fri, 20 Oct 2023 11:11:42 -0400 Subject: [PATCH 01/16] Support for `asyncio` correct callsite params --- src/structlog/_frames.py | 6 +++++- src/structlog/_log_levels.py | 14 ++++++++++++-- src/structlog/contextvars.py | 2 ++ src/structlog/stdlib.py | 5 ++++- tests/test_processors.py | 17 ++++++++--------- 5 files changed, 31 insertions(+), 13 deletions(-) diff --git a/src/structlog/_frames.py b/src/structlog/_frames.py index 7a5fb6c3..a6e5342e 100644 --- a/src/structlog/_frames.py +++ b/src/structlog/_frames.py @@ -8,10 +8,13 @@ import sys import traceback +import contextvars + from io import StringIO from types import FrameType from .typing import ExcInfo +from .contextvars import async_calling_stack def _format_exception(exc_info: ExcInfo) -> str: @@ -49,8 +52,9 @@ def _find_first_app_frame_and_name( tuple of (frame, name) """ + ctx = contextvars.copy_context() ignores = ["structlog"] + (additional_ignores or []) - f = sys._getframe() + f = ctx.get(async_calling_stack) if async_calling_stack in ctx else sys._getframe() name = f.f_globals.get("__name__") or "?" while any(tuple(name.startswith(i) for i in ignores)): if f.f_back is None: diff --git a/src/structlog/_log_levels.py b/src/structlog/_log_levels.py index b2e721b6..e16a7006 100644 --- a/src/structlog/_log_levels.py +++ b/src/structlog/_log_levels.py @@ -18,6 +18,7 @@ from ._base import BoundLoggerBase from .typing import EventDict, FilteringBoundLogger +from .contextvars import async_calling_stack # Adapted from the stdlib @@ -96,11 +97,15 @@ async def aexception( if kw.get("exc_info", True) is True: kw["exc_info"] = sys.exc_info() + _scs_token = async_calling_stack.set(sys._getframe().f_back) ctx = contextvars.copy_context() - return await asyncio.get_running_loop().run_in_executor( + _run = await asyncio.get_running_loop().run_in_executor( None, lambda: ctx.run(lambda: self.error(event, *args, **kw)), ) + async_calling_stack.reset(_scs_token) + + return _run def make_filtering_bound_logger(min_level: int) -> type[FilteringBoundLogger]: @@ -173,6 +178,7 @@ async def ameth(self: Any, event: str, *args: Any, **kw: Any) -> Any: if args: event = event % args + _scs_token = async_calling_stack.set(sys._getframe().f_back) ctx = contextvars.copy_context() await asyncio.get_running_loop().run_in_executor( None, @@ -180,6 +186,7 @@ async def ameth(self: Any, event: str, *args: Any, **kw: Any) -> Any: lambda: self._proxy_to_logger(name, event, **kw) ), ) + async_calling_stack.reset(_scs_token) meth.__name__ = name ameth.__name__ = f"a{name}" @@ -205,11 +212,14 @@ async def alog( if args: event = event % args + _scs_token = async_calling_stack.set(sys._getframe().f_back) ctx = contextvars.copy_context() - return await asyncio.get_running_loop().run_in_executor( + _run = await asyncio.get_running_loop().run_in_executor( None, lambda: ctx.run(lambda: self._proxy_to_logger(name, event, **kw)), ) + async_calling_stack.reset(_scs_token) + return _run meths: dict[str, Callable[..., Any]] = {"log": log, "alog": alog} for lvl, name in _LEVEL_TO_NAME.items(): diff --git a/src/structlog/contextvars.py b/src/structlog/contextvars.py index ebb5941d..39ec83d1 100644 --- a/src/structlog/contextvars.py +++ b/src/structlog/contextvars.py @@ -30,6 +30,8 @@ STRUCTLOG_KEY_PREFIX = "structlog_" STRUCTLOG_KEY_PREFIX_LEN = len(STRUCTLOG_KEY_PREFIX) +async_calling_stack = contextvars.ContextVar("async_calling_stack") + # For proper isolation, we have to use a dict of ContextVars instead of a # single ContextVar with a dict. # See https://github.com/hynek/structlog/pull/302 for details. diff --git a/src/structlog/stdlib.py b/src/structlog/stdlib.py index 9de32fd9..685290cc 100644 --- a/src/structlog/stdlib.py +++ b/src/structlog/stdlib.py @@ -24,7 +24,7 @@ from ._base import BoundLoggerBase from ._frames import _find_first_app_frame_and_name, _format_stack from ._log_levels import _LEVEL_TO_NAME, _NAME_TO_LEVEL, add_log_level -from .contextvars import merge_contextvars +from .contextvars import merge_contextvars, async_calling_stack from .exceptions import DropEvent from .processors import StackInfoRenderer from .typing import Context, EventDict, ExcInfo, Processor, WrappedLogger @@ -588,6 +588,7 @@ async def _dispatch_to_sync( """ Merge contextvars and log using the sync logger in a thread pool. """ + _scs_token = async_calling_stack.set(sys._getframe().f_back.f_back) ctx = contextvars.copy_context() await asyncio.get_running_loop().run_in_executor( @@ -595,6 +596,8 @@ async def _dispatch_to_sync( lambda: ctx.run(lambda: meth(event, *args, **kw)), ) + async_calling_stack.reset(_scs_token) + async def debug(self, event: str, *args: Any, **kw: Any) -> None: await self._dispatch_to_sync(self.sync_bl.debug, event, args, kw) diff --git a/tests/test_processors.py b/tests/test_processors.py index c8628302..0e9a1cab 100644 --- a/tests/test_processors.py +++ b/tests/test_processors.py @@ -823,12 +823,6 @@ def test_all_parameters(self) -> None: } assert self.parameter_strings == self.get_callsite_parameters().keys() - @pytest.mark.xfail( - reason=( - "CallsiteParameterAdder cannot " - "determine the callsite for async calls." - ) - ) @pytest.mark.asyncio() async def test_async(self) -> None: """ @@ -850,12 +844,17 @@ def __init__(self): logger = structlog.stdlib.get_logger() + # These are different when running under async + exclude_keys = ['thread', 'thread_name'] + callsite_params = self.get_callsite_parameters() await logger.info("baz") + logger_params = json.loads(string_io.getvalue()) - assert {"event": "baz", **callsite_params} == json.loads( - string_io.getvalue() - ) + [callsite_params.pop(key) for key in exclude_keys] + [logger_params.pop(key) for key in exclude_keys] + + assert {"event": "baz", **callsite_params} == logger_params def test_additional_ignores(self, monkeypatch: pytest.MonkeyPatch) -> None: """ From aca3046e7463174df4ef1f7abb7eeef6aa7190f0 Mon Sep 17 00:00:00 2001 From: rob dailey Date: Fri, 20 Oct 2023 11:20:33 -0400 Subject: [PATCH 02/16] Support for `asyncio` correct callsite params --- src/structlog/processors.py | 4 ---- 1 file changed, 4 deletions(-) diff --git a/src/structlog/processors.py b/src/structlog/processors.py index 7b2377a7..b4063332 100644 --- a/src/structlog/processors.py +++ b/src/structlog/processors.py @@ -734,10 +734,6 @@ class CallsiteParameterAdder: dictionaries with information such as the function name, line number and filename that an event dictionary originated from. - .. warning:: - This processor cannot detect the correct callsite for invocation of - async functions. - If the event dictionary has an embedded `logging.LogRecord` object and did not originate from *structlog* then the callsite information will be determined from the `logging.LogRecord` object. For event dictionaries From c520e26993deba76196c457c78bb875fd831f242 Mon Sep 17 00:00:00 2001 From: rob dailey Date: Fri, 20 Oct 2023 11:30:00 -0400 Subject: [PATCH 03/16] Support for `asyncio` correct callsite params --- CHANGELOG.md | 2 ++ src/structlog/_frames.py | 12 ++++++++---- src/structlog/_log_levels.py | 2 +- src/structlog/stdlib.py | 3 ++- 4 files changed, 13 insertions(+), 6 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index cfdd8222..57f86b6a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -17,6 +17,8 @@ You can find our backwards-compatibility policy [here](https://github.com/hynek/ ### Fixed +- `AsyncBoundLogger` now properly supports callsite parameters. + - The return value from `get_logger()` (a `BoundLoggerLazyProxy`) now passes `isinstance`-checks against `structlog.typing.BindableLogger` on Python 3.12. [#561](https://github.com/hynek/structlog/issues/561) diff --git a/src/structlog/_frames.py b/src/structlog/_frames.py index a6e5342e..61777cb1 100644 --- a/src/structlog/_frames.py +++ b/src/structlog/_frames.py @@ -5,16 +5,15 @@ from __future__ import annotations +import contextvars import sys import traceback -import contextvars - from io import StringIO from types import FrameType -from .typing import ExcInfo from .contextvars import async_calling_stack +from .typing import ExcInfo def _format_exception(exc_info: ExcInfo) -> str: @@ -53,8 +52,13 @@ def _find_first_app_frame_and_name( tuple of (frame, name) """ ctx = contextvars.copy_context() + ctx = contextvars.copy_context() ignores = ["structlog"] + (additional_ignores or []) - f = ctx.get(async_calling_stack) if async_calling_stack in ctx else sys._getframe() + f = ( + ctx.get(async_calling_stack) + if async_calling_stack in ctx + else sys._getframe() + ) name = f.f_globals.get("__name__") or "?" while any(tuple(name.startswith(i) for i in ignores)): if f.f_back is None: diff --git a/src/structlog/_log_levels.py b/src/structlog/_log_levels.py index e16a7006..056e46e0 100644 --- a/src/structlog/_log_levels.py +++ b/src/structlog/_log_levels.py @@ -17,8 +17,8 @@ from typing import Any, Callable from ._base import BoundLoggerBase -from .typing import EventDict, FilteringBoundLogger from .contextvars import async_calling_stack +from .typing import EventDict, FilteringBoundLogger # Adapted from the stdlib diff --git a/src/structlog/stdlib.py b/src/structlog/stdlib.py index 685290cc..6796e28c 100644 --- a/src/structlog/stdlib.py +++ b/src/structlog/stdlib.py @@ -24,7 +24,7 @@ from ._base import BoundLoggerBase from ._frames import _find_first_app_frame_and_name, _format_stack from ._log_levels import _LEVEL_TO_NAME, _NAME_TO_LEVEL, add_log_level -from .contextvars import merge_contextvars, async_calling_stack +from .contextvars import async_calling_stack, merge_contextvars from .exceptions import DropEvent from .processors import StackInfoRenderer from .typing import Context, EventDict, ExcInfo, Processor, WrappedLogger @@ -589,6 +589,7 @@ async def _dispatch_to_sync( Merge contextvars and log using the sync logger in a thread pool. """ _scs_token = async_calling_stack.set(sys._getframe().f_back.f_back) + _scs_token = async_calling_stack.set(sys._getframe().f_back.f_back) ctx = contextvars.copy_context() await asyncio.get_running_loop().run_in_executor( From 356867a09ede1e0a78a88b82675967935d36ef2a Mon Sep 17 00:00:00 2001 From: rob dailey Date: Fri, 20 Oct 2023 11:43:19 -0400 Subject: [PATCH 04/16] Added `versionchanged` tags --- src/structlog/_log_levels.py | 12 ++++++++++++ src/structlog/contextvars.py | 2 ++ src/structlog/stdlib.py | 3 ++- 3 files changed, 16 insertions(+), 1 deletion(-) diff --git a/src/structlog/_log_levels.py b/src/structlog/_log_levels.py index 056e46e0..fc98d1fc 100644 --- a/src/structlog/_log_levels.py +++ b/src/structlog/_log_levels.py @@ -92,6 +92,10 @@ def exception( async def aexception( self: FilteringBoundLogger, event: str, *args: Any, **kw: Any ) -> Any: + """ + .. versionchanged:: 23.3.0 + Implimented `ContextVar` for holding and resetting async calling stack + """ # Exception info has to be extracted this early, because it is no longer # available once control is passed to the executor. if kw.get("exc_info", True) is True: @@ -175,6 +179,10 @@ def meth(self: Any, event: str, *args: Any, **kw: Any) -> Any: return self._proxy_to_logger(name, event % args, **kw) async def ameth(self: Any, event: str, *args: Any, **kw: Any) -> Any: + """ + .. versionchanged:: 23.3.0 + Implimented `ContextVar` for holding and resetting async calling stack + """ if args: event = event % args @@ -206,6 +214,10 @@ def log(self: Any, level: int, event: str, *args: Any, **kw: Any) -> Any: async def alog( self: Any, level: int, event: str, *args: Any, **kw: Any ) -> Any: + """ + .. versionchanged:: 23.3.0 + Implimented `ContextVar` for holding and resetting async calling stack + """ if level < min_level: return None name = _LEVEL_TO_NAME[level] diff --git a/src/structlog/contextvars.py b/src/structlog/contextvars.py index 39ec83d1..7bae7394 100644 --- a/src/structlog/contextvars.py +++ b/src/structlog/contextvars.py @@ -11,6 +11,8 @@ .. versionchanged:: 21.1.0 Reimplemented without using a single dict as context carrier for improved isolation. Every key-value pair is a separate `contextvars.ContextVar` now. +.. versionchanged:: 23.3.0 + Implimented `ContextVar` for holding and resetting async calling stack See :doc:`contextvars`. """ diff --git a/src/structlog/stdlib.py b/src/structlog/stdlib.py index 6796e28c..7f70173d 100644 --- a/src/structlog/stdlib.py +++ b/src/structlog/stdlib.py @@ -587,9 +587,10 @@ async def _dispatch_to_sync( ) -> None: """ Merge contextvars and log using the sync logger in a thread pool. + .. versionchanged:: 23.3.0 + Implimented `ContextVar` for holding and resetting async calling stack """ _scs_token = async_calling_stack.set(sys._getframe().f_back.f_back) - _scs_token = async_calling_stack.set(sys._getframe().f_back.f_back) ctx = contextvars.copy_context() await asyncio.get_running_loop().run_in_executor( From d9eef09bfdb0dcf2a68a5000e3ca6ba8fc1fd129 Mon Sep 17 00:00:00 2001 From: "pre-commit-ci[bot]" <66853113+pre-commit-ci[bot]@users.noreply.github.com> Date: Fri, 20 Oct 2023 15:43:45 +0000 Subject: [PATCH 05/16] [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci --- src/structlog/_log_levels.py | 6 +++--- tests/test_processors.py | 2 +- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/src/structlog/_log_levels.py b/src/structlog/_log_levels.py index fc98d1fc..1d54c82c 100644 --- a/src/structlog/_log_levels.py +++ b/src/structlog/_log_levels.py @@ -92,7 +92,7 @@ def exception( async def aexception( self: FilteringBoundLogger, event: str, *args: Any, **kw: Any ) -> Any: - """ + """ .. versionchanged:: 23.3.0 Implimented `ContextVar` for holding and resetting async calling stack """ @@ -179,7 +179,7 @@ def meth(self: Any, event: str, *args: Any, **kw: Any) -> Any: return self._proxy_to_logger(name, event % args, **kw) async def ameth(self: Any, event: str, *args: Any, **kw: Any) -> Any: - """ + """ .. versionchanged:: 23.3.0 Implimented `ContextVar` for holding and resetting async calling stack """ @@ -214,7 +214,7 @@ def log(self: Any, level: int, event: str, *args: Any, **kw: Any) -> Any: async def alog( self: Any, level: int, event: str, *args: Any, **kw: Any ) -> Any: - """ + """ .. versionchanged:: 23.3.0 Implimented `ContextVar` for holding and resetting async calling stack """ diff --git a/tests/test_processors.py b/tests/test_processors.py index 0e9a1cab..eb289518 100644 --- a/tests/test_processors.py +++ b/tests/test_processors.py @@ -845,7 +845,7 @@ def __init__(self): logger = structlog.stdlib.get_logger() # These are different when running under async - exclude_keys = ['thread', 'thread_name'] + exclude_keys = ["thread", "thread_name"] callsite_params = self.get_callsite_parameters() await logger.info("baz") From 1429eb321c41727040d5485ccfc44e3cb9435186 Mon Sep 17 00:00:00 2001 From: rob dailey Date: Fri, 20 Oct 2023 12:07:54 -0400 Subject: [PATCH 06/16] Typing additions and corrections --- src/structlog/_frames.py | 9 ++++----- src/structlog/contextvars.py | 4 ++-- src/structlog/stdlib.py | 2 +- 3 files changed, 7 insertions(+), 8 deletions(-) diff --git a/src/structlog/_frames.py b/src/structlog/_frames.py index 61777cb1..ce232b15 100644 --- a/src/structlog/_frames.py +++ b/src/structlog/_frames.py @@ -52,21 +52,20 @@ def _find_first_app_frame_and_name( tuple of (frame, name) """ ctx = contextvars.copy_context() - ctx = contextvars.copy_context() ignores = ["structlog"] + (additional_ignores or []) f = ( ctx.get(async_calling_stack) if async_calling_stack in ctx else sys._getframe() ) - name = f.f_globals.get("__name__") or "?" + name = f.f_globals.get("__name__") or "?" # type: ignore[union-attr] while any(tuple(name.startswith(i) for i in ignores)): - if f.f_back is None: + if f.f_back is None: # type: ignore[union-attr] name = "?" break - f = f.f_back + f = f.f_back # type: ignore[union-attr] name = f.f_globals.get("__name__") or "?" - return f, name + return f, name # type: ignore[return-value] def _format_stack(frame: FrameType) -> str: diff --git a/src/structlog/contextvars.py b/src/structlog/contextvars.py index 7bae7394..40219c4d 100644 --- a/src/structlog/contextvars.py +++ b/src/structlog/contextvars.py @@ -12,7 +12,7 @@ Reimplemented without using a single dict as context carrier for improved isolation. Every key-value pair is a separate `contextvars.ContextVar` now. .. versionchanged:: 23.3.0 - Implimented `ContextVar` for holding and resetting async calling stack + Implimented `contextvars.ContextVar` for holding and resetting async calling stack See :doc:`contextvars`. """ @@ -32,7 +32,7 @@ STRUCTLOG_KEY_PREFIX = "structlog_" STRUCTLOG_KEY_PREFIX_LEN = len(STRUCTLOG_KEY_PREFIX) -async_calling_stack = contextvars.ContextVar("async_calling_stack") +async_calling_stack: contextvars.ContextVar[Any] = contextvars.ContextVar("async_calling_stack") # For proper isolation, we have to use a dict of ContextVars instead of a # single ContextVar with a dict. diff --git a/src/structlog/stdlib.py b/src/structlog/stdlib.py index 7f70173d..8edd4018 100644 --- a/src/structlog/stdlib.py +++ b/src/structlog/stdlib.py @@ -590,7 +590,7 @@ async def _dispatch_to_sync( .. versionchanged:: 23.3.0 Implimented `ContextVar` for holding and resetting async calling stack """ - _scs_token = async_calling_stack.set(sys._getframe().f_back.f_back) + _scs_token = async_calling_stack.set(sys._getframe().f_back.f_back) # type: ignore[union-attr] ctx = contextvars.copy_context() await asyncio.get_running_loop().run_in_executor( From a3013ac58e90876170b564c827d2c323109c8569 Mon Sep 17 00:00:00 2001 From: "pre-commit-ci[bot]" <66853113+pre-commit-ci[bot]@users.noreply.github.com> Date: Fri, 20 Oct 2023 16:08:05 +0000 Subject: [PATCH 07/16] [pre-commit.ci] auto fixes from pre-commit.com hooks for more information, see https://pre-commit.ci --- src/structlog/_frames.py | 6 +++--- src/structlog/contextvars.py | 4 +++- src/structlog/stdlib.py | 2 +- 3 files changed, 7 insertions(+), 5 deletions(-) diff --git a/src/structlog/_frames.py b/src/structlog/_frames.py index ce232b15..d7b5d752 100644 --- a/src/structlog/_frames.py +++ b/src/structlog/_frames.py @@ -58,12 +58,12 @@ def _find_first_app_frame_and_name( if async_calling_stack in ctx else sys._getframe() ) - name = f.f_globals.get("__name__") or "?" # type: ignore[union-attr] + name = f.f_globals.get("__name__") or "?" # type: ignore[union-attr] while any(tuple(name.startswith(i) for i in ignores)): - if f.f_back is None: # type: ignore[union-attr] + if f.f_back is None: # type: ignore[union-attr] name = "?" break - f = f.f_back # type: ignore[union-attr] + f = f.f_back # type: ignore[union-attr] name = f.f_globals.get("__name__") or "?" return f, name # type: ignore[return-value] diff --git a/src/structlog/contextvars.py b/src/structlog/contextvars.py index 40219c4d..46d7ce51 100644 --- a/src/structlog/contextvars.py +++ b/src/structlog/contextvars.py @@ -32,7 +32,9 @@ STRUCTLOG_KEY_PREFIX = "structlog_" STRUCTLOG_KEY_PREFIX_LEN = len(STRUCTLOG_KEY_PREFIX) -async_calling_stack: contextvars.ContextVar[Any] = contextvars.ContextVar("async_calling_stack") +async_calling_stack: contextvars.ContextVar[Any] = contextvars.ContextVar( + "async_calling_stack" +) # For proper isolation, we have to use a dict of ContextVars instead of a # single ContextVar with a dict. diff --git a/src/structlog/stdlib.py b/src/structlog/stdlib.py index 8edd4018..c5233a70 100644 --- a/src/structlog/stdlib.py +++ b/src/structlog/stdlib.py @@ -590,7 +590,7 @@ async def _dispatch_to_sync( .. versionchanged:: 23.3.0 Implimented `ContextVar` for holding and resetting async calling stack """ - _scs_token = async_calling_stack.set(sys._getframe().f_back.f_back) # type: ignore[union-attr] + _scs_token = async_calling_stack.set(sys._getframe().f_back.f_back) # type: ignore[union-attr] ctx = contextvars.copy_context() await asyncio.get_running_loop().run_in_executor( From 761718d5fc95886d9e243695d78feeaf4e6942b0 Mon Sep 17 00:00:00 2001 From: rob dailey Date: Fri, 20 Oct 2023 12:10:58 -0400 Subject: [PATCH 08/16] Spelling corrections --- src/structlog/_log_levels.py | 6 +++--- src/structlog/contextvars.py | 2 +- src/structlog/stdlib.py | 2 +- 3 files changed, 5 insertions(+), 5 deletions(-) diff --git a/src/structlog/_log_levels.py b/src/structlog/_log_levels.py index 1d54c82c..19a2e335 100644 --- a/src/structlog/_log_levels.py +++ b/src/structlog/_log_levels.py @@ -94,7 +94,7 @@ async def aexception( ) -> Any: """ .. versionchanged:: 23.3.0 - Implimented `ContextVar` for holding and resetting async calling stack + Implemented `contextvars.ContextVar` for holding and resetting async calling stack """ # Exception info has to be extracted this early, because it is no longer # available once control is passed to the executor. @@ -181,7 +181,7 @@ def meth(self: Any, event: str, *args: Any, **kw: Any) -> Any: async def ameth(self: Any, event: str, *args: Any, **kw: Any) -> Any: """ .. versionchanged:: 23.3.0 - Implimented `ContextVar` for holding and resetting async calling stack + Implemented `contextvars.ContextVar` for holding and resetting async calling stack """ if args: event = event % args @@ -216,7 +216,7 @@ async def alog( ) -> Any: """ .. versionchanged:: 23.3.0 - Implimented `ContextVar` for holding and resetting async calling stack + Implemented `contextvars.ContextVar` for holding and resetting async calling stack """ if level < min_level: return None diff --git a/src/structlog/contextvars.py b/src/structlog/contextvars.py index 46d7ce51..05a1dc67 100644 --- a/src/structlog/contextvars.py +++ b/src/structlog/contextvars.py @@ -12,7 +12,7 @@ Reimplemented without using a single dict as context carrier for improved isolation. Every key-value pair is a separate `contextvars.ContextVar` now. .. versionchanged:: 23.3.0 - Implimented `contextvars.ContextVar` for holding and resetting async calling stack + Implemented `contextvars.ContextVar` for holding and resetting async calling stack See :doc:`contextvars`. """ diff --git a/src/structlog/stdlib.py b/src/structlog/stdlib.py index c5233a70..eda3c4c8 100644 --- a/src/structlog/stdlib.py +++ b/src/structlog/stdlib.py @@ -588,7 +588,7 @@ async def _dispatch_to_sync( """ Merge contextvars and log using the sync logger in a thread pool. .. versionchanged:: 23.3.0 - Implimented `ContextVar` for holding and resetting async calling stack + Implemented `contextvars.ContextVar` for holding and resetting async calling stack """ _scs_token = async_calling_stack.set(sys._getframe().f_back.f_back) # type: ignore[union-attr] ctx = contextvars.copy_context() From 241df14a599edc5c32ee468d5ca29fc9bba16194 Mon Sep 17 00:00:00 2001 From: rob dailey Date: Sat, 21 Oct 2023 12:50:58 -0400 Subject: [PATCH 09/16] Simplified logic and removed unused code --- src/structlog/_frames.py | 16 +++++----------- 1 file changed, 5 insertions(+), 11 deletions(-) diff --git a/src/structlog/_frames.py b/src/structlog/_frames.py index d7b5d752..edf513b2 100644 --- a/src/structlog/_frames.py +++ b/src/structlog/_frames.py @@ -5,7 +5,6 @@ from __future__ import annotations -import contextvars import sys import traceback @@ -51,21 +50,16 @@ def _find_first_app_frame_and_name( tuple of (frame, name) """ - ctx = contextvars.copy_context() ignores = ["structlog"] + (additional_ignores or []) - f = ( - ctx.get(async_calling_stack) - if async_calling_stack in ctx - else sys._getframe() - ) - name = f.f_globals.get("__name__") or "?" # type: ignore[union-attr] + f = async_calling_stack.get(sys._getframe()) + name = f.f_globals.get("__name__") or "?" while any(tuple(name.startswith(i) for i in ignores)): - if f.f_back is None: # type: ignore[union-attr] + if f.f_back is None: name = "?" break - f = f.f_back # type: ignore[union-attr] + f = f.f_back name = f.f_globals.get("__name__") or "?" - return f, name # type: ignore[return-value] + return f, name def _format_stack(frame: FrameType) -> str: From 8dc4d1fb75c8c8861d6ff63cd32f8b7123397a75 Mon Sep 17 00:00:00 2001 From: rob dailey Date: Sat, 21 Oct 2023 12:51:21 -0400 Subject: [PATCH 10/16] Corrected typing --- src/structlog/contextvars.py | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/src/structlog/contextvars.py b/src/structlog/contextvars.py index 05a1dc67..3006b5cb 100644 --- a/src/structlog/contextvars.py +++ b/src/structlog/contextvars.py @@ -12,7 +12,7 @@ Reimplemented without using a single dict as context carrier for improved isolation. Every key-value pair is a separate `contextvars.ContextVar` now. .. versionchanged:: 23.3.0 - Implemented `contextvars.ContextVar` for holding and resetting async calling stack + Callsite parameters are now also collected under asyncio. See :doc:`contextvars`. """ @@ -22,6 +22,7 @@ import contextlib import contextvars +from types import FrameType from typing import Any, Generator, Mapping import structlog @@ -32,9 +33,9 @@ STRUCTLOG_KEY_PREFIX = "structlog_" STRUCTLOG_KEY_PREFIX_LEN = len(STRUCTLOG_KEY_PREFIX) -async_calling_stack: contextvars.ContextVar[Any] = contextvars.ContextVar( - "async_calling_stack" -) +async_calling_stack: contextvars.ContextVar[ + FrameType +] = contextvars.ContextVar("async_calling_stack") # For proper isolation, we have to use a dict of ContextVars instead of a # single ContextVar with a dict. From 42a85ab3fd7ce46c1c085b03646a64aff03f8bf9 Mon Sep 17 00:00:00 2001 From: rob dailey Date: Sat, 21 Oct 2023 12:51:41 -0400 Subject: [PATCH 11/16] Ensure context is cleared even if logging failure --- src/structlog/_log_levels.py | 58 ++++++++++++++++++++---------------- src/structlog/stdlib.py | 17 ++++++----- 2 files changed, 42 insertions(+), 33 deletions(-) diff --git a/src/structlog/_log_levels.py b/src/structlog/_log_levels.py index 19a2e335..2c90b0fd 100644 --- a/src/structlog/_log_levels.py +++ b/src/structlog/_log_levels.py @@ -94,22 +94,24 @@ async def aexception( ) -> Any: """ .. versionchanged:: 23.3.0 - Implemented `contextvars.ContextVar` for holding and resetting async calling stack + Callsite parameters are now also collected under asyncio. """ # Exception info has to be extracted this early, because it is no longer # available once control is passed to the executor. if kw.get("exc_info", True) is True: kw["exc_info"] = sys.exc_info() - _scs_token = async_calling_stack.set(sys._getframe().f_back) + scs_token = async_calling_stack.set(sys._getframe().f_back) # type: ignore[arg-type] ctx = contextvars.copy_context() - _run = await asyncio.get_running_loop().run_in_executor( - None, - lambda: ctx.run(lambda: self.error(event, *args, **kw)), - ) - async_calling_stack.reset(_scs_token) + try: + runner = await asyncio.get_running_loop().run_in_executor( + None, + lambda: ctx.run(lambda: self.error(event, *args, **kw)), + ) + finally: + async_calling_stack.reset(scs_token) - return _run + return runner def make_filtering_bound_logger(min_level: int) -> type[FilteringBoundLogger]: @@ -181,20 +183,22 @@ def meth(self: Any, event: str, *args: Any, **kw: Any) -> Any: async def ameth(self: Any, event: str, *args: Any, **kw: Any) -> Any: """ .. versionchanged:: 23.3.0 - Implemented `contextvars.ContextVar` for holding and resetting async calling stack + Callsite parameters are now also collected under asyncio. """ if args: event = event % args - _scs_token = async_calling_stack.set(sys._getframe().f_back) + scs_token = async_calling_stack.set(sys._getframe().f_back) # type: ignore[arg-type] ctx = contextvars.copy_context() - await asyncio.get_running_loop().run_in_executor( - None, - lambda: ctx.run( - lambda: self._proxy_to_logger(name, event, **kw) - ), - ) - async_calling_stack.reset(_scs_token) + try: + await asyncio.get_running_loop().run_in_executor( + None, + lambda: ctx.run( + lambda: self._proxy_to_logger(name, event, **kw) + ), + ) + finally: + async_calling_stack.reset(scs_token) meth.__name__ = name ameth.__name__ = f"a{name}" @@ -216,7 +220,7 @@ async def alog( ) -> Any: """ .. versionchanged:: 23.3.0 - Implemented `contextvars.ContextVar` for holding and resetting async calling stack + Callsite parameters are now also collected under asyncio. """ if level < min_level: return None @@ -224,14 +228,18 @@ async def alog( if args: event = event % args - _scs_token = async_calling_stack.set(sys._getframe().f_back) + scs_token = async_calling_stack.set(sys._getframe().f_back) # type: ignore[arg-type] ctx = contextvars.copy_context() - _run = await asyncio.get_running_loop().run_in_executor( - None, - lambda: ctx.run(lambda: self._proxy_to_logger(name, event, **kw)), - ) - async_calling_stack.reset(_scs_token) - return _run + try: + runner = await asyncio.get_running_loop().run_in_executor( + None, + lambda: ctx.run( + lambda: self._proxy_to_logger(name, event, **kw) + ), + ) + finally: + async_calling_stack.reset(scs_token) + return runner meths: dict[str, Callable[..., Any]] = {"log": log, "alog": alog} for lvl, name in _LEVEL_TO_NAME.items(): diff --git a/src/structlog/stdlib.py b/src/structlog/stdlib.py index eda3c4c8..959cb6a4 100644 --- a/src/structlog/stdlib.py +++ b/src/structlog/stdlib.py @@ -588,17 +588,18 @@ async def _dispatch_to_sync( """ Merge contextvars and log using the sync logger in a thread pool. .. versionchanged:: 23.3.0 - Implemented `contextvars.ContextVar` for holding and resetting async calling stack + Callsite parameters are now also collected under asyncio. """ - _scs_token = async_calling_stack.set(sys._getframe().f_back.f_back) # type: ignore[union-attr] + scs_token = async_calling_stack.set(sys._getframe().f_back.f_back) # type: ignore[union-attr, arg-type, unused-ignore] ctx = contextvars.copy_context() - await asyncio.get_running_loop().run_in_executor( - self._executor, - lambda: ctx.run(lambda: meth(event, *args, **kw)), - ) - - async_calling_stack.reset(_scs_token) + try: + await asyncio.get_running_loop().run_in_executor( + self._executor, + lambda: ctx.run(lambda: meth(event, *args, **kw)), + ) + finally: + async_calling_stack.reset(scs_token) async def debug(self, event: str, *args: Any, **kw: Any) -> None: await self._dispatch_to_sync(self.sync_bl.debug, event, args, kw) From 9a8ab6a3cf82f61c9c9f81be7604406a0d0e3459 Mon Sep 17 00:00:00 2001 From: rob dailey Date: Sun, 29 Oct 2023 18:23:15 -0400 Subject: [PATCH 12/16] Renamed async contextvar to match project naming convention --- src/structlog/_frames.py | 4 ++-- src/structlog/_log_levels.py | 14 +++++++------- src/structlog/contextvars.py | 4 ++-- src/structlog/stdlib.py | 6 +++--- 4 files changed, 14 insertions(+), 14 deletions(-) diff --git a/src/structlog/_frames.py b/src/structlog/_frames.py index edf513b2..51346d2f 100644 --- a/src/structlog/_frames.py +++ b/src/structlog/_frames.py @@ -11,7 +11,7 @@ from io import StringIO from types import FrameType -from .contextvars import async_calling_stack +from .contextvars import _ASYNC_CALLING_STACK from .typing import ExcInfo @@ -51,7 +51,7 @@ def _find_first_app_frame_and_name( tuple of (frame, name) """ ignores = ["structlog"] + (additional_ignores or []) - f = async_calling_stack.get(sys._getframe()) + f = _ASYNC_CALLING_STACK.get(sys._getframe()) name = f.f_globals.get("__name__") or "?" while any(tuple(name.startswith(i) for i in ignores)): if f.f_back is None: diff --git a/src/structlog/_log_levels.py b/src/structlog/_log_levels.py index 2c90b0fd..be132fcb 100644 --- a/src/structlog/_log_levels.py +++ b/src/structlog/_log_levels.py @@ -17,7 +17,7 @@ from typing import Any, Callable from ._base import BoundLoggerBase -from .contextvars import async_calling_stack +from .contextvars import _ASYNC_CALLING_STACK from .typing import EventDict, FilteringBoundLogger @@ -101,7 +101,7 @@ async def aexception( if kw.get("exc_info", True) is True: kw["exc_info"] = sys.exc_info() - scs_token = async_calling_stack.set(sys._getframe().f_back) # type: ignore[arg-type] + scs_token = _ASYNC_CALLING_STACK.set(sys._getframe().f_back) # type: ignore[arg-type] ctx = contextvars.copy_context() try: runner = await asyncio.get_running_loop().run_in_executor( @@ -109,7 +109,7 @@ async def aexception( lambda: ctx.run(lambda: self.error(event, *args, **kw)), ) finally: - async_calling_stack.reset(scs_token) + _ASYNC_CALLING_STACK.reset(scs_token) return runner @@ -188,7 +188,7 @@ async def ameth(self: Any, event: str, *args: Any, **kw: Any) -> Any: if args: event = event % args - scs_token = async_calling_stack.set(sys._getframe().f_back) # type: ignore[arg-type] + scs_token = _ASYNC_CALLING_STACK.set(sys._getframe().f_back) # type: ignore[arg-type] ctx = contextvars.copy_context() try: await asyncio.get_running_loop().run_in_executor( @@ -198,7 +198,7 @@ async def ameth(self: Any, event: str, *args: Any, **kw: Any) -> Any: ), ) finally: - async_calling_stack.reset(scs_token) + _ASYNC_CALLING_STACK.reset(scs_token) meth.__name__ = name ameth.__name__ = f"a{name}" @@ -228,7 +228,7 @@ async def alog( if args: event = event % args - scs_token = async_calling_stack.set(sys._getframe().f_back) # type: ignore[arg-type] + scs_token = _ASYNC_CALLING_STACK.set(sys._getframe().f_back) # type: ignore[arg-type] ctx = contextvars.copy_context() try: runner = await asyncio.get_running_loop().run_in_executor( @@ -238,7 +238,7 @@ async def alog( ), ) finally: - async_calling_stack.reset(scs_token) + _ASYNC_CALLING_STACK.reset(scs_token) return runner meths: dict[str, Callable[..., Any]] = {"log": log, "alog": alog} diff --git a/src/structlog/contextvars.py b/src/structlog/contextvars.py index 3006b5cb..cc531889 100644 --- a/src/structlog/contextvars.py +++ b/src/structlog/contextvars.py @@ -33,9 +33,9 @@ STRUCTLOG_KEY_PREFIX = "structlog_" STRUCTLOG_KEY_PREFIX_LEN = len(STRUCTLOG_KEY_PREFIX) -async_calling_stack: contextvars.ContextVar[ +_ASYNC_CALLING_STACK: contextvars.ContextVar[ FrameType -] = contextvars.ContextVar("async_calling_stack") +] = contextvars.ContextVar("_ASYNC_CALLING_STACK") # For proper isolation, we have to use a dict of ContextVars instead of a # single ContextVar with a dict. diff --git a/src/structlog/stdlib.py b/src/structlog/stdlib.py index 959cb6a4..0cac0354 100644 --- a/src/structlog/stdlib.py +++ b/src/structlog/stdlib.py @@ -24,7 +24,7 @@ from ._base import BoundLoggerBase from ._frames import _find_first_app_frame_and_name, _format_stack from ._log_levels import _LEVEL_TO_NAME, _NAME_TO_LEVEL, add_log_level -from .contextvars import async_calling_stack, merge_contextvars +from .contextvars import _ASYNC_CALLING_STACK, merge_contextvars from .exceptions import DropEvent from .processors import StackInfoRenderer from .typing import Context, EventDict, ExcInfo, Processor, WrappedLogger @@ -590,7 +590,7 @@ async def _dispatch_to_sync( .. versionchanged:: 23.3.0 Callsite parameters are now also collected under asyncio. """ - scs_token = async_calling_stack.set(sys._getframe().f_back.f_back) # type: ignore[union-attr, arg-type, unused-ignore] + scs_token = _ASYNC_CALLING_STACK.set(sys._getframe().f_back.f_back) # type: ignore[union-attr, arg-type, unused-ignore] ctx = contextvars.copy_context() try: @@ -599,7 +599,7 @@ async def _dispatch_to_sync( lambda: ctx.run(lambda: meth(event, *args, **kw)), ) finally: - async_calling_stack.reset(scs_token) + _ASYNC_CALLING_STACK.reset(scs_token) async def debug(self, event: str, *args: Any, **kw: Any) -> None: await self._dispatch_to_sync(self.sync_bl.debug, event, args, kw) From a0ab81967174456d83fe3ec0e6e71e142a812dee Mon Sep 17 00:00:00 2001 From: rob dailey Date: Sun, 29 Oct 2023 18:29:50 -0400 Subject: [PATCH 13/16] De-cleverfied logic for easier reading --- tests/test_processors.py | 9 ++++----- 1 file changed, 4 insertions(+), 5 deletions(-) diff --git a/tests/test_processors.py b/tests/test_processors.py index eb289518..9317cc08 100644 --- a/tests/test_processors.py +++ b/tests/test_processors.py @@ -844,15 +844,14 @@ def __init__(self): logger = structlog.stdlib.get_logger() - # These are different when running under async - exclude_keys = ["thread", "thread_name"] - callsite_params = self.get_callsite_parameters() await logger.info("baz") logger_params = json.loads(string_io.getvalue()) - [callsite_params.pop(key) for key in exclude_keys] - [logger_params.pop(key) for key in exclude_keys] + # These are different when running under async + for key in ["thread", "thread_name"]: + callsite_params.pop(key) + logger_params.pop(key) assert {"event": "baz", **callsite_params} == logger_params From fcf925f22da5fe4131bb8be1ca40e0f50a09caee Mon Sep 17 00:00:00 2001 From: rob dailey Date: Mon, 30 Oct 2023 09:25:33 -0400 Subject: [PATCH 14/16] Added `class_path` processor --- CHANGELOG.md | 5 ++- src/structlog/processors.py | 59 ++++++++++++++++++++++++++++++ tests/test_processors.py | 71 +++++++++++++++++++++++++++++++++++++ 3 files changed, 134 insertions(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 57f86b6a..6a6b67ab 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -15,6 +15,10 @@ You can find our backwards-compatibility policy [here](https://github.com/hynek/ ## [Unreleased](https://github.com/hynek/structlog/compare/23.2.0...HEAD) +### Added + +- `structlog.processors.AddCallingClassPath()` added, which will attempt to determine the calling class path and add it as `class_path` to the event dict. Takes an optional `levels` `dict`|`set` to limit which `logging.LEVEL` to include the addition in. + ### Fixed - `AsyncBoundLogger` now properly supports callsite parameters. @@ -24,7 +28,6 @@ You can find our backwards-compatibility policy [here](https://github.com/hynek/ - `structlog.threadlocal.tmp_bind()` now also works `BoundLoggerLazyProxy` (in other words: before anything is bound to a bound logger). - ## [23.2.0](https://github.com/hynek/structlog/compare/23.1.0...23.2.0) - 2023-10-09 ### Removed diff --git a/src/structlog/processors.py b/src/structlog/processors.py index b4063332..2423037d 100644 --- a/src/structlog/processors.py +++ b/src/structlog/processors.py @@ -20,6 +20,7 @@ import threading import time +from types import FrameType from typing import ( Any, Callable, @@ -28,6 +29,7 @@ NamedTuple, Sequence, TextIO, + Union, ) from ._frames import ( @@ -909,3 +911,60 @@ def __call__( event_dict["event"] = replace_by return event_dict + + +class AddCallingClassPath: + """ + Attempt to identify and add the caller class path to the event dict + under the ``class_path`` key. + + Arguments: + + levels: + A set of log levels to add the ``class_path`` key and + information to. An empty set == * + + .. versionadded:: 23.4.0 + """ + + def __init__(self, levels: Union[set[str], dict[str]] | None = None): + self.levels = levels + + def __call__( + self, logger: WrappedLogger, name: str, event_dict: EventDict + ) -> EventDict: + if self.levels and name not in self.levels: + return event_dict + + f, _ = _find_first_app_frame_and_name() + event_dict["class_path"] = self.get_qual_name(f) + + return event_dict + + def get_qual_name(self, frame: FrameType) -> str: + """ + For a given app frame, attempt to deduce the class path + by crawling through the frame's ``f_globals`` to find matching object code. + + This O(n) procedure should return as O(1) in most situations, + but buyer beware. + + Arguments: + + frame: + Frame to process. + + Returns: + + string of the deduced class path + + .. versionadded:: 23.4.0 + """ + for cls in ( + obj for obj in frame.f_globals.values() if inspect.isclass(obj) + ): + member = getattr(cls, frame.f_code.co_name, None) + if inspect.isfunction(member) and member.__code__ == frame.f_code: + return f"{member.__module__}.{member.__qualname__}" + + return f"__main__.{frame.f_code.co_name}" diff --git a/tests/test_processors.py b/tests/test_processors.py index 9317cc08..c990ca38 100644 --- a/tests/test_processors.py +++ b/tests/test_processors.py @@ -27,6 +27,7 @@ from structlog import BoundLogger from structlog._utils import get_processname from structlog.processors import ( + AddCallingClassPath, CallsiteParameter, CallsiteParameterAdder, EventRenamer, @@ -1171,3 +1172,73 @@ def test_replace_by_key_is_optional(self): assert {"msg": "hi", "foo": "bar"} == EventRenamer("msg", "missing")( None, None, {"event": "hi", "foo": "bar"} ) + + +class TestAddCallingClassPath: + def test_simple_lookup(self): + """ + Simple verification of path interogation + """ + assert "{}.{}.{}".format( + self.__module__, + self.__class__.__qualname__, + sys._getframe().f_code.co_name, + ) == AddCallingClassPath().get_qual_name(sys._getframe()) + + async def test_async_lookup(self): + """ + Simple verification of path interogation against async function + """ + assert "{}.{}.{}".format( + self.__module__, + self.__class__.__qualname__, + sys._getframe().f_code.co_name, + ) == AddCallingClassPath().get_qual_name(sys._getframe()) + + def test_processor(self): + """ + Ensure `AddCallingClassPath` Processor can be enabled, and + that the ``class_path`` details are present and correct in a + log entry + """ + cf = structlog.testing.CapturingLoggerFactory() + structlog.configure( + logger_factory=cf, + processors=[ + structlog.processors.AddCallingClassPath(), + structlog.processors.JSONRenderer(), + ], + ) + structlog.get_logger().info("test!") + assert ( + "{}.{}.{}".format( + self.__module__, + self.__class__.__qualname__, + sys._getframe().f_code.co_name, + ) + == json.loads(cf.logger.calls.pop().args[0])["class_path"] + ) + + async def test_async_processor(self): + """ + Ensure `AddCallingClassPath` Processor can be enabled, and + that the ``class_path`` details are present and correct + in an async log entry + """ + cf = structlog.testing.CapturingLoggerFactory() + structlog.configure( + logger_factory=cf, + processors=[ + structlog.processors.AddCallingClassPath(), + structlog.processors.JSONRenderer(), + ], + ) + await structlog.get_logger().ainfo("test!") + assert ( + "{}.{}.{}".format( + self.__module__, + self.__class__.__qualname__, + sys._getframe().f_code.co_name, + ) + == json.loads(cf.logger.calls.pop().args[0])["class_path"] + ) From afbc3cecdfedd9255afee4177776b1cda3e38534 Mon Sep 17 00:00:00 2001 From: rob dailey Date: Mon, 30 Oct 2023 09:31:35 -0400 Subject: [PATCH 15/16] Corrected my stupidity --- CHANGELOG.md | 2 +- src/structlog/processors.py | 23 +++++++++++------------ 2 files changed, 12 insertions(+), 13 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 6a6b67ab..4d1ddca1 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -17,7 +17,7 @@ You can find our backwards-compatibility policy [here](https://github.com/hynek/ ### Added -- `structlog.processors.AddCallingClassPath()` added, which will attempt to determine the calling class path and add it as `class_path` to the event dict. Takes an optional `levels` `dict`|`set` to limit which `logging.LEVEL` to include the addition in. +- `structlog.processors.AddCallingClassPath()` added, which will attempt to determine the calling class path and add it as `class_path` to the event dict. Takes an optional `levels` `list`|`set` to limit which `logging.LEVEL` to include the addition in. ### Fixed diff --git a/src/structlog/processors.py b/src/structlog/processors.py index 2423037d..7afc7caa 100644 --- a/src/structlog/processors.py +++ b/src/structlog/processors.py @@ -29,7 +29,6 @@ NamedTuple, Sequence, TextIO, - Union, ) from ._frames import ( @@ -927,7 +926,7 @@ class AddCallingClassPath: .. versionadded:: 23.4.0 """ - def __init__(self, levels: Union[set[str], dict[str]] | None = None): + def __init__(self, levels: set[str] | list[str] | None = None): self.levels = levels def __call__( @@ -943,22 +942,22 @@ def __call__( def get_qual_name(self, frame: FrameType) -> str: """ - For a given app frame, attempt to deduce the class path - by crawling through the frame's ``f_globals`` to find matching object code. + For a given app frame, attempt to deduce the class path + by crawling through the frame's ``f_globals`` to find matching object code. - This O(n) procedure should return as O(1) in most situations, - but buyer beware. + This O(n) procedure should return as O(1) in most situations, + but buyer beware. - Arguments: + Arguments: - frame: - Frame to process. + frame: + Frame to process. - Returns: + Returns: - string of the deduced class path + string of the deduced class path - .. versionadded:: 23.4.0 + .. versionadded:: 23.4.0 """ for cls in ( obj for obj in frame.f_globals.values() if inspect.isclass(obj) From 0bd0a1670d9bd6a749ff8a9a4d089479f3371bdd Mon Sep 17 00:00:00 2001 From: rob dailey Date: Mon, 30 Oct 2023 09:50:42 -0400 Subject: [PATCH 16/16] Added `AddCallingClassPath` API --- docs/api.rst | 2 ++ 1 file changed, 2 insertions(+) diff --git a/docs/api.rst b/docs/api.rst index 5a911533..3b05a8e8 100644 --- a/docs/api.rst +++ b/docs/api.rst @@ -278,6 +278,8 @@ API Reference .. autoclass:: CallsiteParameterAdder +.. autoclass:: AddCallingClassPath + `structlog.stdlib` Module -------------------------