classification
Title: Clear caches after every test
Type: resource usage Stage: resolved
Components: Tests Versions: Python 3.7, Python 3.6, Python 3.5, Python 2.7
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: serhiy.storchaka Nosy List: ezio.melotti, martin.panter, michael.foord, pitrou, python-dev, rbcollins, rhettinger, serhiy.storchaka, vstinner
Priority: normal Keywords: patch

Created on 2015-04-01 11:30 by serhiy.storchaka, last changed 2017-03-31 16:36 by dstufft. This issue is now closed.

Files
File name Uploaded Description Edit
regrtest_clear_caches.patch serhiy.storchaka, 2015-04-02 10:54 review
regrtest_clear_caches_2.patch serhiy.storchaka, 2016-11-09 18:51 review
regrtest_clear_caches_3.patch serhiy.storchaka, 2016-11-10 06:53 review
Pull Requests
URL Status Linked Edit
PR 552 closed dstufft, 2017-03-31 16:36
Messages (17)
msg239782 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2015-04-01 11:30
Some caches can grow unlimitedly during running the testsuite (in particular linecache). On some machines with limited resources this can cause multiple MemoryErrors. Many of these MemoryErrors can be avoided if clear caches between tests. Lib/test/regrtest.py already contains a code for cleaning caches, but it is used only with the -R option.
msg239791 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2015-04-01 12:05
Maybe tests known to fill caches should clear theirself caches at cleanup? Always clearing all caches may have an impact on performances and so makes tests longer. Caches are designed to speedup Python :-)

We may add some helper functions in test.support for the most common caches, but not to clear *all* caches.

By the way, forcing calls to gc.collect() may make tests more reliable. It would avoid to get warnings 4 lines after the test leaking a resource finished.

But it's not easy to make this reliable, because unittest stores a lot of things. unittest.TestCase.run() stores exceptions which store a traceback which stores frames which store references to local variables. Instead of storing a whole sys.exc_info(), we can maybe use the new light traceback.TracebackException which only stores info required to format a traceback as text, without storing all these heavily objects creating reference cycles.

(Hum, it becomes a little off-topic, sorry, we may open a new separated issue.)
msg239794 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2015-04-01 12:33
We should try to know how it impacts a performance. I suppose not too much, but may be my intuition lies me.
msg239796 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2015-04-01 12:39
By the way, a workaround is also to run each test (file) in a new fresh process. It's a common way to work around memory fragmentation ;-)

> On some machines with limited resources this can cause multiple MemoryErrors.

Do you have an idea of the memory usage of the Python test suite? You may run it with tracemalloc to get the memory peak from tracemalloc.get_traced_memory()[1].

I mean, memory is cheap nowadays. If you get MemoryError, it's probably more a bug than tests leaking more and more memory, no?
msg239799 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2015-04-01 12:57
max_rss is a little larger 500 MB after ran all testsuite (except bigmem tests) on 32-bit Linux. Only few tests needs more than 200 MB. But may be some 64-bit only tests consume more memory. If a test consume more than 1GiB of memory and is not decorated with bigmemtest, it should be considered as a bug.
msg239844 - (view) Author: Robert Collins (rbcollins) * (Python committer) Date: 2015-04-01 20:30
I'd like to see a definite profile of a bloated stdlib test process before we assume we know the issue - the usual leak I see in test code is used test objects, and I'm not sure we've ported the usual fix for that into unittest yet (we should).

As far as linecache is concerned, we shouldn't be triggering linecache population except when a traceback is actually rendered, and so on a passing test run there should be little hitting it at all outside of tests that actually test rendering of tracebacks.
msg239845 - (view) Author: Robert Collins (rbcollins) * (Python committer) Date: 2015-04-01 20:31
+1 on moving to the summary classes rather than actual tracebacks in unittest. (Or perhaps even just serialised tracebacks like we do in testtools).
msg239898 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2015-04-02 10:54
I ran all tests with and without clearing all caches.

Unpatched (without clearing):

real    31m23.694s
user    16m10.340s
sys     2m25.084s

Patched (with clearing):

real    29m28.859s
user    16m19.048s
sys     1m42.184s

There is no significant difference (may be with the patch tests are even faster).
msg249038 - (view) Author: Robert Collins (rbcollins) * (Python committer) Date: 2015-08-24 00:20
Ok, so this is still in the noise space - it might be useful, it might not. Do we have reports of machines failing to run the test suite (that are also usefully big enough to compile Python and use it)?
msg249287 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2015-08-28 18:46
http://buildbot.python.org/all/builders/AMD64%20OpenIndiana%203.x/builds/9963/steps/test/logs/stdio

Passed 395 tests of 398 and failed on test_decimal:

...
[396/398] test_decimal
Traceback (most recent call last):
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/test/regrtest.py", line 1276, in runtest_inner
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/test/test_decimal.py", line 5598, in test_main
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/test/support/__init__.py", line 1809, in run_unittest
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/test/support/__init__.py", line 1775, in _run_suite
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/unittest/runner.py", line 176, in run
    test(result)
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/unittest/suite.py", line 84, in __call__
    return self.run(*args, **kwds)
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/unittest/suite.py", line 122, in run
    test(result)
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/unittest/suite.py", line 84, in __call__
    return self.run(*args, **kwds)
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/unittest/suite.py", line 122, in run
    test(result)
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/unittest/case.py", line 645, in __call__
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/unittest/case.py", line 605, in run
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/unittest/case.py", line 538, in _feedErrorsToResult
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/unittest/runner.py", line 69, in addError
    self.stream.writeln("ERROR")
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/unittest/runner.py", line 25, in writeln
    self.write(arg)
MemoryError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/test/regrtest.py", line 1279, in runtest_inner
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/test/regrtest.py", line 1232, in __exit__
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/test/regrtest.py", line 1172, in get_sysconfig__CONFIG_VARS
MemoryError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/test/regrtest.py", line 532, in main
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/test/regrtest.py", line 963, in runtest
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/test/regrtest.py", line 1300, in runtest_inner
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/traceback.py", line 163, in format_exc
    return "".join(format_exception(*sys.exc_info(), limit=limit, chain=chain))
MemoryError
Traceback (most recent call last):
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/runpy.py", line 170, in _run_module_as_main
    "__main__", mod_spec)
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/test/__main__.py", line 3, in <module>
    regrtest.main_in_temp_cwd()
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/test/regrtest.py", line 1560, in main_in_temp_cwd
    main()
  File "/export/home/buildbot/64bits/3.x.cea-indiana-amd64/build/Lib/test/regrtest.py", line 738, in main
    raise Exception("Child error on {}: {}".format(test, result[1]))
Exception: Child error on test_decimal:
msg249288 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2015-08-28 18:50
May be related: http://buildbot.python.org/all/builders/x86%20OpenIndiana%203.x/builds/10375/steps/test/logs/stdio

======================================================================
ERROR: testCount (test.test_socket.SendfileUsingSendfileTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/export/home/buildbot/32bits/3.x.cea-indiana-x86/build/Lib/test/test_socket.py", line 5160, in testCount
  File "/export/home/buildbot/32bits/3.x.cea-indiana-x86/build/Lib/test/test_socket.py", line 5063, in recv_data
MemoryError

======================================================================
ERROR: testCount (test.test_socket.SendfileUsingSendfileTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/export/home/buildbot/32bits/3.x.cea-indiana-x86/build/Lib/test/test_socket.py", line 266, in _tearDown
  File "/export/home/buildbot/32bits/3.x.cea-indiana-x86/build/Lib/test/test_socket.py", line 278, in clientRun
  File "/export/home/buildbot/32bits/3.x.cea-indiana-x86/build/Lib/test/test_socket.py", line 5153, in _testCount
  File "/export/home/buildbot/32bits/3.x.cea-indiana-x86/build/Lib/socket.py", line 282, in _sendfile_use_sendfile
    raise _socket.timeout('timed out')
socket.timeout: timed out

======================================================================
ERROR: testWithTimeout (test.test_socket.SendfileUsingSendfileTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/export/home/buildbot/32bits/3.x.cea-indiana-x86/build/Lib/test/test_socket.py", line 5230, in testWithTimeout
  File "/export/home/buildbot/32bits/3.x.cea-indiana-x86/build/Lib/test/test_socket.py", line 5063, in recv_data
MemoryError

======================================================================
ERROR: testWithTimeout (test.test_socket.SendfileUsingSendfileTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/export/home/buildbot/32bits/3.x.cea-indiana-x86/build/Lib/test/test_socket.py", line 266, in _tearDown
  File "/export/home/buildbot/32bits/3.x.cea-indiana-x86/build/Lib/test/test_socket.py", line 278, in clientRun
  File "/export/home/buildbot/32bits/3.x.cea-indiana-x86/build/Lib/test/test_socket.py", line 5225, in _testWithTimeout
  File "/export/home/buildbot/32bits/3.x.cea-indiana-x86/build/Lib/socket.py", line 282, in _sendfile_use_sendfile
    raise _socket.timeout('timed out')
socket.timeout: timed out

----------------------------------------------------------------------
msg280433 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2016-11-09 18:51
Synchronized with current code and added clearing typing caches.
msg280562 - (view) Author: Raymond Hettinger (rhettinger) * (Python committer) Date: 2016-11-11 06:32
LGTM.
msg280571 - (view) Author: Roundup Robot (python-dev) (Python triager) Date: 2016-11-11 09:49
New changeset bc81f2137706 by Serhiy Storchaka in branch '2.7':
Issue #23839: Various caches now are cleared before running every test file.
https://hg.python.org/cpython/rev/bc81f2137706

New changeset 89776a40e0ec by Serhiy Storchaka in branch '3.5':
Issue #23839: Various caches now are cleared before running every test file.
https://hg.python.org/cpython/rev/89776a40e0ec

New changeset c89f213b21e8 by Serhiy Storchaka in branch '3.6':
Issue #23839: Various caches now are cleared before running every test file.
https://hg.python.org/cpython/rev/c89f213b21e8

New changeset 5d1067e89717 by Serhiy Storchaka in branch 'default':
Issue #23839: Various caches now are cleared before running every test file.
https://hg.python.org/cpython/rev/5d1067e89717
msg280579 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2016-11-11 12:51
Thanks for the review Raymond.
msg280725 - (view) Author: Martin Panter (martin.panter) * (Python committer) Date: 2016-11-14 01:05
When I run the tests with -Werror (or any other -W option), I now get

2 tests altered the execution environment:
    test___all__ test_warnings
msg280768 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2016-11-14 12:57
Martin Panter:
"""
When I run the tests with -Werror (or any other -W option), I now get

2 tests altered the execution environment:
    test___all__ test_warnings
"""

I confirm: I opened issue #28688 to track this issue (this issue is now closed).
History
Date User Action Args
2017-03-31 16:36:37dstufftsetpull_requests: + pull_request1094
2016-11-14 12:57:50vstinnersetmessages: + msg280768
2016-11-14 01:05:57martin.pantersetnosy: + martin.panter
messages: + msg280725
2016-11-11 12:51:26serhiy.storchakasetstatus: open -> closed
versions: + Python 3.7
messages: + msg280579

assignee: serhiy.storchaka
resolution: fixed
stage: patch review -> resolved
2016-11-11 09:49:20python-devsetnosy: + python-dev
messages: + msg280571
2016-11-11 06:32:46rhettingersetnosy: + rhettinger
messages: + msg280562
2016-11-10 06:53:54serhiy.storchakasetfiles: + regrtest_clear_caches_3.patch
2016-11-09 18:51:11serhiy.storchakasetfiles: + regrtest_clear_caches_2.patch

messages: + msg280433
2016-06-21 20:04:35serhiy.storchakasetversions: + Python 3.6, - Python 3.4
2015-08-28 18:50:16serhiy.storchakasetmessages: + msg249288
2015-08-28 18:46:55serhiy.storchakasetmessages: + msg249287
2015-08-24 00:20:53rbcollinssetmessages: + msg249038
2015-04-02 10:54:49serhiy.storchakasetfiles: + regrtest_clear_caches.patch
keywords: + patch
stage: patch review
2015-04-02 10:54:17serhiy.storchakasetmessages: + msg239898
2015-04-01 20:31:47rbcollinssetmessages: + msg239845
2015-04-01 20:30:15rbcollinssetmessages: + msg239844
2015-04-01 12:57:37serhiy.storchakasetmessages: + msg239799
2015-04-01 12:39:17vstinnersetmessages: + msg239796
2015-04-01 12:33:16serhiy.storchakasetmessages: + msg239794
2015-04-01 12:05:11vstinnersetnosy: + rbcollins
2015-04-01 12:05:04vstinnersetmessages: + msg239791
2015-04-01 11:30:41serhiy.storchakacreate