-
-
Notifications
You must be signed in to change notification settings - Fork 251
Description
I have a slightly unusual setup that I should explain first. I'm using the maximalist approach of routing all of my structlog and stdlib logging through ProcessorFormatter
as per the docs, but we're also sending logs at ERROR
and above to Rollbar using pyrollbar
and its RollbarHandler.
Unfortunately, RollbarHandler
on its own doesn't play nicely with that approach because it doesn't call self.format()
anywhere meaning we don't have anywhere to plug in ProcessorFormatter
. So, we have a custom subclass (called StructlogRollbarHandler
) that does similar things to ProcessorFormatter.format()
in its emit()
method before calling the superclass emit()
method to send the payload to Rollbar. A notable exception to that is using the raw record.msg
rather than record.getMessage()
as per #520.
That means that it's really important for us that all our LogRecord
objects, whether from structlog
or stdlib loggers, look the same when they get to the Handler.emit(record)
stage of the pipeline, because we can't rely on ProcessorFormatter
or any structlog renderers patching things up for us. This is mostly working fine, apart from calls to BoundLogger.exception
.
When we call BoundLogger.exception
, the LogRecord
that gets to our StructlogRollbarHandler.emit(record)
method has an event dict for its record.msg
attribute, as you'd expect, and that dict has "exc_info"
in it, but the record.exc_info
attribute itself is None
! Obviously this isn't the case for stdlib-originated records.
Having spent a while debugging, this seems to be because BoundLogger.exception
calls self.error
rather than doing something like self._proxy_to_logger("exception", event, *args, **{"exc_info": True, **kw})
. That means that the wrapped logging.Logger
thinks this was a logger.error
call and not a logger.exception
call, which changes the behaviour in a really subtle way.
All of our LogRecord
objects from structlog
go through ProcessorFormatter.wrap_for_formatter
, which puts exc_info
in the record.msg
event dict and strips it out of the kwargs. Then, because of the aforementioned change of the effective log method from .exception
to .error
, the stdlib logger doesn't set this back to True
for us and then Logger._log
doesn't call sys.exc_info()
for us.
I'm honestly not sure whether this is a bug in my code or structlog
. I accept that using ProcessorFormatter
alongside other formatters isn't really documented/supported, but it's really close to working perfectly apart from this!
Sorry for writing such a long issue, thank you for an amazing library! ❤️