22.2.0 - TypeError with logger.exception and string interpolation

[alangenfeld]

_log_levels.py:156
unsupported operand type(s) for %: '<exception object>' and 'tuple'

sample stack https://gist.github.com/alangenfeld/2bc3f1d22e81af428fa487320fc6c797

[fbraza]

Hello @alangenfeld

I confirm the bug. It happens here too. Our bitbucket pipelines kepts hanging for hours. Today bitbucket pipeline service was actually down. So I thought to wait the fix. But next still had the problem. It boiled down to this specific error.

I rolled back to a previous version and the pipeline passed. Because we used the logger extensively our pipeline just bursted I guess. They hanged 2 hours and then crash. I guess the stack trace was huge :-)

I unfortunately cannot share more specific code but can confirm that the error was basically screwing up our testing suite.

Cheers

[hynek]

I would've been helpful if either of you gave an Short, Self Contained, Correct, Example or at least a call example.

Please help me understand this here, so far I'm guessing:

1. @alangenfeld called:

   except Exception as exc:
       log.exception(exc)

2. @fbraza called something like log.info(42)

?

---

So far it looks like a case of Hyrum's Law to me – the event argument was always documented as having to be a str. Case 2 should be wrapped in a str() but how exactly does case 1 work? Even stdlib's logging is documented to take a msg:

logging.exception(msg, *args, **kwargs)

@alangenfeld are you aware that if you're in an except block, you don't have to pass the exception into log.exception()? And if you're in an except block, the correct usage is log.exception("event", exc_info=exc) and the behavior is documented here: https://www.structlog.org/en/stable/api.html#structlog.processors.format_exc_info

---

I'm not sure what to do here there seem to be three bad options for me:

• remove the feature
• add isinstance(event, str) checks slowing down structlog for everybody
• make everybody fix their code, however I don't know how many "everybody" is.

In any case, I should better document the exception handling. I've opened #474 for that.

[hynek]

I think I've found a compromise that shouldn't have a measurable performance impact in #475 – can you two please check if it fixes your problems? Thank you.

[fbraza]

Hello @hynek

Many thanks for your prompt & thorough feedback. I'll come back to you with an answer today.

All the best

[alangenfeld]

Apologies for the terse issue submission and thanks for the detailed response. You are correct that this is from call sites that pass the exception object in directly. #475 looks like it will handle that now as per the test case.

[fbraza]

Hello both,

Indeed it does.

Many thanks again.