Have FakeLogger detect bad calls to logger

[John L. Villalovos]

The logging module does not raise errors that can be caught. So if code logs a message with bad arguments we can't detect the error in unit tests.

See:

>>> import fixtures
>>> import logging
>>> logging.basicConfig()
>>> f = fixtures.FakeLogger()
>>> f.setUp()
>>> logging.warn("foo")
>>> f.output
u'foo\n'
>>> logging.warn("foo", "bar")
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 859, in emit
    msg = self.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 732, in format
    return fmt.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 471, in format
    record.message = record.getMessage()
  File "/usr/lib/python2.7/logging/__init__.py", line 335, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting
Logged from file <stdin>, line 1

>>> try:
... logging.warn("foo", "bar")
... except Exception:
... print("failure")
...
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 859, in emit
    msg = self.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 732, in format
    return fmt.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 471, in format
    record.message = record.getMessage()
  File "/usr/lib/python2.7/logging/__init__.py", line 335, in getMessage
    msg = msg % self.args
TypeError: not all arguments converted during string formatting
Logged from file <stdin>, line 2

[Robert Collins (lifeless)]

This would be lovely to have.

https://docs.python.org/2/library/logging.html#logging.Formatter.format covers the bit in the logging glue where formatting actually happens.

So users can today use a customer formatter already, with a format() method that can do arbitrary stuff (e.g. journal errors to a list , and then have a cleanup call that asserts the list is empty.

Getting at the formatter instance will require a little poking around, and we could certainly make that easier in FakeLogger.

Making this work by default would be great too - for that I think we need:
 - a local subclass for Formatter
 - journal the exceptions to the fixture
 - add a cleanUp that checks the exceptions list is empty
   assertEqual isn't available outside of TestCase, but we can use the Equals matcher directly to format the error nicely and then just raise AssertionError(that string)

[Robert Collins (lifeless)]

Or as John points out on IRC - Handler.handleError(record) - could be used in the same way to capture this stuff without a Formatter subclass - I think thats a superior solution.

[Robert Collins (lifeless)]

(it would look very similar though, handleError, bind it to a list, cleanup checks that).

[Robert Collins (lifeless)]

Oh... last thing would be thread safety, but I suspect we can treat that as a future thing given the synchronous nature of where this is generally used.

[Robert Collins (lifeless)]

Actually, going back on that... handleError doesn't explicitly provide the exception information so while we'd know it failed, we wouldn't know *how* - maybe pulling it out of sys.exc_info() would work, but we've seen issues with that in eventlet with context switches, so I'd be a little worried.