Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ConsoleRenderer does not handle non-tuple exc_info #482

Closed
aclemons opened this issue Dec 6, 2022 · 0 comments · Fixed by #483
Closed

ConsoleRenderer does not handle non-tuple exc_info #482

aclemons opened this issue Dec 6, 2022 · 0 comments · Fixed by #483

Comments

@aclemons
Copy link
Contributor

aclemons commented Dec 6, 2022

First, thank you for this great package.

We are using structlog for creating canonical logs in a lambda function. The entrypoint of the lambda function calls another method which handles the event. This method never raises, but code within the other method might trap an exception and place it in the contextvar key exc_info .

In production, we log output as json and everything is fine. For local development, we are using the console renderer, but the exceptions are not handled properly unless the exc_key contains a tuple.

Here is a minimal reproduction:

import structlog
from structlog.contextvars import bind_contextvars

logger = structlog.stdlib.get_logger()

def process():
    bind_contextvars(event_id="123")
    # do some things, but don't propagate the exception
    try:
        print("Running...")

        raise ValueError("Boom")
    except Exception as exc:
        bind_contextvars(exc_info=exc)

    print("Finished...")

def run():
    try:
        process()
    finally:
        logger.info("canonical-log")

if __name__ == "__main__":
    run()

When running, this explodes while handling the log:

$ poetry run python3 main.py
Running...
Finished...
Traceback (most recent call last):
  File "/Users/aclemons/worksp/structlog-test/main.py", line 25, in <module>
    run()
  File "/Users/aclemons/worksp/structlog-test/main.py", line 22, in run
    logger.info("canonical-log")
  File "/Users/aclemons/Library/Caches/pypoetry/virtualenvs/structlog-test-wfc9biWa-py3.9/lib/python3.9/site-packages/structlog/_log_levels.py", line 157, in meth
    return self._proxy_to_logger(name, event, **kw)
  File "/Users/aclemons/Library/Caches/pypoetry/virtualenvs/structlog-test-wfc9biWa-py3.9/lib/python3.9/site-packages/structlog/_base.py", line 205, in _proxy_to_logger
    args, kw = self._process_event(method_name, event, event_kw)
  File "/Users/aclemons/Library/Caches/pypoetry/virtualenvs/structlog-test-wfc9biWa-py3.9/lib/python3.9/site-packages/structlog/_base.py", line 162, in _process_event
    event_dict = proc(self._logger, method_name, event_dict)
  File "/Users/aclemons/Library/Caches/pypoetry/virtualenvs/structlog-test-wfc9biWa-py3.9/lib/python3.9/site-packages/structlog/dev.py", line 424, in __call__
    self._exception_formatter(sio, exc_info)
  File "/Users/aclemons/Library/Caches/pypoetry/virtualenvs/structlog-test-wfc9biWa-py3.9/lib/python3.9/site-packages/structlog/dev.py", line 187, in rich_traceback
    Traceback.from_exception(*exc_info, show_locals=True)
  File "/Users/aclemons/Library/Caches/pypoetry/virtualenvs/structlog-test-wfc9biWa-py3.9/lib/python3.9/site-packages/rich/traceback.py", line 292, in from_exception
    rich_traceback = cls.extract(
  File "/Users/aclemons/Library/Caches/pypoetry/virtualenvs/structlog-test-wfc9biWa-py3.9/lib/python3.9/site-packages/rich/traceback.py", line 348, in extract
    exc_type=safe_str(exc_type.__name__),
AttributeError: 'NoneType' object has no attribute '__name__'

If the exception is propagated it works without problem.

It looks like the problem is here:

https://github.com/hynek/structlog/blob/22.3.0/src/structlog/dev.py#L420-L424

Since exc_info is not a tuple, it calls sys.exc_info, but we are not currently handling an exception and this returns None values.

Would it be appropriate to replace that with the following code?

        if exc_info:
            self._exception_formatter(sio, _figure_out_exc_info(exc_info))

That is what ExceptionRenderer is using here.
This then works for me.

$ poetry run python3 other.py
Running...
Finished...
2022-12-06 10:40:27 [info     ] canonical-log                  event_id=123
╭─────────────────────────────── Traceback (most recent call last) ────────────────────────────────╮
│ /Users/aclemons/worksp/structlog-test/other.py:25 in process                                     │
│                                                                                                  │
│   22 │   try:                                                                                    │
│   23 │   │   print("Running...")                                                                 │
│   24 │   │                                                                                       │
│ ❱ 25 │   │   raise ValueError("Boom")                                                            │
│   26 │   except Exception as exc:                                                                │
│   27 │   │   bind_contextvars(exc_info=exc)                                                      │
╰──────────────────────────────────────────────────────────────────────────────────────────────────╯
ValueError: Boom
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant