8

When I have lots of different modules using the standard python logging module, the following stack trace does little to help me find out where, exactly, I had a badly formed log statement:

Traceback (most recent call last):
  File "/usr/lib/python2.6/logging/__init__.py", line 768, in emit
    msg = self.format(record)
  File "/usr/lib/python2.6/logging/__init__.py", line 648, in format
    return fmt.format(record)
  File "/usr/lib/python2.6/logging/__init__.py", line 436, in format
    record.message = record.getMessage()
  File "/usr/lib/python2.6/logging/__init__.py", line 306, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting

I'm only starting to use python's logging module, so maybe I am overlooking something obvious. I'm not sure if the stack-trace is useless because I am using greenlets, or if this is normal for the logging module, but any help would be appreciated. I'd be willing to modify the source, anything to make the logging library actually give a clue as to where the problem lies.

5 Answers 5

6

Rather than editing installed python code, you can also find the errors like this:

    def handleError(record):
        raise RuntimeError(record)
    handler.handleError = handleError

where handler is one of the handlers that is giving the problem. Now when the format error occurs you'll see the location.

2
  • Well, it's a horrible way to do it. Nevertheless, it's an approach worth remembering for those cases where editing the library is completely impossible, so +1. Sep 30, 2011 at 10:46
  • 1
    @porgarmingduod: Monkey-patching may not be great, but it is no way more horrible than manipulating the source of the standard library. Monkey-patching will affect everything else in the same process, but the direct editing of the library will affect everything else on the same system.
    – Rörd
    Jan 6, 2013 at 23:21
5

The logging module is designed to stop bad log messages from killing the rest of the code, so the emit method catches errors and passes them to a method handleError. The easiest thing for you to do would be to temporarily edit /usr/lib/python2.6/logging/__init__.py, and find handleError. It looks something like this:

def handleError(self, record):
    """
    Handle errors which occur during an emit() call.

    This method should be called from handlers when an exception is
    encountered during an emit() call. If raiseExceptions is false,
    exceptions get silently ignored. This is what is mostly wanted
    for a logging system - most users will not care about errors in
    the logging system, they are more interested in application errors.
    You could, however, replace this with a custom handler if you wish.
    The record which was being processed is passed in to this method.
    """
    if raiseExceptions:
        ei = sys.exc_info()
        try:
            traceback.print_exception(ei[0], ei[1], ei[2],
                                      None, sys.stderr)
            sys.stderr.write('Logged from file %s, line %s\n' % (
                             record.filename, record.lineno))
        except IOError:
            pass    # see issue 5971
        finally:
            del ei

Now temporarily edit it. Inserting a simple raise at the start should ensure the error gets propogated up your code instead of being swallowed. Once you've fixed the problem just restore the logging code to what it was.

4

It's not really an answer to the question, but hopefully it will be other beginners with the logging module like me.

My problem was that I replaced all occurrences of print with logging.info , so a valid line like print('a',a) became logging.info('a',a) (but it should be logging.info('a %s'%a) instead.

This was also hinted in How to traceback logging errors? , but it doesn't come up in the research

2
1

Alternatively you can create a formatter of your own, but then you have to include it everywhere.

class DebugFormatter(logging.Formatter):
    def format(self, record):
        try:
            return super(DebugFormatter, self).format(record)
        except:
            print "Unable to format record"
            print "record.filename ", record.filename
            print "record.lineno ", record.lineno
            print "record.msg ", record.msg
            print "record.args: ",record.args
            raise


FORMAT = '%(levelname)s %(filename)s:%(lineno)d  %(message)s'
formatter = DebugFormatter(FORMAT)
handler = logging.StreamHandler()
handler.setLevel(logging.DEBUG)
handler.setFormatter(formatter)
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
logger.addHandler(handler)
0

Had same problem Such a Traceback arises due to the wrong format name. So while creating a format for a log file, check the format name once in python documentation: "https://docs.python.org/3/library/logging.html#formatter-objects"

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.