[Django] #36308: Parallel testing fails reporting unit test combining subTest and assertNumQueries

[Django]

#36308: Parallel testing fails reporting unit test combining subTest and
assertNumQueries
-------------------------------------+-------------------------------------
Reporter: Jean Bvt | Type: Bug
Status: new | Component: Testing
| framework
Version: 5.2 | Severity: Normal
Keywords: test assertNumQuery | Triage Stage:
reporting | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Updating from django 5.1.8 to 5.2.0, our test suit fails to correctly
reports failed test.

```
python manage.py test app.module.tests --parallel 8
Found 9 test(s).
[...]
Destroying test database for alias 'default'...
Destroying test database for alias 'default'...
Destroying test database for alias 'default'...
Traceback (most recent call last):
File "/app/manage.py", line 23, in <module>
main()
File "/app/manage.py", line 19, in main
execute_from_command_line(sys.argv)
File "/app/.venv/lib/python3.12/site-
packages/django/core/management/__init__.py", line 442, in
execute_from_command_line
utility.execute()
File "/app/.venv/lib/python3.12/site-
packages/django/core/management/__init__.py", line 436, in execute
self.fetch_command(subcommand).run_from_argv(self.argv)
File "/app/.venv/lib/python3.12/site-
packages/django/core/management/commands/test.py", line 24, in
run_from_argv
super().run_from_argv(argv)
File "/app/.venv/lib/python3.12/site-
packages/django/core/management/base.py", line 416, in run_from_argv
self.execute(*args, **cmd_options)
File "/app/.venv/lib/python3.12/site-
packages/django/core/management/base.py", line 460, in execute
output = self.handle(*args, **options)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/app/.venv/lib/python3.12/site-
packages/django/core/management/commands/test.py", line 63, in handle
failures = test_runner.run_tests(test_labels)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/app/.venv/lib/python3.12/site-packages/django/test/runner.py",
line 1099, in run_tests
result = self.run_suite(suite)
^^^^^^^^^^^^^^^^^^^^^
File "/app/.venv/lib/python3.12/site-packages/django/test/runner.py",
line 1026, in run_suite
return runner.run(suite)
^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/unittest/runner.py", line 240, in run
test(result)
File "/usr/local/lib/python3.12/unittest/suite.py", line 84, in __call__
return self.run(*args, **kwds)
^^^^^^^^^^^^^^^^^^^^^^^
File "/app/.venv/lib/python3.12/site-packages/django/test/runner.py",
line 553, in run
subsuite_index, events = test_results.next(timeout=0.1)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/multiprocessing/pool.py", line 873, in
next
raise value
multiprocessing.pool.MaybeEncodingError: Error sending result: '(17,
[('startTest', 0), ('addDuration', 0, 0.02817973299897858), ('addSuccess',
0), ('stopTest', 0), ('startTest', 1), ('addDuration', 1,
0.02015996399859432), ('addSuccess', 1), ('stopTest', 1), ('startTest',
2), ('addDuration', 2, 0.024580582001362927), ('addSuccess', 2),
('stopTest', 2), ('startTest', 3), ('addSubTest', 3,
<unittest.case._SubTest testMethod=runTest>, (<class 'AssertionError'>,
AssertionError('3 != 2 : 3 queries executed, 2 expected\nCaptured queries
were:\n1. SELECT "app_tokenapi"."id", "app_tokenapi"."user_id",
"app_tokenapi"."key", "app_tokenapi"."name", "app_tokenapi"."scope_level",
"app_tokenapi"."created_at", "app_tokenapi"."expired_at",
"app_tokenapi"."expire_reason", "auth_user"."id", "auth_user"."password",
"auth_user"."last_login", "auth_user"."is_superuser",
"auth_user"."username", "auth_user"."first_name", "auth_user"."last_name",
"auth_user"."email", "auth_user"."is_staff", "auth_user"."is_active",
"auth_user"."date_joined" FROM "app_tokenapi" INNER JOIN "auth_user" ON
("app_tokenapi"."user_id" = "auth_user"."id") WHERE "app_tokenapi"."key" =
\'abcdabcd-abcd-abcd-abcd-abcdabcd\' ORDER BY "app_tokenapi"."id" ASC
LIMIT 1\n2. SELECT "my_models_entite"."id", "my_models_entite"."deleted",
"my_models_entite"."deleted_by_cascade", "my_models_entite"."some_id",
"my_models_entite"."parent_id", "my_models_entite"."type_id",
"my_models_entite"."code", "my_models_entite"."libelle",
"my_models_entite"."libelle_court", "my_models_entite"."url_logo",
"my_models_entite"."begin_date", "my_models_entite"."end_date",
"my_models_entite"."created_at", "my_models_entite"."modified_at",
"my_models_entite"."json", "my_models_entite"."allow_externe_id",
"my_models_entitetype"."id", "my_models_entitetype"."name",
"my_models_entitetype"."id_rfu_link",
"my_models_entitetype"."id_imotep_link",
"my_models_entitetype"."created_at", "my_models_entitetype"."modified_at"
FROM "my_models_entite" INNER JOIN "my_models_entitetype" ON
("my_models_entite"."type_id" = "my_models_entitetype"."id") WHERE
"my_models_entite"."deleted" IS NULL ORDER BY "my_models_entite"."libelle"
ASC\n3. SELECT "my_models_entite"."id", "my_models_entite"."deleted",
"my_models_entite"."deleted_by_cascade", "my_models_entite"."some_id",
"my_models_entite"."parent_id", "my_models_entite"."type_id",
"my_models_entite"."code", "my_models_entite"."libelle",
"my_models_entite"."libelle_court", "my_models_entite"."url_logo",
"my_models_entite"."begin_date", "my_models_entite"."end_date",
"my_models_entite"."created_at", "my_models_entite"."modified_at",
"my_models_entite"."json", "my_models_entite"."allow_externe_id" FROM
"my_models_entite" WHERE ("my_models_entite"."id") IN ((54), (NULL), (59),
(62), (56), (55), (58), (57))'), <traceback object at 0x744f93f72e80>)),
('addDuration', 3, 0.032738704001531005), ('stopTest', 3), ('startTest',
4), ('addDuration', 4, 0.01990954599750694), ('addSuccess', 4),
('stopTest', 4), ('startTest', 5), ('addDuration', 5,
0.10901878799995757), ('addSuccess', 5), ('stopTest', 5), ('startTest',
6), ('addDuration', 6, 0.01989884100112249), ('addSuccess', 6),
('stopTest', 6)])'. Reason: 'AttributeError("Can't get local object
'convert_exception_to_response.<locals>.inner'")'
6998993075), ('addSuccess', 6), ('stopTest', 6)])'. Reason:
'AttributeError("Can't get local object
'convert_exception_to_response.<locals>.inner'")'
```
(I've renamed some name in this SQL queries for privacy reason)
# the culprit test
```
def test_queryset_performances(self):
EntiteFactory.create()
with self.subTest("sub test"):
with self.assertNumQueries(2):
response = self.client.get(self.url)
```

# Reproductibility
This errors does not happen if
- We call only this test or only its TestCase (9 tests)
- `self.client.get(self.url)` is not called, `assertNumQueries` still
raise AssertionError but reporting works fine.
- replacing `self.client.get(...)` with a simpler QuerySet call still
raise AssertionError but reporting works fine.
- we remove `self.subTest(...)`

The problem does not appear in django 5.1.8 because the test succeeded in
5.1.8, it seems that 5.2 unexpectedly raised the number of query from 2 to
3 (notice the third query look redundant with the second query) so the
core issue with reporting may be older than 5.2.
--
Ticket URL: <https://code.djangoproject.com/ticket/36308>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.

[Django]

#36308: Parallel testing fails reporting unit test combining subTest and
assertNumQueries
-------------------------------------+-------------------------------------

Reporter: Jean Bvt | Owner: (none)

Type: Bug | Status: new
Component: Testing framework | Version: 5.2

Severity: Normal | Resolution:

Keywords: test assertNumQuery | Triage Stage:
reporting | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------

Description changed by Jean Bvt:

Old description:

New description:

--
Ticket URL: <https://code.djangoproject.com/ticket/36308#comment:1>

[Django]

#36308: Parallel testing fails reporting unit test combining subTest and
assertNumQueries
-------------------------------------+-------------------------------------
Reporter: Jean Bvt | Owner: (none)

Type: Bug | Status: closed

Component: Testing framework | Version: 5.2

Severity: Normal | Resolution: needsinfo

Keywords: test assertNumQuery | Triage Stage:
reporting | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------

Changes (by Sarah Boyce):

* resolution: => needsinfo
* status: new => closed

Comment:

I cannot reproduce, but I think you would need to share your view here.
Does the view raise an error on it's own?

I tried:
{{{#!diff
diff --git a/tests/test_utils/tests.py b/tests/test_utils/tests.py
index 16692500e3..2b2c3cf2bf 100644
--- a/tests/test_utils/tests.py
+++ b/tests/test_utils/tests.py
@@ -237,6 +237,12 @@ class AssertNumQueriesTests(TestCase):

self.assertNumQueries(2, test_func)

+ def test_assert_num_queries_with_client_and_subtest(self):
+ person = Person.objects.create(name="test")
+ with self.subTest("sub test"):
+ with self.assertNumQueries(2):
+ self.client.get("/test_utils/get_person/%s/" % person.pk)
+

class AssertNumQueriesUponConnectionTests(TransactionTestCase):
}}}
And running `./runtests.py test_utils --parallel 2` but this failed in an
expected manner.
--
Ticket URL: <https://code.djangoproject.com/ticket/36308#comment:2>

[Django]

#36308: Parallel testing fails reporting unit test combining subTest and
assertNumQueries
-------------------------------------+-------------------------------------
Reporter: Jean Bvt | Owner: (none)
Type: Bug | Status: closed
Component: Testing framework | Version: 5.2
Severity: Normal | Resolution: needsinfo
Keywords: test assertNumQuery | Triage Stage:
reporting | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------

Comment (by Jean Bvt):

Replying to [comment:2 Sarah Boyce]:

> I cannot reproduce, but I think you would need to share your view here.
> Does the view raise an error on it's own?
>
> I tried:
> {{{#!diff
> diff --git a/tests/test_utils/tests.py b/tests/test_utils/tests.py
> index 16692500e3..2b2c3cf2bf 100644
> --- a/tests/test_utils/tests.py
> +++ b/tests/test_utils/tests.py
> @@ -237,6 +237,12 @@ class AssertNumQueriesTests(TestCase):
>
> self.assertNumQueries(2, test_func)
>
> + def test_assert_num_queries_with_client_and_subtest(self):
> + person = Person.objects.create(name="test")
> + with self.subTest("sub test"):
> + with self.assertNumQueries(2):
> + self.client.get("/test_utils/get_person/%s/" %
person.pk)
> +
>
> class AssertNumQueriesUponConnectionTests(TransactionTestCase):
> }}}
> And running `./runtests.py test_utils --parallel 2` but this failed in
an expected manner.
>

The view does not raise an exception, the raised exception contains a
message related to AssertNumQueries:

> (<class 'AssertionError'>, AssertionError('3 != 2 : 3 queries executed,
2 expected\nCaptured queries were:\n1. SELECT "app_tokenapi"."id",
"app_tokenapi"."user_id", "app_tokenapi"."key", "app_tokenapi"."name",
"app_tokenapi"."scope_level", "app_tokenapi"."created_at",

"app_tokenapi"."expired_at", "app_tokenapi"."expire [...]

making me believe its the reporting that failed.

Anyway, here is my view (and my serializer since I am using DRF)
{{{
@extend_schema(tags=["entite", "v2"])
class EntitesView(ListAPIView):
permission_classes = [AllowAny]
queryset =
Entite.objects.prefetch_related("parent").select_related("type")
serializer_class = EntiteSerializer
logger_instance = logging.getLogger("entites.entites")
filter_backends = (DjangoFilterBackend,)
filterset_class = EntitesFilter
}}}
{{{
from rest_framework.serializers import ModelSerializer
from rest_framework.relations import SlugRelatedField

from my_models.models.entite import Entite, EntiteType
from rest_framework import serializers


class EntiteSerializer(ModelSerializer):
parent = SlugRelatedField(
slug_field="uness_id",
queryset=Entite.objects.all(),
error_messages={
"does_not_exist": "L'identifiant {value} ne correspond à
aucune entité."
},
required=False,
)

type = SlugRelatedField(
slug_field="name",
queryset=EntiteType.objects.all(),
error_messages={
"does_not_exist": "Le type {value} ne correspond à aucun type
d'entité."
},
)
allow_externe_id = serializers.SerializerMethodField()

def get_allow_externe_id(self, obj):
return obj.allow_externe_id

class Meta:
model = Entite
fields = (
"allow_externe_id",
"code",
"json",
"libelle_court",
"libelle",
"parent",
"type",
"uness_id",
"id",
)
read_only_fields = [
"code",
"libelle_court",
"libelle",
"parent",
"type",
"uness_id",
"id",
]

}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/36308#comment:3>

[Django]

#36308: Parallel testing fails reporting unit test combining subTest and
assertNumQueries
-------------------------------------+-------------------------------------
Reporter: Jean Bvt | Owner: (none)
Type: Bug | Status: closed
Component: Testing framework | Version: 5.2
Severity: Normal | Resolution: needsinfo
Keywords: test assertNumQuery | Triage Stage:
reporting | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------

Changes (by Sarah Boyce):

* cc: David Winiecki, Jacob Walls (added)

Comment:

This needs quite a bit of debugging to simplify and reduce dependencies
There's a chance this is related to the changes in #35849 (as you say this
was introduced in Django 5.2), cc-ing some people
#26942 may also be semi-related
--
Ticket URL: <https://code.djangoproject.com/ticket/36308#comment:4>

[Django]

#36308: Parallel testing fails reporting unit test combining subTest and
assertNumQueries
-------------------------------------+-------------------------------------
Reporter: Jean Bvt | Owner: (none)
Type: Bug | Status: closed
Component: Testing framework | Version: 5.2
Severity: Normal | Resolution: needsinfo
Keywords: test assertNumQuery | Triage Stage:
reporting | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------

Comment (by Jacob Walls):

> The problem does not appear in django 5.1.8 because the test succeeded
in 5.1.8, it seems that 5.2 unexpectedly raised the number of query from 2
to 3 (notice the third query look redundant with the second query) so the
core issue with reporting may be older than 5.2.

The first query looks related to auth, and queries 2 and 3 are as I would
expect when using `.prefetch_related()`. If you didn't see that third
query before, it seems your test data may have changed. Django will not
execute the `.prefetch_related("parent")` if the queryset it is chained to
returned no results. You could verify this quickly by counting
`Entite.objects.all()` at the top of your test and let us know if that
varies between 5.1.8 and 5.2.

Seeing your TestCase would be helpful. For instance, does it subclass
`TestCase` or `TransactionTestCase`? Do you have a `setUpClass()` method?

Finally, a `git bisect` would be very helpful here. You can clone the
django repo, `pip install -e path-to-local-copy-of-django`, run your test
case, and in a matter of minutes report the commit that caused the symptom
of the problem to appear.
--
Ticket URL: <https://code.djangoproject.com/ticket/36308#comment:5>

[Django]

#36308: Parallel testing fails reporting unit test combining subTest and
assertNumQueries
-------------------------------------+-------------------------------------
Reporter: Jean Bvt | Owner: (none)
Type: Bug | Status: closed
Component: Testing framework | Version: 5.2
Severity: Normal | Resolution: needsinfo
Keywords: test assertNumQuery | Triage Stage:
reporting | Unreviewed
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------

Comment (by Jean Bvt):

Replying to [comment:5 Jacob Walls]:

> > The problem does not appear in django 5.1.8 because the test succeeded
in 5.1.8, it seems that 5.2 unexpectedly raised the number of query from 2
to 3 (notice the third query look redundant with the second query) so the
core issue with reporting may be older than 5.2.
>
> The first query looks related to auth, and queries 2 and 3 are as I
would expect when using `.prefetch_related()`. If you didn't see that
third query before, it seems your test data may have changed. Django will
not execute the `.prefetch_related("parent")` if the queryset it is
chained to returned no results. You could verify this quickly by counting
`Entite.objects.all()` at the top of your test and let us know if that
varies between 5.1.8 and 5.2.
>
> Seeing your TestCase would be helpful. For instance, does it subclass
`TestCase` or `TransactionTestCase`? Do you have a `setUpClass()` method?
>
> Finally, a `git bisect` would be very helpful here. You can clone the
django repo, `pip install -e path-to-local-copy-of-django`, run your test
case, and in a matter of minutes report the commit that caused the symptom
of the problem to appear.

Thank you for your reply, I'll try to do all that once I've some time
--
Ticket URL: <https://code.djangoproject.com/ticket/36308#comment:6>