diff --git a/CHANGELOG.md b/CHANGELOG.md index 7a0e35cf..935acf2f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -17,6 +17,9 @@ You can find our backwards-compatibility policy [here](https://github.com/hynek/ ### Added +- `structlog.processors.CallsiteNamespaceAdder()`, which attempts to determine the calling namespace and add it as `namespace` to the event dict. + Takes an optional `levels` `list`|`set` to limit which `logging.LEVEL` to include the addition in. + - Async log methods (those starting with an `a`) now also support the collection of callsite information using `structlog.processors.CallsiteParameterAdder`. [#565](https://github.com/hynek/structlog/issues/565) diff --git a/docs/api.rst b/docs/api.rst index 5a911533..14f39489 100644 --- a/docs/api.rst +++ b/docs/api.rst @@ -278,6 +278,8 @@ API Reference .. autoclass:: CallsiteParameterAdder +.. autoclass:: CallsiteNamespaceAdder + `structlog.stdlib` Module ------------------------- diff --git a/src/structlog/_frames.py b/src/structlog/_frames.py index 51346d2f..4a329bf3 100644 --- a/src/structlog/_frames.py +++ b/src/structlog/_frames.py @@ -5,6 +5,7 @@ from __future__ import annotations +import inspect import sys import traceback @@ -76,3 +77,38 @@ def _format_stack(frame: FrameType) -> str: sio.close() return sinfo + + +def _get_qual_name(frame: FrameType) -> str: + """ + For a given app frame, attempt to deduce the namespace + 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 namespace + + .. versionadded:: 23.3.0 + """ + identified_namespace = frame.f_code.co_name + + for cls in { + obj for obj in frame.f_globals.values() if inspect.isclass(obj) + }: + member = getattr(cls, frame.f_code.co_name, None) + # store the current namespace as a fall back (probably the namespace) + identified_namespace = f"{cls.__module__}.{frame.f_code.co_name}" + if inspect.isfunction(member) and member.__code__ == frame.f_code: + # we found our code match, can stop looking + return f"{member.__module__}.{member.__qualname__}" + + return identified_namespace diff --git a/src/structlog/processors.py b/src/structlog/processors.py index 351cb100..a3f1b3a0 100644 --- a/src/structlog/processors.py +++ b/src/structlog/processors.py @@ -34,6 +34,7 @@ _find_first_app_frame_and_name, _format_exception, _format_stack, + _get_qual_name, ) from ._log_levels import _NAME_TO_LEVEL, add_log_level from ._utils import get_processname @@ -46,6 +47,7 @@ "add_log_level", "CallsiteParameter", "CallsiteParameterAdder", + "CallsiteNamespaceAdder", "dict_tracebacks", "EventRenamer", "ExceptionPrettyPrinter", @@ -909,3 +911,42 @@ def __call__( event_dict["event"] = replace_by return event_dict + + +class CallsiteNamespaceAdder: + """ + Attempt to identify and add the caller namespace to the event dict + under the ``namespace`` key. + + Attempts to deduce the namespace by crawling through the + calling 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: + + levels: + A optional set of log levels to add the ``namespace`` key and + information to. The log levels should be supplied as an integer. + You can use the constants from `logging` like ``logging.INFO`` + or pass the values directly. See `this table from the logging + docs `_ for + possible values. Providing `None` or an empty set == * + + .. versionadded:: 23.3.0 + """ + + def __init__(self, levels: set[int] | list[int] | None = None): + self.levels = levels + + def __call__( + self, logger: WrappedLogger, name: str, event_dict: EventDict + ) -> EventDict: + if self.levels and _NAME_TO_LEVEL[name] not in self.levels: + return event_dict + + f, _ = _find_first_app_frame_and_name() + event_dict["namespace"] = _get_qual_name(f) + + return event_dict diff --git a/src/structlog/stdlib.py b/src/structlog/stdlib.py index 5e05e9bd..c7573540 100644 --- a/src/structlog/stdlib.py +++ b/src/structlog/stdlib.py @@ -392,13 +392,18 @@ async def _dispatch_to_sync( ) -> None: """ Merge contextvars and log using the sync logger in a thread pool. + + .. 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[arg-type, union-attr] ctx = contextvars.copy_context() await asyncio.get_running_loop().run_in_executor( None, lambda: ctx.run(lambda: meth(event, *args, **kw)), ) + _ASYNC_CALLING_STACK.reset(scs_token) async def adebug(self, event: str, *args: Any, **kw: Any) -> None: """ diff --git a/tests/test_processors.py b/tests/test_processors.py index 9317cc08..62b2c688 100644 --- a/tests/test_processors.py +++ b/tests/test_processors.py @@ -25,6 +25,7 @@ import structlog from structlog import BoundLogger +from structlog._frames import _get_qual_name from structlog._utils import get_processname from structlog.processors import ( CallsiteParameter, @@ -1171,3 +1172,101 @@ def test_replace_by_key_is_optional(self): assert {"msg": "hi", "foo": "bar"} == EventRenamer("msg", "missing")( None, None, {"event": "hi", "foo": "bar"} ) + + +class TestCallsiteNamespaceAdder: + def test_simple_lookup(self): + """ + Simple verification of path interogation + """ + assert "{}.{}.{}".format( + self.__module__, + self.__class__.__qualname__, + sys._getframe().f_code.co_name, + ) == _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, + ) == _get_qual_name(sys._getframe()) + + def test_async_lookup_fallback(self): + """ + Simple verification of path interogation fallback when no match + can be found + """ + assert _get_qual_name(sys._getframe().f_back).endswith( + "pytest_pyfunc_call" + ) + + def test_processor(self): + """ + `CallsiteNamespaceAdder` Processor can be enabled and + ``namespace`` details are present. + """ + cf = structlog.testing.CapturingLoggerFactory() + structlog.configure( + logger_factory=cf, + processors=[ + structlog.processors.CallsiteNamespaceAdder(), + 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])["namespace"] + ) + + def test_level_limiter(self): + """ + `CallsiteNamespaceAdder` Processor limits to which levels + the ``namespace`` details are added. + """ + cf = structlog.testing.CapturingLoggerFactory() + structlog.configure( + logger_factory=cf, + processors=[ + structlog.processors.CallsiteNamespaceAdder(levels={"debug"}), + structlog.processors.JSONRenderer(), + ], + ) + structlog.get_logger().info("test!") + + # limiter is set to 'debug', so 'info' should not get the param added + assert "namespace" not in json.loads(cf.logger.calls.pop().args[0]) + + async def test_async_processor(self): + """ + `CallsiteNamespaceAdder` Processor can be enabled and + ``namespace`` details are present for an async log entry. + """ + cf = structlog.testing.CapturingLoggerFactory() + structlog.configure( + logger_factory=cf, + processors=[ + structlog.processors.CallsiteNamespaceAdder(), + 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])["namespace"] + )