From cac9e416266a717a5d1fa05995e5253874ee6ebd Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Thu, 28 Oct 2010 17:31:00 -0400
Subject: [PATCH 01/17] Make it possible to use the factory as a class
 variable.

---
 testtools/deferredruntest.py            | 10 ++++++++--
 testtools/tests/test_deferredruntest.py | 10 ++++++++++
 2 files changed, 18 insertions(+), 2 deletions(-)

diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py
index f2cac92..aaed287 100644
--- a/testtools/deferredruntest.py
+++ b/testtools/deferredruntest.py
@@ -75,8 +75,14 @@ class AsynchronousDeferredRunTest(RunTest):
     @classmethod
     def make_factory(cls, reactor=None, timeout=0.005):
         """Make a factory that conforms to the RunTest factory interface."""
-        return lambda case, handlers=None: AsynchronousDeferredRunTest(
-            case, handlers, reactor, timeout)
+        # This is horrible, but it means that the return value of the method
+        # will be able to be assigned to a class variable *and* also be
+        # invoked directly.
+        class AsynchronousDeferredRunTestFactory:
+            def __call__(self, case, handlers=None):
+                return AsynchronousDeferredRunTest(
+                    case, handlers, reactor, timeout)
+        return AsynchronousDeferredRunTestFactory()
 
     @defer.deferredGenerator
     def _run_cleanups(self):
diff --git a/testtools/tests/test_deferredruntest.py b/testtools/tests/test_deferredruntest.py
index 19f4ef0..a82f2a1 100644
--- a/testtools/tests/test_deferredruntest.py
+++ b/testtools/tests/test_deferredruntest.py
@@ -419,6 +419,16 @@ class TestAsynchronousDeferredRunTest(TestCase):
         self.assertIs(self, runner.case)
         self.assertEqual([handler], runner.handlers)
 
+    def test_use_convenient_factory(self):
+        # Make sure that the factory can actually be used.
+        factory = AsynchronousDeferredRunTest.make_factory()
+        class SomeCase(TestCase):
+            run_tests_with = factory
+            def test_something(self):
+                pass
+        case = SomeCase('test_something')
+        case.run()
+
     def test_convenient_construction_default_reactor(self):
         # As a convenience method, AsynchronousDeferredRunTest has a
         # classmethod that returns an AsynchronousDeferredRunTest

From fb1b81249f28fb284336d517df736e4ac1273f6a Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Thu, 28 Oct 2010 18:06:41 -0400
Subject: [PATCH 02/17] Add a convenience function for string content.

---
 testtools/content.py            | 10 +++++++++-
 testtools/deferredruntest.py    |  1 +
 testtools/tests/test_content.py | 12 ++++++++++--
 3 files changed, 20 insertions(+), 3 deletions(-)

diff --git a/testtools/content.py b/testtools/content.py
index 843133a..03263b4 100644
--- a/testtools/content.py
+++ b/testtools/content.py
@@ -5,7 +5,7 @@
 import codecs
 
 from testtools.compat import _b
-from testtools.content_type import ContentType
+from testtools.content_type import ContentType, UTF8_TEXT
 from testtools.testresult import TestResult
 
 
@@ -89,3 +89,11 @@ class TracebackContent(Content):
         value = self._result._exc_info_to_unicode(err, test)
         super(TracebackContent, self).__init__(
             content_type, lambda: [value.encode("utf8")])
+
+
+def text_content(text):
+    """Create a `Content` object from some text.
+
+    This is useful for adding details which are short strings.
+    """
+    return Content(UTF8_TEXT, lambda: [text.encode('utf8')])
diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py
index aaed287..d1fea41 100644
--- a/testtools/deferredruntest.py
+++ b/testtools/deferredruntest.py
@@ -179,6 +179,7 @@ class AsynchronousDeferredRunTest(RunTest):
             # present.
             for debug_info in unhandled:
                 f = debug_info.failResult
+                
                 self._got_user_exception(
                     (f.type, f.value, f.tb), 'unhandled-error-in-deferred')
         junk = spinner.clear_junk()
diff --git a/testtools/tests/test_content.py b/testtools/tests/test_content.py
index 741256e..3299a62 100644
--- a/testtools/tests/test_content.py
+++ b/testtools/tests/test_content.py
@@ -3,8 +3,8 @@
 import unittest
 from testtools import TestCase
 from testtools.compat import _u
-from testtools.content import Content, TracebackContent
-from testtools.content_type import ContentType
+from testtools.content import Content, TracebackContent, text_content
+from testtools.content_type import ContentType, UTF8_TEXT
 from testtools.tests.helpers import an_exc_info
 
 
@@ -68,6 +68,14 @@ class TestTracebackContent(TestCase):
         self.assertEqual(expected, ''.join(list(content.iter_text())))
 
 
+class TestBytesContent(TestCase):
+
+    def test_bytes(self):
+        data = _u("some data")
+        expected = Content(UTF8_TEXT, lambda: [data.encode('utf8')])
+        self.assertEqual(expected, text_content(data))
+
+
 def test_suite():
     from unittest import TestLoader
     return TestLoader().loadTestsFromName(__name__)

From 818b913bc7855c14afc8ed2705ed597c4e39aa33 Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Thu, 28 Oct 2010 18:09:05 -0400
Subject: [PATCH 03/17] Log the creator and invoker data if we have them.

---
 testtools/deferredruntest.py | 9 ++++++---
 1 file changed, 6 insertions(+), 3 deletions(-)

diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py
index d1fea41..404f05c 100644
--- a/testtools/deferredruntest.py
+++ b/testtools/deferredruntest.py
@@ -14,6 +14,7 @@ __all__ = [
 
 import sys
 
+from testtools.content import text_content
 from testtools.runtest import RunTest
 from testtools._spinner import (
     extract_result,
@@ -175,11 +176,13 @@ class AsynchronousDeferredRunTest(RunTest):
 
         if unhandled:
             successful = False
-            # XXX: Maybe we could log creator & invoker here as well if
-            # present.
             for debug_info in unhandled:
                 f = debug_info.failResult
-                
+                info = debug_info._getDebugTracebacks()
+                if info:
+                    self.case.addDetail(
+                        'unhandled-error-in-deferred-debug',
+                        text_content(info))
                 self._got_user_exception(
                     (f.type, f.value, f.tb), 'unhandled-error-in-deferred')
         junk = spinner.clear_junk()

From 4cc9fb4f3901ae1212058cd3a9dc313f2dff59c4 Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Fri, 29 Oct 2010 12:46:31 -0400
Subject: [PATCH 04/17] Actually make the tests fail when they have errors in
 Deferreds.

---
 testtools/deferredruntest.py            |  8 +++--
 testtools/tests/test_deferredruntest.py | 43 +++++++++++++++++++++++++
 2 files changed, 48 insertions(+), 3 deletions(-)

diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py
index 404f05c..a56d1a4 100644
--- a/testtools/deferredruntest.py
+++ b/testtools/deferredruntest.py
@@ -198,9 +198,11 @@ class AsynchronousDeferredRunTest(RunTest):
         This just makes sure that it returns a Deferred, regardless of how the
         user wrote it.
         """
-        return defer.maybeDeferred(
-            super(AsynchronousDeferredRunTest, self)._run_user,
-            function, *args)
+        d = defer.maybeDeferred(function, *args)
+        def got_user_exception(failure):
+            return self._got_user_exception(
+                (failure.type, failure.value, failure.tb))
+        return d.addErrback(got_user_exception)
 
 
 def assert_fails_with(d, *exc_types, **kwargs):
diff --git a/testtools/tests/test_deferredruntest.py b/testtools/tests/test_deferredruntest.py
index a82f2a1..2fb293f 100644
--- a/testtools/tests/test_deferredruntest.py
+++ b/testtools/tests/test_deferredruntest.py
@@ -351,6 +351,32 @@ class TestAsynchronousDeferredRunTest(TestCase):
                 'unhandled-error-in-deferred-1',
                 ]))
 
+    def test_unhandled_error_from_deferred_combined_with_error(self):
+        # If there's a Deferred with an unhandled error, the test fails.  Each
+        # unhandled error is reported with a separate traceback, and the error
+        # is still reported.
+        class SomeCase(TestCase):
+            def test_cruft(self):
+                # Note we aren't returning the Deferred so that the error will
+                # be unhandled.
+                defer.maybeDeferred(lambda: 1/0)
+                2 / 0
+        test = SomeCase('test_cruft')
+        runner = self.make_runner(test)
+        result = self.make_result()
+        runner.run(result)
+        error = result._events[1][2]
+        result._events[1] = ('addError', test, None)
+        self.assertThat(result._events, Equals(
+            [('startTest', test),
+             ('addError', test, None),
+             ('stopTest', test)]))
+        self.assertThat(
+            sorted(list(error.keys())), Equals([
+                'traceback',
+                'unhandled-error-in-deferred',
+                ]))
+
     @skipIf(os.name != "posix", "Sending SIGINT with os.kill is posix only")
     def test_keyboard_interrupt_stops_test_run(self):
         # If we get a SIGINT during a test run, the test stops and no more
@@ -453,6 +479,23 @@ class TestAsynchronousDeferredRunTest(TestCase):
         self.assertIs(self, runner.case)
         self.assertEqual([handler], runner.handlers)
 
+    def test_deferred_error(self):
+        class SomeTest(TestCase):
+            def test_something(self):
+                return defer.maybeDeferred(lambda: 1/0)
+        test = SomeTest('test_something')
+        runner = self.make_runner(test)
+        result = self.make_result()
+        runner.run(result)
+        self.assertThat(
+            [event[:2] for event in result._events],
+            Equals([
+                ('startTest', test),
+                ('addError', test),
+                ('stopTest', test)]))
+        error = result._events[1][2]
+        self.assertThat(sorted(error.keys()), Equals(['traceback']))
+
     def test_only_addError_once(self):
         # Even if the reactor is unclean and the test raises an error and the
         # cleanups raise errors, we only called addError once per test.

From 7df84b56b8b34190ff405e184146016213bb4464 Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Fri, 29 Oct 2010 13:04:06 -0400
Subject: [PATCH 05/17] Extract some common code for logging user failures.

---
 testtools/deferredruntest.py | 13 +++++++------
 1 file changed, 7 insertions(+), 6 deletions(-)

diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py
index a56d1a4..c5508b8 100644
--- a/testtools/deferredruntest.py
+++ b/testtools/deferredruntest.py
@@ -73,6 +73,11 @@ class AsynchronousDeferredRunTest(RunTest):
         self._reactor = reactor
         self._timeout = timeout
 
+    def _got_user_failure(self, failure, tb_label='traceback'):
+        """We got a failure from user code."""
+        return self._got_user_exception(
+            (failure.type, failure.value, failure.tb), tb_label=tb_label)
+
     @classmethod
     def make_factory(cls, reactor=None, timeout=0.005):
         """Make a factory that conforms to the RunTest factory interface."""
@@ -183,8 +188,7 @@ class AsynchronousDeferredRunTest(RunTest):
                     self.case.addDetail(
                         'unhandled-error-in-deferred-debug',
                         text_content(info))
-                self._got_user_exception(
-                    (f.type, f.value, f.tb), 'unhandled-error-in-deferred')
+                self._got_user_failure(f, 'unhandled-error-in-deferred')
         junk = spinner.clear_junk()
         if junk:
             successful = False
@@ -199,10 +203,7 @@ class AsynchronousDeferredRunTest(RunTest):
         user wrote it.
         """
         d = defer.maybeDeferred(function, *args)
-        def got_user_exception(failure):
-            return self._got_user_exception(
-                (failure.type, failure.value, failure.tb))
-        return d.addErrback(got_user_exception)
+        return d.addErrback(self._got_user_failure)
 
 
 def assert_fails_with(d, *exc_types, **kwargs):

From 3b2ca357036ff68bff2ebe8b6676760c8529bdcb Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Sat, 30 Oct 2010 17:28:27 -0400
Subject: [PATCH 06/17] Fail tests on logged errors, include the error.

---
 testtools/deferredruntest.py            | 27 ++++++++++-
 testtools/tests/test_deferredruntest.py | 64 +++++++++++++++++++++----
 2 files changed, 81 insertions(+), 10 deletions(-)

diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py
index c5508b8..f09044a 100644
--- a/testtools/deferredruntest.py
+++ b/testtools/deferredruntest.py
@@ -14,7 +14,9 @@ __all__ = [
 
 import sys
 
-from testtools.content import text_content
+from testtools.content import (
+    text_content,
+    )
 from testtools.runtest import RunTest
 from testtools._spinner import (
     extract_result,
@@ -25,6 +27,7 @@ from testtools._spinner import (
     )
 
 from twisted.internet import defer
+from twisted.trial.unittest import _LogObserver
 
 
 # TODO: Need a conversion guide for flushLoggedErrors
@@ -42,6 +45,11 @@ class SynchronousDeferredRunTest(RunTest):
         return result
 
 
+# Observer of the Twisted log that we install during tests.
+_log_observer = _LogObserver()
+
+
+
 class AsynchronousDeferredRunTest(RunTest):
     """Runner for tests that return Deferreds that fire asynchronously.
 
@@ -164,6 +172,10 @@ class AsynchronousDeferredRunTest(RunTest):
             self._got_user_exception(sys.exc_info())
 
     def _run_core(self):
+        # Add an observer to trap all logged errors.
+        test_observer = _log_observer
+        test_observer._add()
+
         spinner = Spinner(self._reactor)
         try:
             successful, unhandled = trap_unhandled_errors(
@@ -178,6 +190,13 @@ class AsynchronousDeferredRunTest(RunTest):
             # deferreds.  Report the timeout and skip to the end.
             self._log_user_exception(TimeoutError(self.case, self._timeout))
             return
+        finally:
+            test_observer._remove()
+
+        logged_errors = test_observer.flushErrors()
+        for logged_error in logged_errors:
+            successful = False
+            self._got_user_failure(logged_error, tb_label='logged-error')
 
         if unhandled:
             successful = False
@@ -189,10 +208,12 @@ class AsynchronousDeferredRunTest(RunTest):
                         'unhandled-error-in-deferred-debug',
                         text_content(info))
                 self._got_user_failure(f, 'unhandled-error-in-deferred')
+
         junk = spinner.clear_junk()
         if junk:
             successful = False
             self._log_user_exception(UncleanReactorError(junk))
+
         if successful:
             self.result.addSuccess(self.case, details=self.case.getDetails())
 
@@ -240,6 +261,10 @@ def assert_fails_with(d, *exc_types, **kwargs):
     return d.addCallbacks(got_success, got_failure)
 
 
+def flush_logged_errors(*error_types):
+    return _log_observer.flushErrors(*error_types)
+
+
 class UncleanReactorError(Exception):
     """Raised when the reactor has junk in it."""
 
diff --git a/testtools/tests/test_deferredruntest.py b/testtools/tests/test_deferredruntest.py
index 2fb293f..49524fa 100644
--- a/testtools/tests/test_deferredruntest.py
+++ b/testtools/tests/test_deferredruntest.py
@@ -12,6 +12,7 @@ from testtools import (
 from testtools.deferredruntest import (
     assert_fails_with,
     AsynchronousDeferredRunTest,
+    flush_logged_errors,
     SynchronousDeferredRunTest,
     )
 from testtools.tests.helpers import ExtendedTestResult
@@ -21,7 +22,7 @@ from testtools.matchers import (
 from testtools.runtest import RunTest
 
 from twisted.internet import defer
-from twisted.python import failure
+from twisted.python import failure, log
 
 
 class X(object):
@@ -281,21 +282,21 @@ class TestAsynchronousDeferredRunTest(TestCase):
             def test_whatever(self):
                 pass
         test = SomeCase('test_whatever')
-        log = []
-        a = defer.Deferred().addCallback(lambda x: log.append('a'))
-        b = defer.Deferred().addCallback(lambda x: log.append('b'))
-        c = defer.Deferred().addCallback(lambda x: log.append('c'))
+        call_log = []
+        a = defer.Deferred().addCallback(lambda x: call_log.append('a'))
+        b = defer.Deferred().addCallback(lambda x: call_log.append('b'))
+        c = defer.Deferred().addCallback(lambda x: call_log.append('c'))
         test.addCleanup(lambda: a)
         test.addCleanup(lambda: b)
         test.addCleanup(lambda: c)
         def fire_a():
-            self.assertThat(log, Equals([]))
+            self.assertThat(call_log, Equals([]))
             a.callback(None)
         def fire_b():
-            self.assertThat(log, Equals(['a']))
+            self.assertThat(call_log, Equals(['a']))
             b.callback(None)
         def fire_c():
-            self.assertThat(log, Equals(['a', 'b']))
+            self.assertThat(call_log, Equals(['a', 'b']))
             c.callback(None)
         timeout = self.make_timeout()
         reactor = self.make_reactor()
@@ -305,7 +306,7 @@ class TestAsynchronousDeferredRunTest(TestCase):
         runner = self.make_runner(test, timeout)
         result = self.make_result()
         runner.run(result)
-        self.assertThat(log, Equals(['a', 'b', 'c']))
+        self.assertThat(call_log, Equals(['a', 'b', 'c']))
 
     def test_clean_reactor(self):
         # If there's cruft left over in the reactor, the test fails.
@@ -530,6 +531,51 @@ class TestAsynchronousDeferredRunTest(TestCase):
                 'unhandled-error-in-deferred',
                 ]))
 
+    def test_log_err_is_error(self):
+        # An error logged during the test run is recorded as an error in the
+        # tests.
+        class LogAnError(TestCase):
+            def test_something(self):
+                try:
+                    1/0
+                except ZeroDivisionError:
+                    f = failure.Failure()
+                log.err(f)
+        test = LogAnError('test_something')
+        runner = self.make_runner(test)
+        result = self.make_result()
+        runner.run(result)
+        self.assertThat(
+            [event[:2] for event in result._events],
+            Equals([
+                ('startTest', test),
+                ('addError', test),
+                ('stopTest', test)]))
+        error = result._events[1][2]
+        self.assertThat(sorted(error.keys()), Equals(['logged-error']))
+
+    def test_log_err_flushed_is_success(self):
+        # An error logged during the test run is recorded as an error in the
+        # tests.
+        class LogAnError(TestCase):
+            def test_something(self):
+                try:
+                    1/0
+                except ZeroDivisionError:
+                    f = failure.Failure()
+                log.err(f)
+                flush_logged_errors(ZeroDivisionError)
+        test = LogAnError('test_something')
+        runner = self.make_runner(test)
+        result = self.make_result()
+        runner.run(result)
+        self.assertThat(
+            result._events,
+            Equals([
+                ('startTest', test),
+                ('addSuccess', test),
+                ('stopTest', test)]))
+
 
 class TestAssertFailsWith(TestCase):
     """Tests for `assert_fails_with`."""

From 0ae9fc418501bf5db0763d4a2df940fd956ea74b Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Sat, 30 Oct 2010 17:37:54 -0400
Subject: [PATCH 07/17] Move out the bit that actually runs the test so we can
 more easily wrap it with things.

---
 testtools/deferredruntest.py | 23 ++++++++++++-----------
 1 file changed, 12 insertions(+), 11 deletions(-)

diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py
index f09044a..f73cc5d 100644
--- a/testtools/deferredruntest.py
+++ b/testtools/deferredruntest.py
@@ -171,25 +171,26 @@ class AsynchronousDeferredRunTest(RunTest):
         except e.__class__:
             self._got_user_exception(sys.exc_info())
 
-    def _run_core(self):
-        # Add an observer to trap all logged errors.
-        test_observer = _log_observer
-        test_observer._add()
-
-        spinner = Spinner(self._reactor)
+    def _blocking_run_deferred(self, spinner):
         try:
-            successful, unhandled = trap_unhandled_errors(
+            return trap_unhandled_errors(
                 spinner.run, self._timeout, self._run_deferred)
         except NoResultError:
             # We didn't get a result at all!  This could be for any number of
             # reasons, but most likely someone hit Ctrl-C during the test.
             raise KeyboardInterrupt
         except TimeoutError:
-            # The function took too long to run.  No point reporting about
-            # junk and we don't have any information about unhandled errors in
-            # deferreds.  Report the timeout and skip to the end.
+            # The function took too long to run.
             self._log_user_exception(TimeoutError(self.case, self._timeout))
-            return
+            return False, []
+
+    def _run_core(self):
+        # Add an observer to trap all logged errors.
+        test_observer = _log_observer
+        test_observer._add()
+        spinner = Spinner(self._reactor)
+        try:
+            successful, unhandled = self._blocking_run_deferred(spinner)
         finally:
             test_observer._remove()
 

From 4d6431d68c153f635c826e0160ba5cbb055c1695 Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Sat, 30 Oct 2010 17:40:07 -0400
Subject: [PATCH 08/17] Silence the dump of logging to stdout/stderr by
 completely masking the log observers for the test

---
 testtools/deferredruntest.py | 23 ++++++++++++++++++-----
 1 file changed, 18 insertions(+), 5 deletions(-)

diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py
index f73cc5d..f1a98b8 100644
--- a/testtools/deferredruntest.py
+++ b/testtools/deferredruntest.py
@@ -27,6 +27,7 @@ from testtools._spinner import (
     )
 
 from twisted.internet import defer
+from twisted.python import log
 from twisted.trial.unittest import _LogObserver
 
 
@@ -45,6 +46,21 @@ class SynchronousDeferredRunTest(RunTest):
         return result
 
 
+def run_with_log_observers(observers, function, *args, **kwargs):
+    real_observers = log.theLogPublisher.observers
+    for observer in real_observers:
+        log.theLogPublisher.removeObserver(observer)
+    for observer in observers:
+        log.theLogPublisher.addObserver(observer)
+    try:
+        return function(*args, **kwargs)
+    finally:
+        for observer in observers:
+            log.theLogPublisher.removeObserver(observer)
+        for observer in real_observers:
+            log.theLogPublisher.addObserver(observer)
+
+
 # Observer of the Twisted log that we install during tests.
 _log_observer = _LogObserver()
 
@@ -187,12 +203,9 @@ class AsynchronousDeferredRunTest(RunTest):
     def _run_core(self):
         # Add an observer to trap all logged errors.
         test_observer = _log_observer
-        test_observer._add()
         spinner = Spinner(self._reactor)
-        try:
-            successful, unhandled = self._blocking_run_deferred(spinner)
-        finally:
-            test_observer._remove()
+        successful, unhandled = run_with_log_observers(
+            [test_observer.gotEvent], self._blocking_run_deferred, spinner)
 
         logged_errors = test_observer.flushErrors()
         for logged_error in logged_errors:

From f35f80ff79031b3332229fd4f22137adc36d9670 Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Sat, 30 Oct 2010 17:51:12 -0400
Subject: [PATCH 09/17] Actually display the trapped log information in failing
 tests.

---
 testtools/deferredruntest.py            | 20 +++++++++++---
 testtools/tests/test_deferredruntest.py | 35 +++++++++++++++++++++----
 2 files changed, 47 insertions(+), 8 deletions(-)

diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py
index f1a98b8..6ebf2a2 100644
--- a/testtools/deferredruntest.py
+++ b/testtools/deferredruntest.py
@@ -12,11 +12,17 @@ __all__ = [
     'SynchronousDeferredRunTest',
     ]
 
+try:
+    from StringIO import StringIO
+except ImportError:
+    from io import StringIO
 import sys
 
 from testtools.content import (
+    Content,
     text_content,
     )
+from testtools.content_type import UTF8_TEXT
 from testtools.runtest import RunTest
 from testtools._spinner import (
     extract_result,
@@ -47,6 +53,7 @@ class SynchronousDeferredRunTest(RunTest):
 
 
 def run_with_log_observers(observers, function, *args, **kwargs):
+    """Run 'function' with the given Twisted log observers."""
     real_observers = log.theLogPublisher.observers
     for observer in real_observers:
         log.theLogPublisher.removeObserver(observer)
@@ -202,12 +209,15 @@ class AsynchronousDeferredRunTest(RunTest):
 
     def _run_core(self):
         # Add an observer to trap all logged errors.
-        test_observer = _log_observer
+        error_observer = _log_observer
+        full_log = StringIO()
+        full_observer = log.FileLogObserver(full_log)
         spinner = Spinner(self._reactor)
         successful, unhandled = run_with_log_observers(
-            [test_observer.gotEvent], self._blocking_run_deferred, spinner)
+            [error_observer.gotEvent, full_observer.emit],
+            self._blocking_run_deferred, spinner)
 
-        logged_errors = test_observer.flushErrors()
+        logged_errors = error_observer.flushErrors()
         for logged_error in logged_errors:
             successful = False
             self._got_user_failure(logged_error, tb_label='logged-error')
@@ -230,6 +240,10 @@ class AsynchronousDeferredRunTest(RunTest):
 
         if successful:
             self.result.addSuccess(self.case, details=self.case.getDetails())
+        else:
+            self.case.addDetail(
+                'twisted-log',
+                Content(UTF8_TEXT, lambda: [full_log.getvalue()]))
 
     def _run_user(self, function, *args):
         """Run a user-supplied function.
diff --git a/testtools/tests/test_deferredruntest.py b/testtools/tests/test_deferredruntest.py
index 49524fa..6a95f89 100644
--- a/testtools/tests/test_deferredruntest.py
+++ b/testtools/tests/test_deferredruntest.py
@@ -325,7 +325,8 @@ class TestAsynchronousDeferredRunTest(TestCase):
             [('startTest', test),
              ('addError', test, None),
              ('stopTest', test)]))
-        self.assertThat(list(error.keys()), Equals(['traceback']))
+        self.assertThat(
+            sorted(error.keys()), Equals(['traceback', 'twisted-log']))
 
     def test_unhandled_error_from_deferred(self):
         # If there's a Deferred with an unhandled error, the test fails.  Each
@@ -347,7 +348,8 @@ class TestAsynchronousDeferredRunTest(TestCase):
              ('addError', test, None),
              ('stopTest', test)]))
         self.assertThat(
-            list(error.keys()), Equals([
+            sorted(error.keys()), Equals([
+                'twisted-log',
                 'unhandled-error-in-deferred',
                 'unhandled-error-in-deferred-1',
                 ]))
@@ -373,8 +375,9 @@ class TestAsynchronousDeferredRunTest(TestCase):
              ('addError', test, None),
              ('stopTest', test)]))
         self.assertThat(
-            sorted(list(error.keys())), Equals([
+            sorted(error.keys()), Equals([
                 'traceback',
+                'twisted-log',
                 'unhandled-error-in-deferred',
                 ]))
 
@@ -495,7 +498,8 @@ class TestAsynchronousDeferredRunTest(TestCase):
                 ('addError', test),
                 ('stopTest', test)]))
         error = result._events[1][2]
-        self.assertThat(sorted(error.keys()), Equals(['traceback']))
+        self.assertThat(
+            sorted(error.keys()), Equals(['traceback', 'twisted-log']))
 
     def test_only_addError_once(self):
         # Even if the reactor is unclean and the test raises an error and the
@@ -528,6 +532,7 @@ class TestAsynchronousDeferredRunTest(TestCase):
                 'traceback',
                 'traceback-1',
                 'traceback-2',
+                'twisted-log',
                 'unhandled-error-in-deferred',
                 ]))
 
@@ -552,7 +557,8 @@ class TestAsynchronousDeferredRunTest(TestCase):
                 ('addError', test),
                 ('stopTest', test)]))
         error = result._events[1][2]
-        self.assertThat(sorted(error.keys()), Equals(['logged-error']))
+        self.assertThat(
+            sorted(error.keys()), Equals(['logged-error', 'twisted-log']))
 
     def test_log_err_flushed_is_success(self):
         # An error logged during the test run is recorded as an error in the
@@ -576,6 +582,25 @@ class TestAsynchronousDeferredRunTest(TestCase):
                 ('addSuccess', test),
                 ('stopTest', test)]))
 
+    def test_log_in_details(self):
+        class LogAnError(TestCase):
+            def test_something(self):
+                log.msg("foo")
+                1/0
+        test = LogAnError('test_something')
+        runner = self.make_runner(test)
+        result = self.make_result()
+        runner.run(result)
+        self.assertThat(
+            [event[:2] for event in result._events],
+            Equals([
+                ('startTest', test),
+                ('addError', test),
+                ('stopTest', test)]))
+        error = result._events[1][2]
+        self.assertThat(
+            sorted(error.keys()), Equals(['traceback', 'twisted-log']))
+
 
 class TestAssertFailsWith(TestCase):
     """Tests for `assert_fails_with`."""

From bc9569e067b7455481aee46112cf5ce6166dbbdc Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Sat, 30 Oct 2010 18:39:42 -0400
Subject: [PATCH 10/17] Ugly hack, but I think necessary.  Spin the reactor
 once before cleaning.

---
 testtools/_spinner.py | 4 ++++
 1 file changed, 4 insertions(+)

diff --git a/testtools/_spinner.py b/testtools/_spinner.py
index df8c6e2..b7fecf9 100644
--- a/testtools/_spinner.py
+++ b/testtools/_spinner.py
@@ -195,6 +195,10 @@ class Spinner(object):
 
     def _clean(self):
         """Clean up any junk in the reactor."""
+        # If we've just run a method that calls, say, loseConnection and then
+        # returns, then the reactor might not have had a chance to actually
+        # close the connection yet.  Here we explicitly give it such a chance.
+        self._reactor.iterate(0)
         junk = []
         for delayed_call in self._reactor.getDelayedCalls():
             delayed_call.cancel()

From 002803f9804a1bdf7210eabb23422e9682ee59d6 Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Sat, 30 Oct 2010 20:12:09 -0400
Subject: [PATCH 11/17] Things I need to do before I land.

---
 testtools/deferredruntest.py | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py
index 6ebf2a2..e93f085 100644
--- a/testtools/deferredruntest.py
+++ b/testtools/deferredruntest.py
@@ -106,6 +106,7 @@ class AsynchronousDeferredRunTest(RunTest):
 
     def _got_user_failure(self, failure, tb_label='traceback'):
         """We got a failure from user code."""
+        # XXX: We don't always get tracebacks from these.
         return self._got_user_exception(
             (failure.type, failure.value, failure.tb), tb_label=tb_label)
 
@@ -241,6 +242,8 @@ class AsynchronousDeferredRunTest(RunTest):
         if successful:
             self.result.addSuccess(self.case, details=self.case.getDetails())
         else:
+            # XXX: Maybe we should only add this when there is something worth
+            # adding? i.e. don't add when it's empty.
             self.case.addDetail(
                 'twisted-log',
                 Content(UTF8_TEXT, lambda: [full_log.getvalue()]))

From e7b67ef2315c5c2722d6d8481bf88aa1c5559c4d Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Sat, 30 Oct 2010 20:20:57 -0400
Subject: [PATCH 12/17] Actually, no we don't.

---
 testtools/deferredruntest.py | 2 --
 1 file changed, 2 deletions(-)

diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py
index e93f085..a3b811e 100644
--- a/testtools/deferredruntest.py
+++ b/testtools/deferredruntest.py
@@ -37,8 +37,6 @@ from twisted.python import log
 from twisted.trial.unittest import _LogObserver
 
 
-# TODO: Need a conversion guide for flushLoggedErrors
-
 class SynchronousDeferredRunTest(RunTest):
     """Runner for tests that return synchronous Deferreds."""
 

From a707db70476781adbcc6d4149fcfe74acad78c5d Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Sun, 31 Oct 2010 12:08:16 -0400
Subject: [PATCH 13/17] Make the test more robust in the face of a slow
 computer.

---
 testtools/tests/test_deferredruntest.py | 13 +++++++------
 1 file changed, 7 insertions(+), 6 deletions(-)

diff --git a/testtools/tests/test_deferredruntest.py b/testtools/tests/test_deferredruntest.py
index 6a95f89..2de02b3 100644
--- a/testtools/tests/test_deferredruntest.py
+++ b/testtools/tests/test_deferredruntest.py
@@ -314,17 +314,18 @@ class TestAsynchronousDeferredRunTest(TestCase):
         timeout = self.make_timeout()
         class SomeCase(TestCase):
             def test_cruft(self):
-                reactor.callLater(timeout * 2.0, lambda: None)
+                reactor.callLater(timeout * 10.0, lambda: None)
         test = SomeCase('test_cruft')
         runner = self.make_runner(test, timeout)
         result = self.make_result()
         runner.run(result)
+        self.assertThat(
+            [event[:2] for event in result._events],
+            Equals(
+                [('startTest', test),
+                 ('addError', test),
+                 ('stopTest', test)]))
         error = result._events[1][2]
-        result._events[1] = ('addError', test, None)
-        self.assertThat(result._events, Equals(
-            [('startTest', test),
-             ('addError', test, None),
-             ('stopTest', test)]))
         self.assertThat(
             sorted(error.keys()), Equals(['traceback', 'twisted-log']))
 

From 7a31bd4b460c17190cfa38fef6cae055f2057b5b Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Sun, 31 Oct 2010 12:11:45 -0400
Subject: [PATCH 14/17] Some simple changes from code review.

---
 testtools/_spinner.py        | 7 ++++++-
 testtools/deferredruntest.py | 5 +----
 2 files changed, 7 insertions(+), 5 deletions(-)

diff --git a/testtools/_spinner.py b/testtools/_spinner.py
index b7fecf9..365d193 100644
--- a/testtools/_spinner.py
+++ b/testtools/_spinner.py
@@ -194,7 +194,12 @@ class Spinner(object):
         self._stop_reactor()
 
     def _clean(self):
-        """Clean up any junk in the reactor."""
+        """Clean up any junk in the reactor.
+
+        This will *always* spin the reactor at least once.  We do this in
+        order to give the reactor a chance to do the disconnections and
+        terminations that were asked of it.
+        """
         # If we've just run a method that calls, say, loseConnection and then
         # returns, then the reactor might not have had a chance to actually
         # close the connection yet.  Here we explicitly give it such a chance.
diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py
index a3b811e..54299cd 100644
--- a/testtools/deferredruntest.py
+++ b/testtools/deferredruntest.py
@@ -240,11 +240,8 @@ class AsynchronousDeferredRunTest(RunTest):
         if successful:
             self.result.addSuccess(self.case, details=self.case.getDetails())
         else:
-            # XXX: Maybe we should only add this when there is something worth
-            # adding? i.e. don't add when it's empty.
             self.case.addDetail(
-                'twisted-log',
-                Content(UTF8_TEXT, lambda: [full_log.getvalue()]))
+                'twisted-log', Content(UTF8_TEXT, full_log.readlines))
 
     def _run_user(self, function, *args):
         """Run a user-supplied function.

From 6028b8046cdc643b453cf2ae5978fe02b02c9c6a Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Sun, 31 Oct 2010 12:25:47 -0400
Subject: [PATCH 15/17] Implement KeysEqual matcher.

---
 testtools/matchers.py            | 28 ++++++++++++++++++++++++++++
 testtools/tests/test_matchers.py | 26 ++++++++++++++++++++++++++
 2 files changed, 54 insertions(+)

diff --git a/testtools/matchers.py b/testtools/matchers.py
index 6208545..448d28e 100644
--- a/testtools/matchers.py
+++ b/testtools/matchers.py
@@ -342,6 +342,34 @@ class StartsWith(Matcher):
         return None
 
 
+class KeysEqual(Matcher):
+    """Checks whether a dict has particular keys."""
+
+    def __init__(self, *expected):
+        """Create a `KeysEqual` Matcher.
+
+        :param *expected: The keys the dict is expected to have.  If a dict,
+            then we use the keys of that dict, if a collection, we assume it
+            is a collection of expected keys.
+        """
+        try:
+            self.expected = expected.keys()
+        except AttributeError:
+            self.expected = list(expected)
+
+    def __str__(self):
+        return "KeysEqual(%s)" % ', '.join(map(repr, self.expected))
+
+    def match(self, matchee):
+        expected = sorted(self.expected)
+        matched = Equals(expected).match(sorted(matchee.keys()))
+        if matched:
+            return AnnotatedMismatch(
+                'Keys not equal',
+                _BinaryMismatch(expected, 'does not match', matchee))
+        return None
+
+
 class Annotate(object):
     """Annotates a matcher with a descriptive string.
 
diff --git a/testtools/tests/test_matchers.py b/testtools/tests/test_matchers.py
index b8406e7..270fa64 100644
--- a/testtools/tests/test_matchers.py
+++ b/testtools/tests/test_matchers.py
@@ -13,6 +13,7 @@ from testtools.matchers import (
     Equals,
     DocTestMatches,
     DoesNotStartWith,
+    KeysEqual,
     Is,
     LessThan,
     MatchesAny,
@@ -211,6 +212,31 @@ class TestMatchesAllInterface(TestCase, TestMatchersInterface):
                           1, MatchesAll(NotEquals(1), NotEquals(2)))]
 
 
+class TestKeysEqual(TestCase, TestMatchersInterface):
+
+    matches_matcher = KeysEqual('foo', 'bar')
+    matches_matches = [
+        {'foo': 0, 'bar': 1},
+        ]
+    matches_mismatches = [
+        {},
+        {'foo': 0},
+        {'bar': 1},
+        {'foo': 0, 'bar': 1, 'baz': 2},
+        {'a': None, 'b': None, 'c': None},
+        ]
+
+    str_examples = [
+        ("KeysEqual('foo', 'bar')", KeysEqual('foo', 'bar')),
+        ]
+
+    describe_examples = [
+        ("['bar', 'foo'] does not match {'baz': 2, 'foo': 0, 'bar': 1}: "
+         "Keys not equal",
+         {'foo': 0, 'bar': 1, 'baz': 2}, KeysEqual('foo', 'bar')),
+        ]
+
+
 class TestAnnotate(TestCase, TestMatchersInterface):
 
     matches_matcher = Annotate("foo", Equals(1))

From 53bf3e462aff069fad2073d6dd60475d5782f7c5 Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Sun, 31 Oct 2010 12:28:46 -0400
Subject: [PATCH 16/17] Use the new KeysEqual matcher.

---
 testtools/tests/test_deferredruntest.py | 25 +++++++++++--------------
 1 file changed, 11 insertions(+), 14 deletions(-)

diff --git a/testtools/tests/test_deferredruntest.py b/testtools/tests/test_deferredruntest.py
index 2de02b3..7da92f9 100644
--- a/testtools/tests/test_deferredruntest.py
+++ b/testtools/tests/test_deferredruntest.py
@@ -18,6 +18,7 @@ from testtools.deferredruntest import (
 from testtools.tests.helpers import ExtendedTestResult
 from testtools.matchers import (
     Equals,
+    KeysEqual,
     )
 from testtools.runtest import RunTest
 
@@ -326,8 +327,7 @@ class TestAsynchronousDeferredRunTest(TestCase):
                  ('addError', test),
                  ('stopTest', test)]))
         error = result._events[1][2]
-        self.assertThat(
-            sorted(error.keys()), Equals(['traceback', 'twisted-log']))
+        self.assertThat(error, KeysEqual('traceback', 'twisted-log'))
 
     def test_unhandled_error_from_deferred(self):
         # If there's a Deferred with an unhandled error, the test fails.  Each
@@ -349,11 +349,11 @@ class TestAsynchronousDeferredRunTest(TestCase):
              ('addError', test, None),
              ('stopTest', test)]))
         self.assertThat(
-            sorted(error.keys()), Equals([
+            error, KeysEqual(
                 'twisted-log',
                 'unhandled-error-in-deferred',
                 'unhandled-error-in-deferred-1',
-                ]))
+                ))
 
     def test_unhandled_error_from_deferred_combined_with_error(self):
         # If there's a Deferred with an unhandled error, the test fails.  Each
@@ -376,11 +376,11 @@ class TestAsynchronousDeferredRunTest(TestCase):
              ('addError', test, None),
              ('stopTest', test)]))
         self.assertThat(
-            sorted(error.keys()), Equals([
+            error, KeysEqual(
                 'traceback',
                 'twisted-log',
                 'unhandled-error-in-deferred',
-                ]))
+                ))
 
     @skipIf(os.name != "posix", "Sending SIGINT with os.kill is posix only")
     def test_keyboard_interrupt_stops_test_run(self):
@@ -499,8 +499,7 @@ class TestAsynchronousDeferredRunTest(TestCase):
                 ('addError', test),
                 ('stopTest', test)]))
         error = result._events[1][2]
-        self.assertThat(
-            sorted(error.keys()), Equals(['traceback', 'twisted-log']))
+        self.assertThat(error, KeysEqual('traceback', 'twisted-log'))
 
     def test_only_addError_once(self):
         # Even if the reactor is unclean and the test raises an error and the
@@ -529,13 +528,13 @@ class TestAsynchronousDeferredRunTest(TestCase):
                 ('stopTest', test)]))
         error = result._events[1][2]
         self.assertThat(
-            sorted(error.keys()), Equals([
+            error, KeysEqual(
                 'traceback',
                 'traceback-1',
                 'traceback-2',
                 'twisted-log',
                 'unhandled-error-in-deferred',
-                ]))
+                ))
 
     def test_log_err_is_error(self):
         # An error logged during the test run is recorded as an error in the
@@ -558,8 +557,7 @@ class TestAsynchronousDeferredRunTest(TestCase):
                 ('addError', test),
                 ('stopTest', test)]))
         error = result._events[1][2]
-        self.assertThat(
-            sorted(error.keys()), Equals(['logged-error', 'twisted-log']))
+        self.assertThat(error, KeysEqual('logged-error', 'twisted-log'))
 
     def test_log_err_flushed_is_success(self):
         # An error logged during the test run is recorded as an error in the
@@ -599,8 +597,7 @@ class TestAsynchronousDeferredRunTest(TestCase):
                 ('addError', test),
                 ('stopTest', test)]))
         error = result._events[1][2]
-        self.assertThat(
-            sorted(error.keys()), Equals(['traceback', 'twisted-log']))
+        self.assertThat(error, KeysEqual('traceback', 'twisted-log'))
 
 
 class TestAssertFailsWith(TestCase):

From cb70880ad844f50078cea870653b38be3573775f Mon Sep 17 00:00:00 2001
From: Jonathan Lange <jml@canonical.com>
Date: Sun, 31 Oct 2010 12:33:44 -0400
Subject: [PATCH 17/17] Add the twisted log unconditionally.

---
 testtools/deferredruntest.py            |  6 +++---
 testtools/tests/test_deferredruntest.py | 10 ++++------
 2 files changed, 7 insertions(+), 9 deletions(-)

diff --git a/testtools/deferredruntest.py b/testtools/deferredruntest.py
index 54299cd..38cda99 100644
--- a/testtools/deferredruntest.py
+++ b/testtools/deferredruntest.py
@@ -216,6 +216,9 @@ class AsynchronousDeferredRunTest(RunTest):
             [error_observer.gotEvent, full_observer.emit],
             self._blocking_run_deferred, spinner)
 
+        self.case.addDetail(
+            'twisted-log', Content(UTF8_TEXT, full_log.readlines))
+
         logged_errors = error_observer.flushErrors()
         for logged_error in logged_errors:
             successful = False
@@ -239,9 +242,6 @@ class AsynchronousDeferredRunTest(RunTest):
 
         if successful:
             self.result.addSuccess(self.case, details=self.case.getDetails())
-        else:
-            self.case.addDetail(
-                'twisted-log', Content(UTF8_TEXT, full_log.readlines))
 
     def _run_user(self, function, *args):
         """Run a user-supplied function.
diff --git a/testtools/tests/test_deferredruntest.py b/testtools/tests/test_deferredruntest.py
index 7da92f9..2c7648d 100644
--- a/testtools/tests/test_deferredruntest.py
+++ b/testtools/tests/test_deferredruntest.py
@@ -9,6 +9,9 @@ from testtools import (
     skipIf,
     TestCase,
     )
+from testtools.content import (
+    text_content,
+    )
 from testtools.deferredruntest import (
     assert_fails_with,
     AsynchronousDeferredRunTest,
@@ -40,10 +43,6 @@ class X(object):
             self.calls.append('tearDown')
             super(X.Base, self).tearDown()
 
-    class Success(Base):
-        expected_calls = ['setUp', 'test', 'tearDown', 'clean-up']
-        expected_results = [['addSuccess']]
-
     class ErrorInSetup(Base):
         expected_calls = ['setUp', 'clean-up']
         expected_results = [('addError', RuntimeError)]
@@ -109,7 +108,6 @@ def make_integration_tests():
         ]
 
     tests = [
-        X.Success,
         X.ErrorInSetup,
         X.ErrorInTest,
         X.ErrorInTearDown,
@@ -578,7 +576,7 @@ class TestAsynchronousDeferredRunTest(TestCase):
             result._events,
             Equals([
                 ('startTest', test),
-                ('addSuccess', test),
+                ('addSuccess', test, {'twisted-log': text_content('')}),
                 ('stopTest', test)]))
 
     def test_log_in_details(self):