[Django] #32140: `startTest` result hook not called until after tests already started when `--parallel` used
Django
`--parallel` used
---------------------------------------------+------------------------
Reporter: bobwhitelock | Owner: nobody
Type: Bug | Status: new
Component: Testing framework | Version: 3.1
Severity: Normal | Keywords:
Triage Stage: Unreviewed | Has patch: 0
Needs documentation: 0 | Needs tests: 0
Patch needs improvement: 0 | Easy pickings: 0
UI/UX: 0 |
---------------------------------------------+------------------------
Given a custom Django test runner that uses a custom result class, like
this:
{{{
from unittest.runner import TextTestRunner, TextTestResult
from django.test.runner import DiscoverRunner
class CustomResult(TextTestResult):
def startTest(self, test):
print(f"startTest called for {test}")
super().startTest(test)
class CustomRunner(TextTestRunner):
resultclass = CustomResult
class CustomDjangoRunner(DiscoverRunner):
test_runner = CustomRunner
}}}
And some tests, like this:
{{{
from django.test import TestCase
class FirstTest(TestCase):
def test_first(self):
print("Running test_first")
class SecondTest(TestCase):
def test_second(self):
print("Running test_second")
}}}
When the tests are run without `--parallel`, the expected behaviour
occurs, and the `startTest` hook is called just before starting the test:
{{{
$ ./manage.py test
Creating test database for alias 'default'...
System check identified no issues (0 silenced).
startTest called for test_first (parallel_test.tests.FirstTest)
Running test_first
.startTest called for test_second (parallel_test.tests.SecondTest)
Running test_second
.
----------------------------------------------------------------------
Ran 2 tests in 0.001s
OK
Destroying test database for alias 'default'...
}}}
When the tests are run with `--parallel`, the `startTest` hook appears to
be called after the test has already been run:
{{{
$ ./manage.py test --parallel
Creating test database for alias 'default'...
Cloning test database for alias 'default'...
Cloning test database for alias 'default'...
System check identified no issues (0 silenced).
Running test_first
Running test_second
startTest called for test_second (parallel_test.tests.SecondTest)
.startTest called for test_first (parallel_test.tests.FirstTest)
.
----------------------------------------------------------------------
Ran 2 tests in 0.017s
OK
Destroying test database for alias 'default'...
Destroying test database for alias 'default'...
Destroying test database for alias 'default'...
}}}
This is surprising, as I would expect the hook to a. be called in a
consistent place when running a test, whether this is in parallel or
serial, and b. be called before/as the test is started. This inconsistent
behaviour can lead to issues when writing custom Django test runners, as
people use this hook to run some code just as each test is started - for
example see https://github.com/xmlrunner/unittest-xml-reporting/issues/229
and https://stackoverflow.com/a/39758653/2620402.
See https://github.com/bobwhitelock/django_parallel_test_issue_repro for a
minimal repro of the issue including the code samples above.
I've confirmed this issue is present in both Django 3.1 and 2.2.
Happy to help with fixing this, but I'd need some pointers as to where to
start. Thanks!
--
Ticket URL: <https://code.djangoproject.com/ticket/32140>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.
Django
`--parallel` used
Reporter: Bob Whitelock | Owner: nobody
Type: Bug | Status: new
Component: Testing framework | Version: 3.1
Keywords: startTest parallel | Triage Stage:
test runner | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
Changes (by Mariusz Felisiak):
* cc: Adam (Chainz) Johnson (added)
--
Ticket URL: <https://code.djangoproject.com/ticket/32140#comment:2>
Django
`--parallel` used
Reporter: Bob Whitelock | Owner: nobody
Type: Bug | Status: new
Component: Testing framework | Version: 3.1
Keywords: startTest parallel | Triage Stage:
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
Comment (by Adam (Chainz) Johnson):
The reason this happens is that custom result classes aren't used in the
parallel processes, but instead `RemoteTestResult`, which mostly holds
onto the result to send it back to the main process for display. In theory
it's possible to change how that works, and might even allow the `--debug-
sql` and `--pdb` options work with `--parallel`, but it might require a
little thought.
If you're trying to do something before a test begins, you can also
override `TestCase._callTestMethod`, for example to capture output:
{{{
class ExampleTestMixin:
def _callTestMethod(self, method):
try:
out = StringIO()
err = StringIO()
with mock.patch.object(sys, "stdout", new=out),
mock.patch.object(
sys, "stderr", new=err
):
super()._callTestMethod(method)
except Exception:
print(out.getvalue(), end="")
print(err.getvalue(), end="", file=sys.stderr)
raise
class SimpleTestCase(ExampleTestMixin, test.SimpleTestCase):
pass
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/32140#comment:3>
Django
`--parallel` used
Reporter: Bob Whitelock | Owner: nobody
Type: Bug | Status: closed
Component: Testing framework | Version: 3.1
Keywords: startTest parallel | Triage Stage:
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
Changes (by Carlton Gibson):
* status: new => closed
* resolution: => needsinfo
Comment:
Given Adam's comment, I'm going to mark this as `needsinfo` — that info
being a Proof of concept for what a patch might look like here.
--
Ticket URL: <https://code.djangoproject.com/ticket/32140#comment:4>
Django
`--parallel` used
Reporter: Bob Whitelock | Owner: nobody
Type: Bug | Status: closed
Component: Testing framework | Version: 3.1
Keywords: startTest parallel | Triage Stage:
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
Comment (by Bob Whitelock):
> The reason this happens is that custom result classes aren't used in the
parallel processes, but instead RemoteTestResult, which mostly holds onto
the result to send it back to the main process for display. In theory it's
possible to change how that works, and might even allow the --debug-sql
and --pdb options work with --parallel, but it might require a little
thought.
Thanks for the explanation, and that's interesting - the custom startTest
method does appear to be called however, just after the test has actually
started, so it does look like the custom result class is being used.
Unless I'm misunderstanding what you mean?
--
Ticket URL: <https://code.djangoproject.com/ticket/32140#comment:5>
Django
`--parallel` used
Reporter: Bob Whitelock | Owner: nobody
Type: Bug | Status: closed
Component: Testing framework | Version: 3.1
Keywords: startTest parallel | Triage Stage:
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
Comment (by Adam (Chainz) Johnson):
> the custom startTest method does appear to be called however, just after
the test has actually started, so it does look like the custom result
class is being used.
Yes - I think it's being called back in the main process when reporting
the results, though I haven't confirmed this.
--
Ticket URL: <https://code.djangoproject.com/ticket/32140#comment:6>