Message326242
I debugged this issue and found that `format()` is being called twice and appending the traceback twice.
The first call -
QueueHandler.emit() -> QueueHandler.prepare() -> self.format() (which is the default Formatter) -- this gets called with self.msg = 'Look out!' in this example.
The second call -
StreamHandler.emit() -> self.format() -- gets called with a record.msg = 'Look out!' + the traceback added in the first call above. This call to format also appends the traceback because even though record.exc_info is None, record.exc_text is still set.
Because of the following note in `format()`:
if record.exc_info:
# Cache the traceback text to avoid converting it multiple times
# (it's constant anyway)
if not record.exc_text:
record.exc_text = self.formatException(record.exc_info)
Even when record.exc_info has been set to None before the second call, record.exc_text still contains the cached value, which is re-appended in the next line:
if record.exc_text:
if s[-1:] != "\n":
s = s + "\n"
s = s + record.exc_text
So the traceback appears twice.
Based on the design of this, my guess is the record.msg was never intended to contain the value with the traceback already appended to it, so I've made a PR with that change. This will still allow record.message to have the change from issue31084, but record.msg won't get the traceback twice. |
|
Date |
User |
Action |
Args |
2018-09-24 14:41:31 | cheryl.sabella | set | recipients:
+ cheryl.sabella, vinay.sajip, avdd, xtreak, danishprakash |
2018-09-24 14:41:31 | cheryl.sabella | set | messageid: <1537800091.33.0.956365154283.issue34334@psf.upfronthosting.co.za> |
2018-09-24 14:41:31 | cheryl.sabella | link | issue34334 messages |
2018-09-24 14:41:31 | cheryl.sabella | create | |
|