This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

Author Miksus
Recipients Miksus
Date 2021-08-16.10:11:13
SpamBayes Score -1.0
Marked as misclassified Yes
Message-id <1629108674.13.0.869133594401.issue44924@roundup.psfhosted.org>
In-reply-to
Content
The reason why logging.handlers.QueueHandler does not maintain exc_text is obvious:

    def prepare(self, record):
        ...
        record = copy.copy(record)
        record.message = msg
        record.msg = msg
        record.args = None
        record.exc_info = None
        record.exc_text = None
        return record

The record.exc_text is set to None. The reason for this is to prevent the exception text showing up multiple times to the message. See https://bugs.python.org/issue34334.

However, there are a couple of situations this may cause a problem. First, it's not currently possible to format the exception of the record in a handler on the other side of the queue. Second, it's not possible to let the handler on the other side of the queue utilize exc_text. The default handlers do not behave in such a way but one could prefer to create their own handler that does so, such as log the records to a database with a column for the exception text.


Possible solution:
Don't override the record.msg and don't set the record.exc_text to None. I think it could be done simply:

    def prepare(self, record):
        ...
        record = copy.copy(record)
        record.message = msg
        # record.msg = msg
        record.args = None
        record.exc_info = None
        # record.exc_text = None
        return record

 
This way one can format the record later again without multiple exception text showing up in the message. Doing so will fail the test 'test_logging.QueueHandlerTest.test_formatting' as this tests the record.msg is the same as record.message. This may cause issues if someone relies on record.msg. On the other hand, now other formatters and handlers down the line could use the exc_text attribute. I'm not sure if this is too breaking change or not.

The failing test:

    def test_formatting(self):
        msg = self.next_message()
        levelname = logging.getLevelName(logging.WARNING)
        log_format_str = '{name} -> {levelname}: {message}'
        formatted_msg = log_format_str.format(name=self.name,
                                              levelname=levelname, message=msg)
        formatter = logging.Formatter(self.log_format)
        self.que_hdlr.setFormatter(formatter)
        self.que_logger.warning(msg)
        log_record = self.queue.get_nowait()
        self.assertEqual(formatted_msg, log_record.msg) # <Fails here, if commented out it's a pass>
        self.assertEqual(formatted_msg, log_record.message)



I tested this issue with the following test (which is a pass with the current build):

class QueueHandlerTest(BaseTest):

    def test_formatting_exc_text(self):
        formatter = logging.Formatter(self.log_format)
        self.que_hdlr.setFormatter(formatter)
        try:
            raise RuntimeError('deliberate mistake')
        except:
            self.que_logger.exception('failed', stack_info=True)
        log_record = self.queue.get_nowait()
        self.assertTrue(log_record.exc_text.startswith('Traceback (most recent '
                                                       'call last):\n'))
History
Date User Action Args
2021-08-16 10:11:14Miksussetrecipients: + Miksus
2021-08-16 10:11:14Miksussetmessageid: <1629108674.13.0.869133594401.issue44924@roundup.psfhosted.org>
2021-08-16 10:11:14Miksuslinkissue44924 messages
2021-08-16 10:11:13Miksuscreate