Merge lp:~benji/testtools/modernize-tsfr into lp:~testtools-committers/testtools/trunk

[Benji York]

Modernise ThreadSafeForwardingResult by simplifying it and adding some tests.

The ThreadSafeForwardingResult attempts to manage tag state itself
because the wrapped test result did not previously manage tags
correctly. The recent ~jml/testtools/forward-current-tags branch fixes
those issues so TSFR needed to be updated. This branch does that by
simplifying TSFR, removing some now unneeded tests, and adding some new
tests.

[Jonathan Lange (jml)]

Hey Benji,

First up, thanks so much for the contribution, and for valiantly persisting in cleaning up this somewhat unclear code. Sadly, I'm afraid it's back to the drawing with this one. I'm afraid it's our fault for not clearly communicating the intent of TSFR.

TSFR's main purpose is to send all of the events for a single test in an atomic unit, preventing the destination result from receiving input like this:

  startTest(foo)
  startTest(bar)
  addSuccess(foo)
  addSuccess(bar)
  stopTest(bar)
  stopTest(foo)

And instead guaranteeing input like this:

  startTest(bar)
  addSuccess(bar)
  stopTest(bar)
  startTest(foo)
  addSuccess(foo)
  stopTest(foo)

If I understand this patch correctly, it wraps each individual event in a semaphore, which isn't enough to guarantee this per-test atomicity.

I'll try to sketch out, or possibly even implement, a solution here.

jml

review: Disapprove

[Robert Collins (lifeless)]

In fact TSFR *must* manage tag state itself; it has to supply either
the delta (by inspection) to what its state is at each synchronisation
point, or it has to supply a back-out-its-own-state command at the end
of each synchronisation point.

I'd be inclined to do the latter.

Do you have a SSCCE of the problem?

-Rob

Unmerged revisions

270. By Benji York on 2012-04-12

tweak comment

269. By Benji York on 2012-04-12

add a test that demonstrates ThreadsafeForwardingResult's use of semaphores

268. By Benji York on 2012-04-12

simplify tests some more and fix recently-introduced bug in wasSuccessful

267. By Benji York on 2012-04-12

wasSuccessful might do anything, so wrap it in the semaphore too

266. By Benji York on 2012-04-12

regularize semaphore use

265. By Benji York on 2012-04-12

cleanup some unneeded concepts that I recently introduced

264. By Benji York on 2012-04-12

get ThreadsafeForwardingResult tests passing

263. By Benji York on 2012-04-12

checkpoint - all tag tests pass

=== modified file 'testtools/testresult/real.py'
--- testtools/testresult/real.py	2012-04-12 15:07:32 +0000
+++ testtools/testresult/real.py	2012-04-12 15:07:32 +0000
@@ -376,110 +376,72 @@
         TestResult.__init__(self)
         self.result = ExtendedToOriginalDecorator(target)
         self.semaphore = semaphore
-        self._test_start = None
         self._global_tags = set(), set()
         self._test_tags = set(), set()
 
     def __repr__(self):
         return '<%s %r>' % (self.__class__.__name__, self.result)
 
-    def _not_empty_tags(self, tags):
-        return bool(tags[0] and tags[1])
+    @property
+    def current_tags(self):
+        self.semaphore.acquire()
+        try:
+            return self.result.current_tags
+        finally:
+            self.semaphore.release()
 
-    def _add_result_with_semaphore(self, method, test, *args, **kwargs):
-        now = self._now()
+    def _call_with_semaphore(self, method, *args, **kwargs):
         self.semaphore.acquire()
         try:
-            self.result.time(self._test_start)
-            if self._not_empty_tags(self._global_tags):
-                self.result.tags(*self._global_tags)
-            try:
-                self.result.startTest(test)
-                self.result.time(now)
-                if self._not_empty_tags(self._test_tags):
-                    self.result.tags(*self._test_tags)
-                try:
-                    method(test, *args, **kwargs)
-                finally:
-                    self.result.stopTest(test)
-            finally:
-                if self._not_empty_tags(self._global_tags):
-                    self.result.tags(*reversed(self._global_tags))
+            return method(*args, **kwargs)
         finally:
             self.semaphore.release()
-        self._test_start = None
 
     def addError(self, test, err=None, details=None):
-        self._add_result_with_semaphore(self.result.addError,
+        self._call_with_semaphore(self.result.addError,
             test, err, details=details)
 
     def addExpectedFailure(self, test, err=None, details=None):
-        self._add_result_with_semaphore(self.result.addExpectedFailure,
+        self._call_with_semaphore(self.result.addExpectedFailure,
             test, err, details=details)
 
     def addFailure(self, test, err=None, details=None):
-        self._add_result_with_semaphore(self.result.addFailure,
+        self._call_with_semaphore(self.result.addFailure,
             test, err, details=details)
 
     def addSkip(self, test, reason=None, details=None):
-        self._add_result_with_semaphore(self.result.addSkip,
+        self._call_with_semaphore(self.result.addSkip,
             test, reason, details=details)
 
     def addSuccess(self, test, details=None):
-        self._add_result_with_semaphore(self.result.addSuccess,
+        self._call_with_semaphore(self.result.addSuccess,
             test, details=details)
 
     def addUnexpectedSuccess(self, test, details=None):
-        self._add_result_with_semaphore(self.result.addUnexpectedSuccess,
+        self._call_with_semaphore(self.result.addUnexpectedSuccess,
             test, details=details)
 
     def startTestRun(self):
-        super(ThreadsafeForwardingResult, self).startTestRun()
-        self.semaphore.acquire()
-        try:
-            self.result.startTestRun()
-        finally:
-            self.semaphore.release()
+        self._call_with_semaphore(self.result.startTestRun)
 
     def stopTestRun(self):
-        self.semaphore.acquire()
-        try:
-            self.result.stopTestRun()
-        finally:
-            self.semaphore.release()
+        self._call_with_semaphore(self.result.stopTestRun)
 
     def done(self):
-        self.semaphore.acquire()
-        try:
-            self.result.done()
-        finally:
-            self.semaphore.release()
+        self._call_with_semaphore(self.result.done)
 
     def startTest(self, test):
-        self._test_start = self._now()
-        super(ThreadsafeForwardingResult, self).startTest(test)
+        self._call_with_semaphore(self.result.startTest, test)
+
+    def stopTest(self, test):
+        self._call_with_semaphore(self.result.stopTest, test)
 
     def wasSuccessful(self):
-        return self.result.wasSuccessful()
+        return self._call_with_semaphore(self.result.wasSuccessful)
 
     def tags(self, new_tags, gone_tags):
         """See `TestResult`."""
-        super(ThreadsafeForwardingResult, self).tags(new_tags, gone_tags)
-        if self._test_start is not None:
-            self._test_tags = self._merge_tags(
-                self._test_tags, new_tags, gone_tags)
-        else:
-            self._global_tags = self._merge_tags(
-                self._global_tags, new_tags, gone_tags)
-
-    def _merge_tags(self, existing, new_tags, gone_tags):
-        result_new = set(existing[0])
-        result_gone = set(existing[1])
-        result_new.update(new_tags)
-        result_new.difference_update(gone_tags)
-        result_gone.update(gone_tags)
-        result_gone.difference_update(new_tags)
-        return result_new, result_gone
+        self._call_with_semaphore(self.result.tags, new_tags, gone_tags)
 
 
 class ExtendedToOriginalDecorator(object):
 
=== modified file 'testtools/tests/test_testresult.py'
--- testtools/tests/test_testresult.py	2012-04-12 15:07:32 +0000
+++ testtools/tests/test_testresult.py	2012-04-12 15:07:32 +0000
@@ -103,6 +103,18 @@
         return sys.exc_info()
 
 
+class SemaphoreDouble(object):
+
+    def __init__(self, log):
+        self.log = log.append
+
+    def acquire(self):
+        self.log('acquired')
+
+    def release(self):
+        self.log('released')
+
+
 class Python26Contract(object):
 
     def test_fresh_result_is_successful(self):
@@ -766,13 +778,6 @@
         self.result1 = ThreadsafeForwardingResult(self.target,
             self.result_semaphore)
 
-    def test_nonforwarding_methods(self):
-        # startTest and stopTest are not forwarded because they need to be
-        # batched.
-        self.result1.startTest(self)
-        self.result1.stopTest(self)
-        self.assertEqual([], self.target._events)
-
     def test_startTestRun(self):
         self.result1.startTestRun()
         self.result2 = ThreadsafeForwardingResult(self.target,
@@ -787,75 +792,21 @@
         self.result2.stopTestRun()
         self.assertEqual(["stopTestRun", "stopTestRun"], self.target._events)
 
-    def test_forwarding_methods(self):
-        # error, failure, skip and success are forwarded in batches.
-        exc_info1 = make_exception_info(RuntimeError, 'error')
-        starttime1 = datetime.datetime.utcfromtimestamp(1.489)
-        endtime1 = datetime.datetime.utcfromtimestamp(51.476)
-        self.result1.time(starttime1)
-        self.result1.startTest(self)
-        self.result1.time(endtime1)
-        self.result1.addError(self, exc_info1)
-        exc_info2 = make_exception_info(AssertionError, 'failure')
-        starttime2 = datetime.datetime.utcfromtimestamp(2.489)
-        endtime2 = datetime.datetime.utcfromtimestamp(3.476)
-        self.result1.time(starttime2)
-        self.result1.startTest(self)
-        self.result1.time(endtime2)
-        self.result1.addFailure(self, exc_info2)
-        reason = _u("Skipped for some reason")
-        starttime3 = datetime.datetime.utcfromtimestamp(4.489)
-        endtime3 = datetime.datetime.utcfromtimestamp(5.476)
-        self.result1.time(starttime3)
-        self.result1.startTest(self)
-        self.result1.time(endtime3)
-        self.result1.addSkip(self, reason)
-        starttime4 = datetime.datetime.utcfromtimestamp(6.489)
-        endtime4 = datetime.datetime.utcfromtimestamp(7.476)
-        self.result1.time(starttime4)
-        self.result1.startTest(self)
-        self.result1.time(endtime4)
-        self.result1.addSuccess(self)
-        self.assertEqual([
-            ('time', starttime1),
-            ('startTest', self),
-            ('time', endtime1),
-            ('addError', self, exc_info1),
-            ('stopTest', self),
-            ('time', starttime2),
-            ('startTest', self),
-            ('time', endtime2),
-            ('addFailure', self, exc_info2),
-            ('stopTest', self),
-            ('time', starttime3),
-            ('startTest', self),
-            ('time', endtime3),
-            ('addSkip', self, reason),
-            ('stopTest', self),
-            ('time', starttime4),
-            ('startTest', self),
-            ('time', endtime4),
-            ('addSuccess', self),
-            ('stopTest', self),
-            ], self.target._events)
-
-    def test_tags_helper(self):
-       expected = set(['present']), set(['missing', 'going'])
-       input = set(['present']), set(['missing'])
-       self.assertEqual(
-            expected, self.result1._merge_tags(input, set(), set(['going'])))
-       expected = set(['present']), set(['missing', 'going'])
-       input = set(['present', 'going']), set(['missing'])
-       self.assertEqual(
-            expected, self.result1._merge_tags(input, set(), set(['going'])))
-       expected = set(['coming', 'present']), set(['missing'])
-       input = set(['present']), set(['missing'])
-       self.assertEqual(
-            expected, self.result1._merge_tags(input, set(['coming']), set()))
-       expected = set(['coming', 'present']), set(['missing'])
-       input = set(['present']), set(['coming', 'missing'])
-       self.assertEqual(
-            expected, self.result1._merge_tags(input, set(['coming']), set()))
+    def test_semaphore_aquired(self):
+        # The methods (and properties) of TSFR (ThreadsafeForwardingResult)
+        # are protected by a semaphore so only one thread may access the
+        # underlying test result at any one time.  This can be demonstrated by
+        # inserting our own logging semaphore double and watching its
+        # behavior.
+        log = []
+        result = LoggingResult(log)
+        semaphore = SemaphoreDouble(log)
+        tsfr = ThreadsafeForwardingResult(result, semaphore)
+        # Now if we make calls on the TSFR the underlying result will be
+        # called too and the semaphore will be acquired and released around
+        # the calls.
+        tsfr.startTestRun()
+        self.assertEqual(['acquired', 'startTestRun', 'released'], log)
 
 
 class TestExtendedToOriginalResultDecoratorBase(TestCase):