Strange logging.Formatter behaviour

[Tiaburn Stedd]

Hello, all!

I'm working on specific project and have a curious task where I need
to use specific formatter and custom handlers, which are switchable to
default handlers. Problem is that default handlers behaviour is to
consume errors, so errors raised from code have printed tracebacks,
but not passed outside logger, because of it silent behaviour.

Unit test for this is below:

import logging
import unittest

class SpecificFormatException(Exception):
pass

class MyClass(object):
def __init__(self, record):
raise TypeError

class MyFormatter(logging.Formatter, object):
def format(self, record):
try:
specific_format_record = MyClass(record)
except TypeError:
raise SpecificFormatException("Error raised")

class TestLogger(unittest.TestCase):
def test_my_logger(self):
self.logger = logging.getLogger(self.__class__.__name__)
handler = logging.FileHandler('test_logger.log')
handler.setFormatter(fmt=MyFormatter())
self.logger.addHandler(handler)
self.assertRaises(SpecificFormatException,
self.logger.warn,"Log something")

if __name__ == '__main__':
unittest.main()


I don't believe this behavior is normal. I expect error raised in a
Formatter.format function, should be passed all the way up, but not
consumed.

I found a workaround:

class CustomFileHandler(logging.FileHandler, object):
def handleError(self, record):
super(CustomFileHandler, self).handleError(record)
raise

But it looks ugly to add Custom*Handler for any default Handler (like,
StreamHandler, etc) to make them possible to fall out on any error.

There are raiseException switch in source of logging/__init__.py

92 #raiseExceptions is used to see if exceptions during handling
should be
93 #propagated
94 #
95 raiseExceptions = 1

But all it switch is only is traceback printed or not. I think this
behaviour is against Zen of Python: "Errors should never pass
silently."

May be logging library should be updated to contain 2 flags:
printTracebacks and raiseExceptions ?

 

[Vinay Sajip]

I don't believe this behavior is normal. I expect error raised in a
Formatter.format function, should be passed all the way up, but not
consumed.

I found a workaround:

class CustomFileHandler(logging.FileHandler, object):
    def handleError(self, record):
         super(CustomFileHandler, self).handleError(record)
         raise

But it looks ugly to add Custom*Handler for any default Handler (like,
StreamHandler, etc) to make them possible to fall out on any error.

There are raiseException switch in source of logging/__init__.py

  92 #raiseExceptions is used to see if exceptions during handling
should be
  93 #propagated
  94 #
  95 raiseExceptions = 1

But all it switch is only is traceback printed or not. I think this
behaviour is against Zen of Python: "Errors should never pass
silently."

They don't pass silently - raiseExceptions defaults to 1, so
tracebacks are printed by default. In production, it's not a good idea
for a potentially long-running process like a server to be brought
down because someone put a typo in a logging format string, so the
recommendation is to set raiseExceptions to 0/False in such scenarios.

Since you are developing a custom formatter, you can certainly catch
any formatting exceptions in your format method and decide what you
want to do with them.

The default handleError behaviour of printing a traceback is
reasonable, in my view. If you want something else, you can subclass
the relevant handler class; just setting a printTracebacks flag to
false isn't going to get useful behaviour specific to individual
requirements.

There's no real point in throwing a very specific exception from a
formatter, as a handler isn't going to automatically know how to
handle a SpecificFormatException in any meaningful way. Remember that
in the general case, application developers don't always have control
of what handlers are configured for an application (for example, this
could be set by end-user or per-deployment configuration).

Regards,

Vinay Sajip