Merge 52b9754 into ad25458

CHANGES.rst

@@ -5,7 +5,13 @@
 5.4.1 (unreleased)
 ==================
 
-- Nothing changed yet.
+- New option ``--gc-after-test``. It calls for a garbage collection
+  after each test and can be used to track down ``ResourceWarning``s
+  and cyclic garbage.
+  With ``rv = gc.collect()``, ``!`` is output on verbosity level 1 when
+  ``rv`` is non zero (i.e. when cyclic structures have been released)
+  and ``[``*rv*``]`` on higher verbosity levels
+  (`#131 <https://github.com/zopefoundation/zope.testrunner/issues/131`_).
 
 
 5.4.0 (2021-11-19)

src/zope/testrunner/formatter.py

@@ -395,8 +395,12 @@ def format_traceback(self, exc_info):
             tb = "".join(traceback.format_exception(*exc_info))
         return tb
 
-    def stop_test(self, test):
+    def stop_test(self, test, gccount):
         """Clean up the output state after a test."""
+        if gccount and self.verbose:
+            s = "!" if self.verbose == 1 else " [%d]" % gccount
+            self.test_width += len(s)
+            print(s, end="")
         if self.progress:
             self.last_width = self.test_width
         elif self.verbose > 1:
@@ -1293,7 +1297,7 @@ def test_failure(self, test, seconds, exc_info, stdout=None, stderr=None):
         self._add_std_streams_to_details(details, stdout, stderr)
         self._subunit.addFailure(test, details=details)
 
-    def stop_test(self, test):
+    def stop_test(self, test, gccount):
         """Clean up the output state after a test."""
         self._subunit.stopTest(test)
 

src/zope/testrunner/options.py

@@ -341,6 +341,16 @@ def _regex_search(s):
 once to set multiple flags.
 """)
 
+analysis.add_argument(
+    '--gc-after-test', action="store_true", dest='gc_after_test',
+    help="""\
+After each test, call 'gc.collect' and record the return
+value *rv*; when *rv* is non-zero, output '!' on verbosity level 1
+and '[*rv*]' on higher verbosity levels.\n
+Note: the option does not work under `jython` and not fully works
+under `PyPy`.
+""")
+
 analysis.add_argument(
     '--repeat', '-N', action="store", type=int, dest='repeat',
     default=1,

src/zope/testrunner/runner.py

@@ -941,6 +941,7 @@ def _restoreStdStreams(self):
             return None, None
 
     def startTest(self, test):
+        self._test_state = test.__dict__.copy()
         self.testSetUp()
         unittest.TestResult.startTest(self, test)
         testsRun = self.testsRun - 1  # subtract the one the base class added
@@ -1027,7 +1028,15 @@ def addUnexpectedSuccess(self, test):
 
     def stopTest(self, test):
         self.testTearDown()
-        self.options.output.stop_test(test)
+        # Without clearing, cyclic garbage referenced by the test
+        # would be reported in the following test.
+        test.__dict__.clear()
+        test.__dict__.update(self._test_state)
+        del self._test_state
+        gccount = gc.collect() \
+            if self.options.gc_after_test and not is_jython \
+            else 0
+        self.options.output.stop_test(test, gccount)
 
         if is_jython:
             pass
@@ -1097,7 +1106,10 @@ def _gather(layer):
         key.append(layer)
 
     _gather(layer)
-    return tuple(name_from_layer(ly) for ly in key if ly != UnitTests)
+    try:
+        return tuple(name_from_layer(ly) for ly in key if ly != UnitTests)
+    finally:
+        del _gather  # break reference cycle
 
 
 def order_by_bases(layers):

src/zope/testrunner/tests/test_doctest.py

@@ -18,12 +18,17 @@
 import doctest
 import gc
 import os
+import platform
 import re
 import sys
 import unittest
 
+from six import PY2
 from zope.testing import renormalizing
 
+from ..runner import is_jython
+
+is_pypy = platform.python_implementation() == "PyPy"
 
 # separated checkers for the different platform,
 # because it s...s to maintain just one
@@ -384,6 +389,25 @@ def test_suite():
                 checker=checker,
             )
         )
+    if not is_jython and not is_pypy:
+        # ``Jython`` apparently does not implement ``gc``
+        # and for ``PyPy``, ``gc.collect`` returns ``None``
+        # rather than the number of collected objects
+        suites.append(
+            doctest.DocFileSuite(
+                'testrunner-gc-after-test.rst',
+                setUp=setUp, tearDown=tearDown,
+                optionflags=optionflags,
+                checker=renormalizing.RENormalizing([
+                    (re.compile(r'(\d+ minutes )?\d+[.]\d\d\d seconds'),
+                     'N.NNN seconds'),
+                    (re.compile(r'\(\d+[.]\d\d\d s\)'),
+                     '(N.NNN s)'),
+                    ]
+                    # objects on cycle differ between PY2 and PY3
+                    + (
+                    [(re.compile(r'\[\d+\]'), '[C]')] if PY2
+                    else []))))
 
     try:
         import subunit

src/zope/testrunner/tests/testrunner-ex/gc-after-test.py

@@ -0,0 +1,54 @@
+from unittest import TestCase
+from warnings import warn
+
+from six import PY2
+
+
+class GcAfterTestTests(TestCase):
+    def tearDown(self):
+        try:
+            del self.cycle
+        except AttributeError:
+            pass
+
+    def test_okay(self):
+        pass
+
+    def test_cycle_without_resource(self):
+        self.cycle = _Cycle()
+
+    def test_cycle_with_resource(self):
+        self.cycle = _Cycle(resource=_Resource())
+
+    def test_test_holds_cycle(self):
+        self.hold_cycle = _Cycle(resource=_Resource())
+
+    def test_failure(self):
+        raise AssertionError("failure")
+
+    def test_exception(self):
+        1/0
+
+
+class _Cycle(object):
+    """Auxiliary class creating a reference cycle."""
+    def __init__(self, **kw):
+        self.self = self  # create reference cycle
+        self.__dict__.update(kw)
+
+
+class _Resource(object):
+    """Auxiliary class emulating a resource."""
+    closed = False
+
+    def close(self):
+        self.closed = True
+
+    def __del__(self):
+        if not self.closed:
+            warn(ResourceWarning("not closed"))
+
+
+if PY2:
+    class ResourceWarning(Warning):
+        pass

src/zope/testrunner/tests/testrunner-gc-after-test.rst

@@ -0,0 +1,91 @@
+Debugging cyclic garbage and ResourceWarnings
+=============================================
+
+The --gc-after-test option can be used
+to detect the creation of cyclic garbage and diagnose ``ResourceWarning``s.
+
+Note: Python writes ``ResourceWarning`` messages to ``stderr``
+which it not captured by ``doctest``. The sample output below
+therefore does not show the warnings (even though two are issued).
+
+    >>> import os.path, sys
+    >>> directory_with_tests = os.path.join(this_directory, 'testrunner-ex')
+    >>> defaults = [
+    ...     '--path', directory_with_tests,
+    ...     '--tests-pattern', 'gc-after-test',
+    ...     ]
+
+    >>> from zope import testrunner
+
+
+    Verbosity level 1
+    >>> sys.argv = 'test --gc-after-test -v'.split()
+    >>> _ = testrunner.run_internal(defaults)
+    Running tests at level 1
+    Running zope.testrunner.layer.UnitTests tests:
+      Set up zope.testrunner.layer.UnitTests in N.NNN seconds.
+      Running:
+    .!.!.
+    <BLANKLINE>
+    Error in test test_exception (gc-after-test.GcAfterTestTests)
+    Traceback (most recent call last):
+    ...
+    ZeroDivisionError: ...
+    <BLANKLINE>
+    .
+    <BLANKLINE>
+    Failure in test test_failure (gc-after-test.GcAfterTestTests)
+    Traceback (most recent call last):
+      ...	
+    AssertionError: failure
+    <BLANKLINE>
+    ..!
+      Ran 6 tests with 1 failures, 1 errors and 0 skipped in N.NNN seconds.
+    Tearing down left over layers:
+      Tear down zope.testrunner.layer.UnitTests in N.NNN seconds.
+    <BLANKLINE>
+    Tests with errors:
+       test_exception (gc-after-test.GcAfterTestTests)
+    <BLANKLINE>
+    Tests with failures:
+       test_failure (gc-after-test.GcAfterTestTests)
+
+    Verbosity level 2 (or higher)
+    >>> sys.argv = 'test --gc-after-test -vv'.split()
+    >>> _ = testrunner.run_internal(defaults)
+    Running tests at level 1
+    Running zope.testrunner.layer.UnitTests tests:
+      Set up zope.testrunner.layer.UnitTests in N.NNN seconds.
+      Running:
+     test_cycle_with_resource (gc-after-test.GcAfterTestTests) [3]
+    <BLANKLINE>
+     test_cycle_without_resource (gc-after-test.GcAfterTestTests) [2]
+    <BLANKLINE>
+     test_exception (gc-after-test.GcAfterTestTests)
+    <BLANKLINE>
+    Error in test test_exception (gc-after-test.GcAfterTestTests)
+    Traceback (most recent call last):
+      ...
+    ZeroDivisionError: ...
+    <BLANKLINE>
+    <BLANKLINE>
+     test_failure (gc-after-test.GcAfterTestTests)
+    <BLANKLINE>
+    Failure in test test_failure (gc-after-test.GcAfterTestTests)
+    Traceback (most recent call last):
+      ...
+    AssertionError: failure
+    <BLANKLINE>
+    <BLANKLINE>
+     test_okay (gc-after-test.GcAfterTestTests)
+     test_test_holds_cycle (gc-after-test.GcAfterTestTests) [3]
+      Ran 6 tests with 1 failures, 1 errors and 0 skipped in N.NNN seconds.
+    Tearing down left over layers:
+      Tear down zope.testrunner.layer.UnitTests in N.NNN seconds.
+    <BLANKLINE>
+    Tests with errors:
+       test_exception (gc-after-test.GcAfterTestTests)
+    <BLANKLINE>
+    Tests with failures:
+       test_failure (gc-after-test.GcAfterTestTests)
+