diff --git a/lbrynet/core/log_support.py b/lbrynet/core/log_support.py index 9f6ad2222..c57c063d6 100644 --- a/lbrynet/core/log_support.py +++ b/lbrynet/core/log_support.py @@ -332,7 +332,7 @@ class LogUploader(object): class Logger(logging.Logger): """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. 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 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 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 keywoards are treated as normal log kwargs. - """ fn, lno, func = findCaller() - def _fail(err, msg, *args, **kwargs): + def _fail(err, msg, *msg_args, **kwargs): level = kwargs.pop('level', logging.ERROR) msg += ": %s" - args += (err.getErrorMessage(),) + msg_args += (err.getErrorMessage(),) exc_info = (err.type, err.value, err.getTracebackObject()) 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) + if callback: + callback(err, *args) return _fail diff --git a/tests/unit/core/test_log_support.py b/tests/unit/core/test_log_support.py index 07ea5946d..cf7bdfc27 100644 --- a/tests/unit/core/test_log_support.py +++ b/tests/unit/core/test_log_support.py @@ -1,6 +1,7 @@ import StringIO import logging +import mock from twisted.internet import defer from twisted.trial import unittest @@ -11,30 +12,37 @@ class TestLogger(unittest.TestCase): def raiseError(self): raise Exception('terrible things happened') - def triggerErrback(self, log): + def triggerErrback(self, callback=None): d = defer.Deferred() d.addCallback(lambda _: self.raiseError()) - d.addErrback(log.fail(), 'My message') + d.addErrback(self.log.fail(callback), 'My message') d.callback(None) 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 output_lines(): - return 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) + return self.stream.getvalue().split('\n') # 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 # traceback will depend on the system the test is being run on # 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.assertEqual(10, len(output_lines()))) 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