Merge lp:~gz/bzr/parallel_fork_broken_child_804130 into lp:bzr

[Martin Packman]

Report child process exceptions from selftest --parallel=fork

Makes breakage in a selftest --parallel=fork child visible by printing the traceback to the child-to-parent stream if possible, rather than silently exiting with a success code. This is mostly useful when working on selftest code, as otherwise when something breaks it reports "0 tests OK" which takes some remembering to know it actually means the world broke. Now at least, it should be preceded by two plus tracebacks from the child processes, so will look different from the usual case of having misspelt a test subset.

I pulled some of the hacky code out of the TestUncollectedWarnings* classes so it could be reused for the test here, any feedback on how I've done that is welcome.

Finally, it would be nice to actually do something in the parent process if the child finishes with a non-zero status. It's no good raising an exception, because it just gets caught in the subthread, so short of creating another fake test case just to fail and appear in the output I'm not sure what.

[Robert Collins (lifeless)]

A fake test in the output seems sane to me. Or - you know all the
tests that were intended to run, you could make them all fail ('not
executed by <...>')

[Jelmer Vernooij (jelmer)]

The refactoring seems reasonable to me.

review: Approve

[Martin Packman (gz)]

sent to pqm by email

[Martin Packman (gz)]

Decided to merge this branch as it stands and leave thinking about better error reporting for subunit for another day.

[Martin Packman (gz)]

sent to pqm by email

=== modified file 'bzrlib/tests/__init__.py'
--- bzrlib/tests/__init__.py	2011-10-17 15:27:38 +0000
+++ bzrlib/tests/__init__.py	2011-10-21 16:05:50 +0000
@@ -3488,7 +3488,9 @@
             try:
                 ProtocolTestCase.run(self, result)
             finally:
-                os.waitpid(self.pid, 0)
+                pid, status = os.waitpid(self.pid, 0)
+            # GZ 2011-10-18: If status is nonzero, should report to the result
+            #                that something went wrong.
 
     test_blocks = partition_tests(suite, concurrency)
     # Clear the tests from the original suite so it doesn't keep them alive
@@ -3500,24 +3502,26 @@
         c2pread, c2pwrite = os.pipe()
         pid = os.fork()
         if pid == 0:
-            workaround_zealous_crypto_random()
             try:
+                stream = os.fdopen(c2pwrite, 'wb', 1)
+                workaround_zealous_crypto_random()
                 os.close(c2pread)
                 # Leave stderr and stdout open so we can see test noise
                 # Close stdin so that the child goes away if it decides to
                 # read from stdin (otherwise its a roulette to see what
                 # child actually gets keystrokes for pdb etc).
                 sys.stdin.close()
-                # GZ 2011-06-16: Why set stdin to None? Breaks multi fork.
-                #sys.stdin = None
-                stream = os.fdopen(c2pwrite, 'wb', 1)
                 subunit_result = AutoTimingTestResultDecorator(
                     SubUnitBzrProtocolClient(stream))
                 process_suite.run(subunit_result)
-            finally:
-                # GZ 2011-06-16: Is always exiting with silent success
-                #                really the right thing? Hurts debugging.
-                os._exit(0)
+            except:
+                # Try and report traceback on stream, but exit with error even
+                # if stream couldn't be created or something else goes wrong
+                try:
+                    traceback.print_exc(file=stream)
+                finally:
+                    os._exit(1)
+            os._exit(0)
         else:
             os.close(c2pwrite)
             stream = os.fdopen(c2pread, 'rb', 1)

=== modified file 'bzrlib/tests/test_selftest.py'
--- bzrlib/tests/test_selftest.py	2011-10-05 14:46:09 +0000
+++ bzrlib/tests/test_selftest.py	2011-10-21 16:05:50 +0000
@@ -3315,7 +3315,66 @@
         self.assertLength(1, calls)
 
 
-class TestUncollectedWarnings(tests.TestCase):
+class _Selftest(object):
+    """Mixin for tests needing full selftest output"""
+
+    def _inject_stream_into_subunit(self, stream):
+        """To be overridden by subclasses that run tests out of process"""
+
+    def _run_selftest(self, **kwargs):
+        sio = StringIO()
+        self._inject_stream_into_subunit(sio)
+        tests.selftest(stream=sio, stop_on_failure=False, **kwargs)
+        return sio.getvalue()
+
+
+class _ForkedSelftest(_Selftest):
+    """Mixin for tests needing full selftest output with forked children"""
+
+    _test_needs_features = [features.subunit]
+
+    def _inject_stream_into_subunit(self, stream):
+        """Monkey-patch subunit so the extra output goes to stream not stdout
+
+        Some APIs need rewriting so this kind of bogus hackery can be replaced
+        by passing the stream param from run_tests down into ProtocolTestCase.
+        """
+        from subunit import ProtocolTestCase
+        _original_init = ProtocolTestCase.__init__
+        def _init_with_passthrough(self, *args, **kwargs):
+            _original_init(self, *args, **kwargs)
+            self._passthrough = stream
+        self.overrideAttr(ProtocolTestCase, "__init__", _init_with_passthrough)
+
+    def _run_selftest(self, **kwargs):
+        # GZ 2011-05-26: Add a PosixSystem feature so this check can go away
+        if getattr(os, "fork", None) is None:
+            raise tests.TestNotApplicable("Platform doesn't support forking")
+        # Make sure the fork code is actually invoked by claiming two cores
+        self.overrideAttr(osutils, "local_concurrency", lambda: 2)
+        kwargs.setdefault("suite_decorators", []).append(tests.fork_decorator)
+        return super(_ForkedSelftest, self)._run_selftest(**kwargs)
+
+
+class TestParallelFork(_ForkedSelftest, tests.TestCase):
+    """Check operation of --parallel=fork selftest option"""
+
+    def test_error_in_child_during_fork(self):
+        """Error in a forked child during test setup should get reported"""
+        class Test(tests.TestCase):
+            def testMethod(self):
+                pass
+        # We don't care what, just break something that a child will run
+        self.overrideAttr(tests, "workaround_zealous_crypto_random", None)
+        out = self._run_selftest(test_suite_factory=Test)
+        self.assertContainsRe(out,
+            "Traceback.*:\n"
+            ".+ in fork_for_tests\n"
+            "\s*workaround_zealous_crypto_random\(\)\n"
+            "TypeError:")
+
+
+class TestUncollectedWarnings(_Selftest, tests.TestCase):
     """Check a test case still alive after being run emits a warning"""
 
     class Test(tests.TestCase):
@@ -3333,25 +3392,19 @@
             self.Test("test_skip"),
             ])
 
-    def _inject_stream_into_subunit(self, stream):
-        """To be overridden by subclasses that run tests out of process"""
-
     def _run_selftest_with_suite(self, **kwargs):
-        sio = StringIO()
-        self._inject_stream_into_subunit(sio)
         old_flags = tests.selftest_debug_flags
         tests.selftest_debug_flags = old_flags.union(["uncollected_cases"])
         gc_on = gc.isenabled()
         if gc_on:
             gc.disable()
         try:
-            tests.selftest(test_suite_factory=self._get_suite, stream=sio,
-                stop_on_failure=False, **kwargs)
+            output = self._run_selftest(test_suite_factory=self._get_suite,
+                **kwargs)
         finally:
             if gc_on:
                 gc.enable()
             tests.selftest_debug_flags = old_flags
-        output = sio.getvalue()
         self.assertNotContainsRe(output, "Uncollected test case.*test_pass")
         self.assertContainsRe(output, "Uncollected test case.*test_self_ref")
         return output
@@ -3394,33 +3447,9 @@
             runner_class=tests.SubUnitBzrRunner, **kwargs)
 
 
-class TestUncollectedWarningsForking(TestUncollectedWarnings):
+class TestUncollectedWarningsForked(_ForkedSelftest, TestUncollectedWarnings):
     """Check warnings from tests staying alive are emitted when forking"""
 
-    _test_needs_features = [features.subunit]
-
-    def _inject_stream_into_subunit(self, stream):
-        """Monkey-patch subunit so the extra output goes to stream not stdout
-
-        Some APIs need rewriting so this kind of bogus hackery can be replaced
-        by passing the stream param from run_tests down into ProtocolTestCase.
-        """
-        from subunit import ProtocolTestCase
-        _original_init = ProtocolTestCase.__init__
-        def _init_with_passthrough(self, *args, **kwargs):
-            _original_init(self, *args, **kwargs)
-            self._passthrough = stream
-        self.overrideAttr(ProtocolTestCase, "__init__", _init_with_passthrough)
-
-    def _run_selftest_with_suite(self, **kwargs):
-        # GZ 2011-05-26: Add a PosixSystem feature so this check can go away
-        if getattr(os, "fork", None) is None:
-            raise tests.TestNotApplicable("Platform doesn't support forking")
-        # Make sure the fork code is actually invoked by claiming two cores
-        self.overrideAttr(osutils, "local_concurrency", lambda: 2)
-        kwargs.setdefault("suite_decorators", []).append(tests.fork_decorator)
-        return TestUncollectedWarnings._run_selftest_with_suite(self, **kwargs)
-
 
 class TestEnvironHandling(tests.TestCase):
 

=== modified file 'doc/en/release-notes/bzr-2.5.txt'
--- doc/en/release-notes/bzr-2.5.txt	2011-10-19 12:46:41 +0000
+++ doc/en/release-notes/bzr-2.5.txt	2011-10-21 16:05:50 +0000
@@ -107,6 +107,9 @@
   run. The new ``-Euncollected_cases`` selftest flag will add failures if any
   case which persists pasts its expected lifetime. (Martin Packman, #613247)
 
+* Report exceptions from child processes during fork instead of swallowing the
+  error and reporting that everything went okay. (Martin Packman, #804130)
+
 
 bzr 2.5b2
 #########