How to track logging errors?

Question

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

Often I find myself in a situation where an error in 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 trace inside the registration module; he does not tell me where the error occurred in my code.

Is there any way to fix this?

Answer 1

I had the same problems finding the source of the error. the log module handles such exceptions and does not stop the program, which is acceptable behavior for the log module. But it excludes the exception and does not provide sufficient information when working with it.

I found and now use the one described below

The trick is to replace the most basic logging function, which performs string formatting of logging.LogRecord.getMessage with a function that wraps the call with an exception handling condition.
Before using the recorder, make sure that you make this replacement. This replacement will work in other modules of your program.

So, your example will be modified as follows: Note that I modified the code a bit to ensure that an exception is thrown.

 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 now this will throw a more useful exception:

 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 an application with an intensive log, I would suggest adding an option to replace the loggin function or not. Thus, in debug mode, an overloaded function will be used, but in production it is not so, you will avoid a penalty for the performance of another exception handling.