hynek / structlog

Simple, powerful, and fast logging for Python.
https://www.structlog.org/
Other
3.6k stars 225 forks source link

Cannot log with `structlog.processors.format_exc_info` #673

Closed fraghag closed 2 weeks ago

fraghag commented 2 weeks ago

I'm trying to log thrown exceptions. Using structlog 24.4.0 and Python 3.12.5.

This is what I'm running:

import structlog

structlog.configure(
    processors=[
        structlog.processors.add_log_level,
        structlog.processors.JSONRenderer(),
        # structlog.processors.format_exc_info,
    ]
)
log = structlog.stdlib.get_logger()

log.info("Started")
try:
    a = 1 / 0
except Exception as e:
    log.exception("Failed.")

This works and prints

{"event": "Started", "level": "info"}
{"exc_info": true, "event": "Failed.", "level": "error"}

But I also want the exception to be included in the exception log message so I added structlog.processors.format_exc_info but then I get the following exception already on log.info():

Traceback (most recent call last):
  File "/home/me/git/repo_name/test_log.py", line 12, in <module>
    log.info("Started")
  File "/home/me/.cache/pypoetry/virtualenvs/repo_name-vETpVZ8U-py3.12/lib/python3.12/site-packages/structlog/_native.py", line 134, in meth
    return self._proxy_to_logger(name, event, **kw)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/me/.cache/pypoetry/virtualenvs/repo_name-vETpVZ8U-py3.12/lib/python3.12/site-packages/structlog/_base.py", line 214, in _proxy_to_logger
    args, kw = self._process_event(method_name, event, event_kw)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/me/.cache/pypoetry/virtualenvs/repo_name-vETpVZ8U-py3.12/lib/python3.12/site-packages/structlog/_base.py", line 165, in _process_event
    event_dict = proc(self._logger, method_name, event_dict)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/me/.cache/pypoetry/virtualenvs/repo_name-vETpVZ8U-py3.12/lib/python3.12/site-packages/structlog/processors.py", line 410, in __call__
    exc_info = event_dict.pop("exc_info", None)
               ^^^^^^^^^^^^^^
AttributeError: 'str' object has no attribute 'pop'

Is this a bug or am I using the library wrong?

fraghag commented 2 weeks ago

Never mind, realized now that the order of the processors matter and that the renderer should be last.

Thanks for a great package. Would be nice with a sanity check on processor order with a nice error or warning.