Add callback functionality to log.fail

This enables the common pattern of being able to log a failure and
then do something.
This commit is contained in:
Job Evers-Meltzer 2016-12-10 11:28:32 -08:00
parent b8c91c61bb
commit 20b6b22334
2 changed files with 32 additions and 18 deletions

View file

@ -332,7 +332,7 @@ class LogUploader(object):
class Logger(logging.Logger): class Logger(logging.Logger):
"""A logger that has an extra `fail` method useful for handling twisted failures.""" """A logger that has an extra `fail` method useful for handling twisted failures."""
def fail(self): def fail(self, callback=None, *args):
"""Returns a function to log a failure from an errback. """Returns a function to log a failure from an errback.
The returned function appends the error message and extracts The returned function appends the error message and extracts
@ -346,23 +346,29 @@ class Logger(logging.Logger):
reported values are from inside twisted's deferred handling reported values are from inside twisted's deferred handling
code. code.
Args (for the returned function): Args:
callback: callable to call after making the log. The first argument
will be the `err` from the deferred
args: extra arguments to pass into `callback`
Returns: a function that takes the following arguments:
err: twisted.python.failure.Failure err: twisted.python.failure.Failure
msg: the message to log, using normal logging string iterpolation. msg: the message to log, using normal logging string iterpolation.
args: the values to subtitute into `msg` msg_args: the values to subtitute into `msg`
kwargs: set `level` to change from the default ERROR severity. Other kwargs: set `level` to change from the default ERROR severity. Other
keywoards are treated as normal log kwargs. keywoards are treated as normal log kwargs.
""" """
fn, lno, func = findCaller() fn, lno, func = findCaller()
def _fail(err, msg, *args, **kwargs): def _fail(err, msg, *msg_args, **kwargs):
level = kwargs.pop('level', logging.ERROR) level = kwargs.pop('level', logging.ERROR)
msg += ": %s" msg += ": %s"
args += (err.getErrorMessage(),) msg_args += (err.getErrorMessage(),)
exc_info = (err.type, err.value, err.getTracebackObject()) exc_info = (err.type, err.value, err.getTracebackObject())
record = self.makeRecord( record = self.makeRecord(
self.name, level, fn, lno, msg, args, exc_info, func, kwargs) self.name, level, fn, lno, msg, msg_args, exc_info, func, kwargs)
self.handle(record) self.handle(record)
if callback:
callback(err, *args)
return _fail return _fail

View file

@ -1,6 +1,7 @@
import StringIO import StringIO
import logging import logging
import mock
from twisted.internet import defer from twisted.internet import defer
from twisted.trial import unittest from twisted.trial import unittest
@ -11,30 +12,37 @@ class TestLogger(unittest.TestCase):
def raiseError(self): def raiseError(self):
raise Exception('terrible things happened') raise Exception('terrible things happened')
def triggerErrback(self, log): def triggerErrback(self, callback=None):
d = defer.Deferred() d = defer.Deferred()
d.addCallback(lambda _: self.raiseError()) d.addCallback(lambda _: self.raiseError())
d.addErrback(log.fail(), 'My message') d.addErrback(self.log.fail(callback), 'My message')
d.callback(None) d.callback(None)
return d return d
def setUp(self):
self.log = log_support.Logger('test')
self.stream = StringIO.StringIO()
handler = logging.StreamHandler(self.stream)
handler.setFormatter(logging.Formatter("%(filename)s:%(lineno)d - %(message)s"))
self.log.addHandler(handler)
def test_can_log_failure(self): def test_can_log_failure(self):
def output_lines(): def output_lines():
return stream.getvalue().split('\n') return self.stream.getvalue().split('\n')
log = log_support.Logger('test')
stream = StringIO.StringIO()
handler = logging.StreamHandler(stream)
handler.setFormatter(logging.Formatter("%(filename)s:%(lineno)d - %(message)s"))
log.addHandler(handler)
# the line number could change if this file gets refactored # the line number could change if this file gets refactored
expected_first_line = 'test_log_support.py:17 - My message: terrible things happened' expected_first_line = 'test_log_support.py:18 - My message: terrible things happened'
# testing the entirety of the message is futile as the # testing the entirety of the message is futile as the
# traceback will depend on the system the test is being run on # traceback will depend on the system the test is being run on
# but hopefully these two tests are good enough # but hopefully these two tests are good enough
d = self.triggerErrback(log) d = self.triggerErrback()
d.addCallback(lambda _: self.assertEquals(expected_first_line, output_lines()[0])) d.addCallback(lambda _: self.assertEquals(expected_first_line, output_lines()[0]))
d.addCallback(lambda _: self.assertEqual(10, len(output_lines()))) d.addCallback(lambda _: self.assertEqual(10, len(output_lines())))
return d return d
def test_can_log_failure_with_callback(self):
callback = mock.Mock()
d = self.triggerErrback(callback)
d.addCallback(lambda _: callback.assert_called_once_with(mock.ANY))
return d