[Django] #35728: Lazily compute assertion messages

[Django]

#35728: Lazily compute assertion messages
-------------------------------------+-------------------------------------
Reporter: Adam Johnson | Type:
| Cleanup/optimization
Status: new | Component: Testing
| framework
Version: dev | 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
-------------------------------------+-------------------------------------
Django’s custom test assertions have some rich failure messages.
Typically, assertions pass, so most computation of these messages is
wasted.

This overhead is quite noticeable for messages based on large strings. For
example, `assertContains` calls `repr()` on the whole response content,
typically thousands of bytes.

To mitigate this, I propose that all custom assert methods pass lazy-
computing objects to unittest’s `msg` arguments.
[https://github.com/python/cpython/blob/f95fc4de115ae03d7aa6dece678240df085cb4f6/Lib/unittest/case.py#L755-L774
unittest’s _formatMessage()] effectively calls `str()` on the given object
when displaying, so this should work well.

To measure the overhead, I created this test script, named `benchmark.py`:

{{{
import unittest

from django.conf import settings
from django.http import HttpResponse
from django.test import SimpleTestCase

if not settings.configured:
settings.configure()


class ExampleTests(SimpleTestCase):
def test_example(self):
response = HttpResponse("Apple\n" * 1_000)
for _ in range(100_000):
self.assertContains(response, "Apple")


if __name__ == '__main__':
unittest.main(module='benchmark')
}}}

I ran it under cProfile with:

{{{
$ python -m cProfile -o profile -m benchmark
}}}

I tried it without and with the below patch, which disables the custom
message for `assertContains`:

{{{
diff --git django/test/testcases.py django/test/testcases.py
index cd7e7b45d6..de86cb55ec 100644
--- django/test/testcases.py
+++ django/test/testcases.py
@@ -580,13 +580,13 @@ def _assert_contains(self, response, text,
status_code, msg_prefix, html):
content = b"".join(response.streaming_content)
else:
content = response.content
- content_repr = safe_repr(content)
+ content_repr = ""
if not isinstance(text, bytes) or html:
text = str(text)
content = content.decode(response.charset)
- text_repr = "'%s'" % text
+ text_repr = ""
else:
- text_repr = repr(text)
+ text_repr = ""
if html:
content = assert_and_parse_html(
self, content, None, "Response's content is not valid
HTML:"
@@ -623,10 +623,10 @@ def assertContains(
else:
self.assertTrue(
real_count != 0,
- (
- f"{msg_prefix}Couldn't find {text_repr} in the
following response\n"
- f"{content_repr}"
- ),
+ # (
+ # f"{msg_prefix}Couldn't find {text_repr} in the
following response\n"
+ # f"{content_repr}"
+ # ),
)

def assertNotContains(
}}}

Here are the stats.

Before:

* 2,724,770 function calls in 2.280 seconds
* 2.119 seconds spent in `assertContains` calls

After:

* 2,524,805 function calls in 1.117 seconds
* 0.949 seconds spent in `assertContains` calls

It looks like ~50% of the cost of calling `assertContains` is forming the
message.
--
Ticket URL: <https://code.djangoproject.com/ticket/35728>
Django <https://code.djangoproject.com/>
The Web framework for perfectionists with deadlines.

[Django]

#35728: Lazily compute assertion messages

--------------------------------------+------------------------------------
Reporter: Adam Johnson | Owner: (none)

Type: Cleanup/optimization | Status: new
Component: Testing framework | Version: dev

Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted

Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0

--------------------------------------+------------------------------------
Changes (by Natalia Bidart):

* stage: Unreviewed => Accepted

Comment:

Thank you Adam for this ticket and analysis, I agree with your rationale.

I performed a simpler test: I added the proposed testcase in an existing
`tests.py` file, and ran with the usual `python -Wall manage.py test
testapp.tests.ExampleTests`. Then, I replaced `assertContains` with a call
similar to `self.assertIn(text, response.content.decode())`. My timings
are:

* without the replacement, `ExampleTests` runs in about 4 seconds
* with the replacement, `ExampleTests` runs in around a second (0.950s)

Accepting following the above with the note that we should, ideally, be
mindful of potential subclassing of Django's TestCase when designing how
the laziness will be incorported to ensure backwards compatibility.
--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:1>

[Django]

#35728: Lazily compute assertion messages
--------------------------------------+------------------------------------
Reporter: Adam Johnson | Owner: (none)
Type: Cleanup/optimization | Status: new
Component: Testing framework | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------

Comment (by Adam Johnson):

Nice benchmarking idea. Looks like we may be able to trim the overhead
further.

For reference, `assertIn` avoids the overhead by performing the test
first:

https://github.com/python/cpython/blob/fbb26f067a7a3cd6dc6eed31cce12892cc0fedbb/Lib/unittest/case.py#L1178-L1183

I think we should be able to adopt that pattern too. No need for a lazy
string, really.

> Accepting following the above with the note that we should, ideally, be
mindful of potential subclassing of Django's TestCase when designing how
the laziness will be incorported to ensure backwards compatibility.

Sure, but I don’t think we don’t need to support, say, an overridden
`_assert_contains`, because that’s the private method under the public
`assertContains`.
--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:2>

[Django]

#35728: Lazily compute assertion messages
--------------------------------------+------------------------------------
Reporter: Adam Johnson | Owner: (none)
Type: Cleanup/optimization | Status: new
Component: Testing framework | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------

Comment (by Ahmed Ibrahim):

What's the status of this ticket? can I help in any way?
--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:3>

[Django]

#35728: Lazily compute assertion messages
--------------------------------------+------------------------------------

Reporter: Adam Johnson | Owner: devda
Type: Cleanup/optimization | Status: assigned

Component: Testing framework | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------

Changes (by devday):

* owner: (none) => devda
* status: new => assigned

--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:4>

[Django]

#35728: Lazily compute assertion messages
--------------------------------------+------------------------------------

Reporter: Adam Johnson | Owner: (none)
Type: Cleanup/optimization | Status: new

Component: Testing framework | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------
Changes (by devday):

* owner: devda => (none)
* status: assigned => new

--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:5>

[Django]

#35728: Lazily compute assertion messages
--------------------------------------+------------------------------------

Reporter: Adam Johnson | Owner: Rish
Type: Cleanup/optimization | Status: assigned

Component: Testing framework | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
--------------------------------------+------------------------------------

Changes (by Rish):

* owner: (none) => Rish

* status: new => assigned

--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:4>

[Django]

#35728: Lazily compute assertion messages

-------------------------------------+-------------------------------------
Reporter: Adam Johnson | Owner: Clifford
Type: | Gama

Cleanup/optimization | Status: assigned
Component: Testing framework | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 0 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0

-------------------------------------+-------------------------------------
Changes (by Clifford Gama):

* owner: Rish => Clifford Gama

--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:5>

[Django]

#35728: Lazily compute assertion messages
-------------------------------------+-------------------------------------
Reporter: Adam Johnson | Owner: Clifford
Type: | Gama
Cleanup/optimization | Status: assigned
Component: Testing framework | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted

Has patch: 1 | Needs documentation: 0

Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Changes (by Clifford Gama):

* has_patch: 0 => 1

--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:6>

[Django]

#35728: Lazily compute assertion messages
-------------------------------------+-------------------------------------
Reporter: Adam Johnson | Owner: Clifford
Type: | Gama
Cleanup/optimization | Status: assigned
Component: Testing framework | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0

Needs tests: 0 | Patch needs improvement: 1

Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Changes (by Clifford Gama):

* needs_better_patch: 0 => 1

--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:7>

[Django]

#35728: Lazily compute assertion messages
-------------------------------------+-------------------------------------
Reporter: Adam Johnson | Owner: Clifford
Type: | Gama
Cleanup/optimization | Status: assigned
Component: Testing framework | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0

Needs tests: 0 | Patch needs improvement: 0

Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------
Changes (by Clifford Gama):

* needs_better_patch: 1 => 0

--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:8>

[Django]

#35728: Lazily compute assertion messages
-------------------------------------+-------------------------------------
Reporter: Adam Johnson | Owner: Clifford
Type: | Gama
Cleanup/optimization | Status: assigned
Component: Testing framework | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------

Comment (by Sarah Boyce):

Note that this is a performance regression in
1dae65dc63ae84be5002c37b4ddae0b9220e8808 (Django 5.1) refs #34657
--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:9>

[Django]

#35728: Lazily compute assertion messages
-------------------------------------+-------------------------------------
Reporter: Adam Johnson | Owner: Clifford
Type: | Gama
Cleanup/optimization | Status: assigned
Component: Testing framework | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0

Needs tests: 0 | Patch needs improvement: 1

Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------

Changes (by Sarah Boyce):

* needs_better_patch: 0 => 1

--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:10>

[Django]

#35728: Lazily compute assertion messages
-------------------------------------+-------------------------------------
Reporter: Adam Johnson | Owner: Clifford
Type: | Gama
Cleanup/optimization | Status: assigned
Component: Testing framework | Version: dev
Severity: Normal | Resolution:
Keywords: | Triage Stage: Accepted
Has patch: 1 | Needs documentation: 0

Needs tests: 0 | Patch needs improvement: 0

Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------

Changes (by Clifford Gama):

* needs_better_patch: 1 => 0

--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:11>

[Django]

#35728: Lazily compute assertion messages
-------------------------------------+-------------------------------------
Reporter: Adam Johnson | Owner: Clifford
Type: | Gama
Cleanup/optimization | Status: assigned
Component: Testing framework | Version: dev
Severity: Normal | Resolution:

Keywords: | Triage Stage: Ready for
| checkin

Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------

Changes (by Sarah Boyce):

* stage: Accepted => Ready for checkin

--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:12>

[Django]

#35728: Lazily compute assertion messages
-------------------------------------+-------------------------------------
Reporter: Adam Johnson | Owner: Clifford
Type: | Gama

Cleanup/optimization | Status: closed

Component: Testing framework | Version: dev

Severity: Normal | Resolution: fixed

Keywords: | Triage Stage: Ready for
| checkin
Has patch: 1 | Needs documentation: 0
Needs tests: 0 | Patch needs improvement: 0
Easy pickings: 0 | UI/UX: 0
-------------------------------------+-------------------------------------

Changes (by Sarah Boyce <42296566+sarahboyce@…>):

* resolution: => fixed
* status: assigned => closed

Comment:

In [changeset:"449b9f9aeeaa3a1529d2c29a9a43e87350177559" 449b9f9]:
{{{#!CommitTicketReference repository=""
revision="449b9f9aeeaa3a1529d2c29a9a43e87350177559"
Fixed #35728 -- Computed error messages in assertions only on test
failures.

Performance regression in 1dae65dc63ae84be5002c37b4ddae0b9220e8808.

Thanks to Adam Johnson for the report.
}}}
--
Ticket URL: <https://code.djangoproject.com/ticket/35728#comment:13>