zope.testrunner fails one test with Python 3.12, succeeding with 3.11

[doko42]

seen when testing with the python 3.12 branch, the test succeed with 3.11.7:

Failure in test /home/packages/zope/zope.testrunner/.pybuild/cpython3_3.12/build/zope/testrunner/
tests/testrunner-colors.rst
Failed doctest test for testrunner-colors.rst
File "/home/packages/zope/zope.testrunner/.pybuild/cpython3_3.12/build/zope/testrunner/tests/te
strunner-colors.rst", line 0

---

File "/home/packages/zope/zope.testrunner/.pybuild/cpython3_3.12/build/zope/testrunner/tests/testrunner-colors.rst", line 165, in testrunner-colors.rst
Failed example:
_ = testrunner.run_internal(defaults_skip)
Exception raised:
Traceback (most recent call last):
File "/usr/lib/python3.12/doctest.py", line 1359, in __run
exec(compile(example.source, filename, "single",
File "<doctest testrunner-colors.rst[14]>", line 1, in
_ = testrunner.run_internal(defaults_skip)
File "/home/packages/zope/zope.testrunner/.pybuild/cpython3_3.12/build/zope/testrunner/init.py", line 55, in run_internal
runner.run()
File "/home/packages/zope/zope.testrunner/.pybuild/cpython3_3.12/build/zope/testrunner/runner.py", line 191, in run
self.run_tests()
File "/home/packages/zope/zope.testrunner/.pybuild/cpython3_3.12/build/zope/testrunner/runner.py", line 292, in run_tests
self.ran += run_layer(self.options, layer_name, layer, tests,
File "/home/packages/zope/zope.testrunner/.pybuild/cpython3_3.12/build/zope/testrunner/runner.py", line 473, in run_layer
return run_tests(options, tests, layer_name, failures, errors, skipped,
File "/home/packages/zope/zope.testrunner/.pybuild/cpython3_3.12/build/zope/testrunner/runner.py", line 399, in run_tests
test(result)
File "/usr/lib/python3.12/unittest/case.py", line 692, in call
return self.run(*args, **kwds)
File "/usr/lib/python3.12/unittest/case.py", line 662, in run
result.stopTest(self)
File "/home/packages/zope/zope.testrunner/.pybuild/cpython3_3.12/build/zope/testrunner/runner.py", line 1023, in stopTest
test.dict.update(self._test_state)
AttributeError: 'TestResult' object has no attribute '_test_state'

[jugmac00]

The test suite passed a week ago on Python 3.12 which suggests either a dependency or the test environment has changed.

[mgedmin]

The AttributeError: 'TestResult' object has no attribute '_test_state' error in stopTest() means that stopTest() was called without startTest() being called first. This can happen if any of the statements at the beginning of the try: block in unittest.TestCase.run() raise an exception in https://github.com/python/cpython/blob/399a3f2e1e428710fa4dc5c54841e179dc8e1028/Lib/unittest/case.py#L609-L620, which then causes the finally: to call our stopTest().

When I fix this (and a similar AttributeError about _threads) in stopTest(), I get to see the real failure:

File "/home/mg/src/zopefoundation/zope.testrunner/src/zope/testrunner/tests/testrunner-colors.rst", line 165, in testrunner-colors.rst
Failed example:
    _ = testrunner.run_internal(defaults_skip)
Exception raised:
    Traceback (most recent call last):
      File "/home/mg/opt/python312/lib/python3.12/doctest.py", line 1357, in __run
        exec(compile(example.source, filename, "single",
      File "<doctest testrunner-colors.rst[14]>", line 1, in <module>
        _ = testrunner.run_internal(defaults_skip)
      File "/home/mg/src/zopefoundation/zope.testrunner/src/zope/testrunner/__init__.py", line 55, in run_internal
        runner.run()
      File "/home/mg/src/zopefoundation/zope.testrunner/src/zope/testrunner/runner.py", line 191, in run
        self.run_tests()
      File "/home/mg/src/zopefoundation/zope.testrunner/src/zope/testrunner/runner.py", line 292, in run_tests
        self.ran += run_layer(self.options, layer_name, layer, tests,
      File "/home/mg/src/zopefoundation/zope.testrunner/src/zope/testrunner/runner.py", line 473, in run_layer
        return run_tests(options, tests, layer_name, failures, errors, skipped,
      File "/home/mg/src/zopefoundation/zope.testrunner/src/zope/testrunner/runner.py", line 399, in run_tests
        test(result)
      File "/home/mg/opt/python312/lib/python3.12/unittest/case.py", line 692, in __call__
        return self.run(*args, **kwds)
      File "/home/mg/opt/python312/lib/python3.12/unittest/case.py", line 616, in run
        _addSkip(result, self, skip_why)
      File "/home/mg/opt/python312/lib/python3.12/unittest/case.py", line 89, in _addSkip
        addSkip(test_case, reason)
      File "/home/mg/src/zopefoundation/zope.testrunner/src/zope/testrunner/runner.py", line 955, in addSkip
        self.options.output.test_skipped(test, reason)
      File "/home/mg/src/zopefoundation/zope.testrunner/src/zope/testrunner/formatter.py", line 573, in test_skipped
        self.test_width += len(s) + 1
    AttributeError: 'ColorfulOutputFormatter' object has no attribute 'test_width'. Did you mean: 'last_width'?

[mgedmin]

Same cause: the code for handing skipped tests is now called without start_test() getting called first.

This is a consequence of python/cpython@551aa6a

[mgedmin]

I started working on a fix but quickly got stuck: #158.

[icemac]

The following test runs also seem to be broken because of this issue:

• https://github.com/zopefoundation/zope.security/actions/runs/7157651411/job/19488816361
• https://github.com/zopefoundation/Acquisition/actions/runs/7157650586/job/19488814839
• https://github.com/zopefoundation/AccessControl/actions/runs/7157631822/job/19488767912
• https://github.com/zopefoundation/zope.proxy/actions/runs/7157624240/job/19488750012
• https://github.com/zopefoundation/zope.index/actions/runs/7157614693/job/19488726229

[icemac]

@d-maurer Do you maybe have an idea here, how to solve this issue?

[d-maurer]

Michael Howitz wrote at 2023-12-15 05:55 -0800:

@d-maurer Do you maybe have an idea here, how to solve this issue?

Currently, I feel sick. Once I am better, I will look into this.

[d-maurer]

@d-maurer Do you maybe have an idea here, how to solve this issue?

I agree with the analysis of @mgedmin.

Apparently, python/cpython@551aa6a
no longer calls startTest for (most) skipped tests in order to get the exit code right if all tests have been skipped.
This case is so isolated that in my view it is not worth to cause significant trouble. Therefore, I see it a potential approach to use a monkey patch to retain the old "call startTest for skipped tests, too" -- until zope.testrunner only supports versions above 3.12. Maybe, we control such a monkey patch with a new option to support the new counting for skipped tests.

Alternatively, #158 is an alternative. As @mgedmin reports, it still lets many tests fail because the counting of skipped tests has changed. My impression: in most cases, those differences are not relevant for the test and should not cause its failure. The failures result from doctests tending to check also things which are not relevant. In this case, a normalized might be able to hide those differences.