Loguru finds the wrong module/function name
rafaelclp opened this issue · 0 comments
Context
Description
When I emit a log with loguru (e.g. logger.info("my log")
), loguru can't correctly figure out what's the module and function that called logger.info
. It always shows as loguru._logger:info
.
This only happens after initializing thew newrelic agent, and it's caused by the loguru._logger
newrelic hook (which is enabled by default). If I add the following lines to my newrelic.ini
, the error goes away:
[import-hook:loguru._logger]
enabled = false
Steps to reproduce
import newrelic.agent
from loguru import logger
newrelic.agent.initialize("newrelic.ini")
def my_function():
logger.info("initialized")
my_function()
Expected Output
2022-08-04 17:28:30.883 | INFO | __main__:my_function:7 - initialized
Actual Output
2022-08-04 17:28:30.883 | INFO | loguru._logger:info:1977 - initialized
What's causing this bug
Newrelic wraps all calls to loguru's Logger._log
, and this causes an issue. Let's see why.
How loguru finds out module and function
To find out the module and function that called logger.info
(or .error
/.warning
/...), loguru looks at the stack trace. Here is the relevant loguru code:
def _log(self, level_id, static_level_no, from_decorator, options, message, args, kwargs):
...
(exception, depth, record, lazy, colors, raw, capture, patcher, extra) = options
frame = get_frame(depth + 2)
...
It finds the stacktrace frame two levels up (depth + 2
), where depth
is 0 by default. It expects the stack trace to be:
__main__:my_function
loguru._logger:info
loguru._logger:_log
However, newrelic breaks this assumption because it wraps the call to logger._log
with another function, so the stack trace looks like this:
__main__:my_function
loguru._logger:info
newrelic.hooks.logger_loguru:wrap_log
loguru._logger:_log
When it looks two levels up, it sees loguru._logger:info
instead of __main__.my_function
, and that's why we always see that in the log instead of the expected.
Where does newrelic patch loguru?
In newrelic.config:initialize
:
_process_module_definition(
"loguru._logger",
"newrelic.hooks.logger_loguru",
"instrument_loguru_logger",
)
Which calls newrelic.hooks.logger_loguru:instrument_loguru_logger
:
def instrument_loguru_logger(module):
if hasattr(module, "Logger"):
wrap_function_wrapper(module, "Logger.__init__", wrap_Logger_init)
if hasattr(module.Logger, "_log"):
wrap_function_wrapper(module, "Logger._log", wrap_log)
The last line wraps loguru._logger.Logger._log
with wrap_log
.