diff --git a/NEWS b/NEWS index 5deb6d1..8676ef1 100644 --- a/NEWS +++ b/NEWS @@ -9,6 +9,14 @@ Next Changes ------- +* ``AsynchronousDeferredRunTest`` now has ``suppress_twisted_logging`` and + ``store_twisted_logs`` parameters that can be used to override the default + logging behaviour. (Jonathan Lange, #942785) + +* New fixture ``CaptureTwistedLogs`` that can be used with + ``AsynchronousDeferredRunTest`` to attach a detail containing everything + logged to Twisted during the test run. (Jonathan Lange, #1515362) + * Python 2.6 and 3.2 are no longer supported. If you want to use either of these versions of Python, use testtools 1.9.0. (Jonathan Lange) diff --git a/doc/api.rst b/doc/api.rst index 9683fb9..e33f71d 100644 --- a/doc/api.rst +++ b/doc/api.rst @@ -30,3 +30,4 @@ testtools.twistedsupport .. automodule:: testtools.twistedsupport :members: + :special-members: __init__ diff --git a/doc/for-test-authors.rst b/doc/for-test-authors.rst index 4e657b0..98f934c 100644 --- a/doc/for-test-authors.rst +++ b/doc/for-test-authors.rst @@ -984,6 +984,7 @@ exception or mangle the display. In most cases simply avoiding the ``%s`` format specifier and using ``%r`` instead will be enough. For examples of more complex formatting see the ``testtools.matchers`` implementatons. +.. _details: Details ======= @@ -1254,7 +1255,7 @@ Twisted support --------------- testtools provides support for running Twisted tests – tests that return a -Deferred_ and rely on the Twisted reactor. See (XXX - jml - insert link) +Deferred_ and rely on the Twisted reactor. See :ref:`twisted-support`. force_failure ------------- diff --git a/doc/twisted-support.rst b/doc/twisted-support.rst index 8cf3742..3ec6d0f 100644 --- a/doc/twisted-support.rst +++ b/doc/twisted-support.rst @@ -1,3 +1,5 @@ +.. _twisted-support: + Twisted support =============== @@ -72,6 +74,47 @@ test runner:: # ... return d +See :py:class:`~testtools.twistedsupport.AsynchronousDeferredRunTest` and +:py:class:`~testtools.twistedsupport.AsynchronousDeferredRunTestForBrokenTwisted` +for more information. + + +Controlling the Twisted logs +---------------------------- + +Users of Twisted Trial will be accustomed to all tests logging to +``_trial_temp/test.log``. By default, +:py:class:`~testtools.twistedsupport.AsynchronousDeferredRunTest` will *not* +do this, but will instead: + + 1. suppress all messages logged during the test run + 2. attach them as the ``twisted-log`` detail (see :ref:`details`) which is + shown if the test fails + +The first behavior is controlled by the ``suppress_twisted_logging`` parameter +to :py:class:`~testtools.twistedsupport.AsynchronousDeferredRunTest`, which is +set to ``True`` by default. The second is controlled by the +``store_twisted_logs`` parameter, which is also ``True`` by default. + +If ``store_twisted_logs`` is set to ``False``, you can still get the logs +attached as a detail by using the +:py:class:`~testtools.twistedsupport.CaptureTwistedLogs` fixture. Using the +:py:class:`~testtools.twistedsupport.CaptureTwistedLogs` fixture is equivalent +to setting ``store_twisted_logs`` to ``True``. + +For example:: + + class DoNotCaptureLogsTests(TestCase): + run_tests_with = partial(AsynchronousDeferredRunTest, + store_twisted_logs=False) + + def test_foo(self): + log.msg('logs from this test are not attached') + + def test_bar(self): + self.useFixture(CaptureTwistedLogs()) + log.msg('logs from this test *are* attached') + Converting Trial tests to testtools tests ----------------------------------------- diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py index bfdd5de..8cf609d 100644 --- a/testtools/deferredruntest.py +++ b/testtools/deferredruntest.py @@ -145,8 +145,27 @@ class _ErrorObserver(Fixture): return self._error_observer.flushErrors(*error_types) -class _CaptureTwistedLogs(Fixture): - """Capture all the Twisted logs and add them as a detail.""" +class CaptureTwistedLogs(Fixture): + """Capture all the Twisted logs and add them as a detail. + + Much of the time, you won't need to use this directly, as + :py:class:`AsynchronousDeferredRunTest` captures Twisted logs when the + ``store_twisted_logs`` is set to ``True`` (which it is by default). + + However, if you want to do custom processing of Twisted's logs, then this + class can be useful. + + For example:: + + class TwistedTests(TestCase): + run_tests_with( + partial(AsynchronousDeferredRunTest, store_twisted_logs=False)) + + def setUp(self): + super(TwistedTests, self).setUp() + twisted_logs = self.useFixture(CaptureTwistedLogs()) + # ... do something with twisted_logs ... + """ LOG_DETAIL_NAME = 'twisted-log' @@ -223,8 +242,9 @@ class AsynchronousDeferredRunTest(_DeferredRunTest): """ def __init__(self, case, handlers=None, last_resort=None, reactor=None, - timeout=0.005, debug=False): - """Construct an `AsynchronousDeferredRunTest`. + timeout=0.005, debug=False, suppress_twisted_logging=True, + store_twisted_logs=True): + """Construct an ``AsynchronousDeferredRunTest``. Please be sure to always use keyword syntax, not positional, as the base class may add arguments in future - and for core code @@ -244,6 +264,11 @@ class AsynchronousDeferredRunTest(_DeferredRunTest): :param debug: Whether or not to enable Twisted's debugging. Use this to get information about unhandled Deferreds and left-over DelayedCalls. Defaults to False. + :param bool suppress_twisted_logging: If True, then suppress Twisted's + default logging while the test is being run. Defaults to True. + :param bool store_twisted_logs: If True, then store the Twisted logs + that took place during the run as the 'twisted-log' detail. + Defaults to True. """ super(AsynchronousDeferredRunTest, self).__init__( case, handlers, last_resort) @@ -252,9 +277,12 @@ class AsynchronousDeferredRunTest(_DeferredRunTest): self._reactor = reactor self._timeout = timeout self._debug = debug + self._suppress_twisted_logging = suppress_twisted_logging + self._store_twisted_logs = store_twisted_logs @classmethod - def make_factory(cls, reactor=None, timeout=0.005, debug=False): + def make_factory(cls, reactor=None, timeout=0.005, debug=False, + suppress_twisted_logging=True, store_twisted_logs=True): """Make a factory that conforms to the RunTest factory interface. Example:: @@ -270,7 +298,9 @@ class AsynchronousDeferredRunTest(_DeferredRunTest): class AsynchronousDeferredRunTestFactory: def __call__(self, case, handlers=None, last_resort=None): return cls( - case, handlers, last_resort, reactor, timeout, debug) + case, handlers, last_resort, reactor, timeout, debug, + suppress_twisted_logging, store_twisted_logs, + ) return AsynchronousDeferredRunTestFactory() @defer.deferredGenerator @@ -371,6 +401,17 @@ class AsynchronousDeferredRunTest(_DeferredRunTest): self._log_user_exception(TimeoutError(self.case, self._timeout)) return False, [] + def _get_log_fixture(self): + """Return the log fixture we're configured to use.""" + fixtures = [] + # TODO: Expose these fixtures and deprecate both of these options in + # favour of them. + if self._suppress_twisted_logging: + fixtures.append(_NoTwistedLogObservers()) + if self._store_twisted_logs: + fixtures.append(CaptureTwistedLogs()) + return _CompoundFixture(fixtures) + def _run_core(self): # XXX: Blatting over the namespace of the test case isn't a nice thing # to do. Find a better way of communicating between runtest and test @@ -378,17 +419,11 @@ class AsynchronousDeferredRunTest(_DeferredRunTest): self.case.reactor = self._reactor spinner = self._make_spinner() - # XXX: We want to make the use of these _NoTwistedLogObservers and - # _CaptureTwistedLogs optional, and ideally, make it so they aren't - # used by default. - logging_fixture = _CompoundFixture( - [_NoTwistedLogObservers(), _CaptureTwistedLogs()]) - # We can't just install these as fixtures on self.case, because we # need the clean up to run even if the test times out. # # See https://bugs.launchpad.net/testtools/+bug/897196. - with logging_fixture as capture_logs: + with self._get_log_fixture() as capture_logs: for name, detail in capture_logs.getDetails().items(): self.case.addDetail(name, detail) with _ErrorObserver(_log_observer) as error_fixture: diff --git a/testtools/tests/test_deferredruntest.py b/testtools/tests/test_deferredruntest.py index 92cd624..68e1291 100644 --- a/testtools/tests/test_deferredruntest.py +++ b/testtools/tests/test_deferredruntest.py @@ -237,11 +237,15 @@ class TestAsynchronousDeferredRunTest(NeedsTwistedTestCase): def make_result(self): return ExtendedTestResult() - def make_runner(self, test, timeout=None): + def make_runner(self, test, timeout=None, suppress_twisted_logging=True, + store_twisted_logs=True): if timeout is None: timeout = self.make_timeout() return AsynchronousDeferredRunTest( - test, test.exception_handlers, timeout=timeout) + test, test.exception_handlers, timeout=timeout, + suppress_twisted_logging=suppress_twisted_logging, + store_twisted_logs=store_twisted_logs, + ) def make_timeout(self): return 0.005 @@ -629,7 +633,7 @@ class TestAsynchronousDeferredRunTest(NeedsTwistedTestCase): f = failure.Failure() log.err(f) test = LogAnError('test_something') - runner = self.make_runner(test) + runner = self.make_runner(test, store_twisted_logs=False) result = self.make_result() runner.run(result) self.assertThat( @@ -641,10 +645,6 @@ class TestAsynchronousDeferredRunTest(NeedsTwistedTestCase): 'Traceback (most recent call last):', 'ZeroDivisionError', ])), - 'twisted-log': AsText(ContainsAll([ - 'Traceback (most recent call last):', - 'ZeroDivisionError', - ])), }), ('stopTest', test))) @@ -660,28 +660,25 @@ class TestAsynchronousDeferredRunTest(NeedsTwistedTestCase): log.err(f) flush_logged_errors(ZeroDivisionError) test = LogAnError('test_something') - runner = self.make_runner(test) + runner = self.make_runner(test, store_twisted_logs=False) result = self.make_result() runner.run(result) self.assertThat( result._events, MatchesEvents( ('startTest', test), - ('addSuccess', test, { - 'twisted-log': AsText(ContainsAll([ - 'Traceback (most recent call last):', - 'ZeroDivisionError', - ])), - }), + ('addSuccess', test), ('stopTest', test))) def test_log_in_details(self): + # If store_twisted_logs is True, we include the Twisted logs as + # details. class LogAnError(TestCase): def test_something(self): log.msg("foo") 1/0 test = LogAnError('test_something') - runner = self.make_runner(test) + runner = self.make_runner(test, store_twisted_logs=True) result = self.make_result() runner.run(result) self.assertThat( @@ -695,9 +692,8 @@ class TestAsynchronousDeferredRunTest(NeedsTwistedTestCase): ('stopTest', test))) def test_do_not_log_to_twisted(self): - # By default, we don't log anything to the default Twisted loggers. - # XXX: We want to make this behaviour optional, and (ideally) - # deprecated. + # If suppress_twisted_logging is True, we don't log anything to the + # default Twisted loggers. messages = [] publisher, _ = _get_global_publisher_and_observers() publisher.addObserver(messages.append) @@ -708,11 +704,30 @@ class TestAsynchronousDeferredRunTest(NeedsTwistedTestCase): log.msg("foo") test = LogSomething('test_something') - runner = self.make_runner(test) + runner = self.make_runner(test, suppress_twisted_logging=True) result = self.make_result() runner.run(result) self.assertThat(messages, Equals([])) + def test_log_to_twisted(self): + # If suppress_twisted_logging is False, we log to the default Twisted + # loggers. + messages = [] + publisher, _ = _get_global_publisher_and_observers() + publisher.addObserver(messages.append) + + class LogSomething(TestCase): + def test_something(self): + log.msg("foo") + + test = LogSomething('test_something') + runner = self.make_runner(test, suppress_twisted_logging=False) + result = self.make_result() + runner.run(result) + self.assertThat( + messages, + MatchesListwise([ContainsDict({'message': Equals(('foo',))})])) + def test_restore_observers(self): # We restore the original observers. publisher, observers = _get_global_publisher_and_observers() @@ -978,15 +993,15 @@ class TestErrorObserver(NeedsTwistedTestCase): class TestCaptureTwistedLogs(NeedsTwistedTestCase): - """Tests for _CaptureTwistedLogs.""" + """Tests for CaptureTwistedLogs.""" def test_captures_logs(self): - # _CaptureTwistedLogs stores all Twisted log messages as a detail. - from testtools.deferredruntest import _CaptureTwistedLogs + # CaptureTwistedLogs stores all Twisted log messages as a detail. + from testtools.deferredruntest import CaptureTwistedLogs class SomeTest(TestCase): def test_something(self): - self.useFixture(_CaptureTwistedLogs()) + self.useFixture(CaptureTwistedLogs()) log.msg('foo') test = SomeTest('test_something') diff --git a/testtools/twistedsupport/__init__.py b/testtools/twistedsupport/__init__.py index 302c6a4..98f7a5c 100644 --- a/testtools/twistedsupport/__init__.py +++ b/testtools/twistedsupport/__init__.py @@ -12,6 +12,7 @@ __all__ = [ 'AsynchronousDeferredRunTest', 'AsynchronousDeferredRunTestForBrokenTwisted', 'SynchronousDeferredRunTest', + 'CaptureTwistedLogs', 'assert_fails_with', 'flush_logged_errors', ] @@ -26,6 +27,7 @@ from testtools.deferredruntest import ( AsynchronousDeferredRunTest, AsynchronousDeferredRunTestForBrokenTwisted, SynchronousDeferredRunTest, + CaptureTwistedLogs, assert_fails_with, flush_logged_errors, )