How to traceback logging errors?

问题:

I use the logging module to log messages on my application.

Often I come to a situation where a mistake on a format string or parameter causes an error, for example:

import logging
my_log = logging.getLogger("MyLog")
# this is obviously wrong
my_log.info('%d', "abc")

The result is an error similar to the one below:

Traceback (most recent call last):
  File "/usr/lib64/python2.6/logging/__init__.py", line 776, in emit
    msg = self.format(record)
  File "/usr/lib64/python2.6/logging/__init__.py", line 654, in format
    return fmt.format(record)
  File "/usr/lib64/python2.6/logging/__init__.py", line 436, in format
    record.message = record.getMessage()
  File "/usr/lib64/python2.6/logging/__init__.py", line 306, in getMessage
    msg = msg % self.args
TypeError: %d format: a number is required, not str

However, it just shows the traceback inside the logging module; it doesn't tell me where the error happened within my code.

Is there any way to fix that?

回答1:

I experienced the same problems with finding the source of error. logging module handles such exceptions and do not stop the program - which is acceptable behavior for log module. But is suppress exception and do not provide sufficient information while handling it.

I found and now using the thick described here

The trick is to replace the very basic logging function that does string formatting logging.LogRecord.getMessage with the function that wraps call with exception handling clause.
Make sure that you did this replacement before using logger. This replacement will work in other modules of your program too.

So your example would be modified like that: Please note that I modified code a little to ensure that exception will be generated.

def print_log_record_on_error(func):
    def wrap(self, *args, **kwargs):
        try:
            return func(self, *args, **kwargs)
        except:
            import sys
            print >>sys.stderr, "Unable to create log message msg=%r, args=%r " % (
                getattr(self, 'msg', '?'), getattr(self, 'args', '?'))
            raise
    return wrap
import logging
logging.LogRecord.getMessage = print_log_record_on_error(logging.LogRecord.getMessage)

logging.basicConfig()
my_log = logging.getLogger("MyLog")
# this is obviously wrong
my_log.error('%d' , "abc")

And it will produce more useful exception now:

Unable to create log message msg='%d', args=('abc',) 
Traceback (most recent call last):
  File "C:\Progs\Python262\Lib\logging\__init__.py", line 760, in emit
    msg = self.format(record)
  File "C:\Progs\Python262\Lib\logging\__init__.py", line 644, in format
    return fmt.format(record)
  File "C:\Progs\Python262\Lib\logging\__init__.py", line 432, in format
    record.message = record.getMessage()
  File "C:/Users/vvlad/PycharmProjects/stackoverflow/test1.py", line 6, in wrap
    return func(self, *args, **kwargs)
  File "C:\Progs\Python262\Lib\logging\__init__.py", line 302, in getMessage
    msg = msg % self.args
TypeError: %d format: a number is required, not str

If you have log intensive application I would suggest to add option to replace loggin function or not. Thus oin debug mode code will use overloaded function, but in production - it won't so you'll avoid performance penalty of one more exception handling.