◐ Shell
reader mode source ↗
Skip to content

gh-108416: Mark slow test methods with @requires_resource('cpu')#108421

Merged
serhiy-storchaka merged 6 commits into
python:mainfrom
serhiy-storchaka:mark-slow-tests
Sep 2, 2023
Merged

gh-108416: Mark slow test methods with @requires_resource('cpu')#108421
serhiy-storchaka merged 6 commits into
python:mainfrom
serhiy-storchaka:mark-slow-tests

Conversation

@serhiy-storchaka

@serhiy-storchaka serhiy-storchaka commented Aug 24, 2023 •
edited by bedevere-bot
Loading

Copy link
Copy Markdown
Member

@serhiy-storchaka serhiy-storchaka added tests Tests in the Lib/test dir skip news needs backport to 3.11 only security fixes needs backport to 3.12 only security fixes labels Aug 24, 2023
@bedevere-bot bedevere-bot mentioned this pull request Aug 24, 2023
Closed
@serhiy-storchaka serhiy-storchaka mentioned this pull request Aug 24, 2023
Closed
@vstinner

vstinner commented Aug 24, 2023

Copy link
Copy Markdown
Member

How did you decide if a function is "slow" or not?

@serhiy-storchaka

serhiy-storchaka commented Aug 24, 2023

Copy link
Copy Markdown
Member Author

I ran all the tests and then sorted them by execution time. --junit-xml saves the execution time per test.

@ambv

ambv commented Aug 24, 2023

Copy link
Copy Markdown
Contributor

Results from macOS 13.5 on M1 Max: from 5 minutes 11 seconds down to 2 minutes 25 seconds.

I would prefer if there was some indication in the summary of how many tests were skipped due to not enabling various resources. We can add this in a separate PR but I consider this important. Right now it's easy to miss the fact that you ran fewer tests. It says "428 tests OK" in both cases.

-m test -j12 -ucpu (with slow tests)

428 tests OK.

10 slowest tests:
- test_math: 3 min 18 sec
- test_tools: 2 min 38 sec
- test_concurrent_futures: 2 min 31 sec
- test_capi: 1 min 39 sec
- test.test_multiprocessing_spawn.test_processes: 1 min 25 sec
- test_faulthandler: 1 min 17 sec
- test_tokenize: 1 min 11 sec
- test_unparse: 1 min 9 sec
- test.test_multiprocessing_forkserver.test_processes: 59.9 sec
- test_signal: 56.2 sec

1 test altered the execution environment:
    test_tools

27 tests skipped:
    test.test_asyncio.test_windows_events
    test.test_asyncio.test_windows_utils
    test.test_multiprocessing_fork.test_manager
    test.test_multiprocessing_fork.test_misc
    test.test_multiprocessing_fork.test_processes
    test.test_multiprocessing_fork.test_threads test_curses
    test_dbm_gnu test_devpoll test_epoll test_gdb test_ioctl
    test_launcher test_perf_profiler test_perfmaps test_smtpnet
    test_socketserver test_startfile test_tkinter test_ttk
    test_urllib2net test_urllibnet test_winconsoleio test_winreg
    test_winsound test_wmi test_zipfile64

Total duration: 5 min 11 sec
Tests result: ENV CHANGED

________________________________________________________
Executed in  312.17 secs    fish           external
   usr time   31.05 mins   48.00 micros   31.05 mins
   sys time    2.44 mins  379.00 micros    2.44 mins

-m test -j12 -u-cpu (without slow tests)

428 tests OK.

10 slowest tests:
- test_concurrent_futures: 1 min 26 sec
- test.test_multiprocessing_spawn.test_processes: 1 min 14 sec
- test_capi: 1 min 10 sec
- test_faulthandler: 1 min 4 sec
- test.test_multiprocessing_forkserver.test_processes: 49.6 sec
- test_tarfile: 39.9 sec
- test.test_multiprocessing_spawn.test_misc: 37.3 sec
- test_ssl: 35.8 sec
- test_socket: 33.1 sec
- test.test_multiprocessing_spawn.test_manager: 33.0 sec

28 tests skipped:
    test.test_asyncio.test_windows_events
    test.test_asyncio.test_windows_utils
    test.test_multiprocessing_fork.test_manager
    test.test_multiprocessing_fork.test_misc
    test.test_multiprocessing_fork.test_processes
    test.test_multiprocessing_fork.test_threads test_curses
    test_dbm_gnu test_devpoll test_epoll test_gdb test_ioctl
    test_launcher test_peg_generator test_perf_profiler test_perfmaps
    test_smtpnet test_socketserver test_startfile test_tkinter
    test_ttk test_urllib2net test_urllibnet test_winconsoleio
    test_winreg test_winsound test_wmi test_zipfile64

Total duration: 2 min 25 sec
Tests result: SUCCESS

________________________________________________________
Executed in  146.01 secs    fish           external
   usr time   16.23 mins   47.00 micros   16.23 mins
   sys time    1.16 mins  373.00 micros    1.16 mins

@gpshead

gpshead commented Aug 24, 2023

Copy link
Copy Markdown
Member

see the issue, I don't like doing this. A goal of avoiding running regression tests is not the right goal.

@serhiy-storchaka

serhiy-storchaka commented Aug 24, 2023

Copy link
Copy Markdown
Member Author

Results from macOS 13.5 on M1 Max: from 5 minutes 11 seconds down to 2 minutes 25 seconds.

Is it the time of running all tests? It is impressive, I did not expect such difference.

This PR adds @requires_resource('cpu') to 86 tests out of 41665, i.e. it allows to skip 0.2% of tests. And it leads to reducing the time more than twice?! 🤯

I would prefer if there was some indication in the summary of how many tests were skipped due to not enabling various resources. We can add this in a separate PR but I consider this important.

I'll do this. Currently the summary only shows if the test file was skipped completely, but not if a TestCase class or separate method was skipped. Although I afraid that the output can be very verbose, because normally many tests are skipped for different reasons. But it would be useful to have such option.

@gpshead

gpshead commented Aug 25, 2023

Copy link
Copy Markdown
Member

Sync and merge past the parallelization refactorings that Victor merged before measuring again.

I don't think we should be abusing the 'cpu' resource for this. Many of these are not CPU hogs so that becomes misleading. Some are important to have run so that we don't break everything. (the AST test that parses the stdlib for example)

Should I go through all 86 tests and give a thumbs up / thumbs down to them being annotated? I'm against merging this as it is... but I think we can get something in sensible shape.

(deeper thoughts recorded on the issue)

7 hidden items Load more…
@serhiy-storchaka

serhiy-storchaka commented Aug 25, 2023

Copy link
Copy Markdown
Member Author

Some tests (test_random_files in Lib/test/test_tokenize.py, test_files in Lib/test/test_unparse.py) test if the cpu resource is enabled, and if it is not, they are not skipped, but run with a small subset of the inputs. I use the same approach in my work-in-progress patch for test_unicodedata. I think that we should use this approach more if it is appropriate (not all tests can be downscaled). But first we should know what tests are slow and for what cause.

@vstinner

vstinner commented Aug 25, 2023

Copy link
Copy Markdown
Member

they are not skipped, but run with a small subset of the inputs

Please log a message in verbose mode, to help debugging. It's surprising when a test pass and then fail on the same machine.

@serhiy-storchaka

serhiy-storchaka commented Aug 26, 2023

Copy link
Copy Markdown
Member Author

Please log a message in verbose mode, to help debugging. It's surprising when a test pass and then fail on the same machine.

They print full lists of tested files in verbose mode.

@serhiy-storchaka

serhiy-storchaka commented Aug 26, 2023

Copy link
Copy Markdown
Member Author

Should I go through all 86 tests and give a thumbs up / thumbs down to them being annotated?

It would help. There are now half as many of them. I have reviewed each case several times and can justify them. But there is always the possibility of missing something and my criteria could be wrong.

@serhiy-storchaka

serhiy-storchaka commented Aug 29, 2023

Copy link
Copy Markdown
Member Author

test_sumprod_stress kills a buildbot: https://buildbot.python.org/all/#/builders/256/builds/1211/steps/6/logs/stdio

@vstinner

vstinner commented Aug 29, 2023

Copy link
Copy Markdown
Member

test_sumprod_stress kills a buildbot

It's a test_math test.

gpshead
gpshead approved these changes Sep 1, 2023
View reviewed changes

@gpshead gpshead left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hide comment

These all make sense as cpu hogs to me.

@vstinner

vstinner commented Sep 2, 2023

Copy link
Copy Markdown
Member

I'm a bit worried that you might forget to un-skip tests in the future, like test_crashers which only run for 3 hours, and then was always skipped for 12 years.

So I wrote PR #108793 to write a more detailed report on tests statistics. To remind that some tests are skipped (for good or bad reasons).

@serhiy-storchaka

serhiy-storchaka commented Sep 2, 2023

Copy link
Copy Markdown
Member Author

test_crashers was run for 3 days, not hours!

These tests are not skipped. I almost always run tests with -uall, and buildbots usually do the same. Well, now there will be more reasons to me to run them with -uall,-cpu by default, but I'll still continue to run them with -uall sometimes.

On other hand, bigmem tests are disabled by default, and run very infrequently. Some of them require over 200GB of memory, so they are never run.

@serhiy-storchaka serhiy-storchaka merged commit f3ba0a7 into python:main Sep 2, 2023
@miss-islington

miss-islington commented Sep 2, 2023

Copy link
Copy Markdown
Contributor

Thanks @serhiy-storchaka for the PR 🌮🎉.. I'm working now to backport this PR to: 3.11, 3.12.
🐍🍒⛏🤖

@serhiy-storchaka serhiy-storchaka deleted the mark-slow-tests branch September 2, 2023 04:45
miss-islington pushed a commit to miss-islington/cpython that referenced this pull request Sep 2, 2023
@serhiy-storchaka @miss-islington
pythongh-108416: Mark slow test methods with @requires_resource('cpu') ( …
ac6ae47 
pythonGH-108421)

Only mark tests which spend significant system or user time,
by itself or in subprocesses.
(cherry picked from commit f3ba0a7)

Co-authored-by: Serhiy Storchaka <storchaka@gmail.com>
@bedevere-bot

bedevere-bot commented Sep 2, 2023

Copy link
Copy Markdown

GH-108798 is a backport of this pull request to the 3.12 branch.

@miss-islington

miss-islington commented Sep 2, 2023

Copy link
Copy Markdown
Contributor

Sorry, @serhiy-storchaka, I could not cleanly backport this to 3.11 due to a conflict.
Please backport using cherry_picker on command line.
cherry_picker f3ba0a74cd50274acdcd592d4ce8395b92492b7c 3.11

@bedevere-bot bedevere-bot removed the needs backport to 3.12 only security fixes label Sep 2, 2023
serhiy-storchaka added a commit to serhiy-storchaka/cpython that referenced this pull request Sep 2, 2023
@serhiy-storchaka
[3.11] pythongh-108416: Mark slow test methods with @requires_resourc… …
4f394c2 
…e('cpu') (pythonGH-108421)

Only mark tests which spend significant system or user time,
by itself or in subprocesses..
(cherry picked from commit f3ba0a7)

Co-authored-by: Serhiy Storchaka <storchaka@gmail.com>
@bedevere-bot

bedevere-bot commented Sep 2, 2023

Copy link
Copy Markdown

GH-108799 is a backport of this pull request to the 3.11 branch.

@bedevere-bot bedevere-bot removed the needs backport to 3.11 only security fixes label Sep 2, 2023
@serhiy-storchaka serhiy-storchaka removed their assignment Sep 2, 2023
@bedevere-bot

bedevere-bot commented Sep 2, 2023

Copy link
Copy Markdown

⚠️⚠️⚠️ Buildbot failure ⚠️⚠️⚠️

Hi! The buildbot AMD64 Debian root 3.x has failed when building commit f3ba0a7.

What do you need to do:

  1. Don't panic.
  2. Check the buildbot page in the devguide if you don't know what the buildbots are or how they work.
  3. Go to the page of the buildbot that failed (https://buildbot.python.org/all/#builders/345/builds/5704) and take a look at the build logs.
  4. Check if the failure is related to this commit (f3ba0a7) or if it is a false positive.
  5. If the failure is related to this commit, please, reflect that on the issue and make a new Pull Request with a fix.

You can take a look at the buildbot page here:

https://buildbot.python.org/all/#builders/345/builds/5704

Failed tests:

  • test.test_multiprocessing_forkserver.test_processes

Summary of the results of the build (if available):

==

Click to see traceback logs 
remote: Enumerating objects: 40, done.        
remote: Counting objects:   2% (1/38)        
remote: Counting objects:   5% (2/38)        
remote: Counting objects:   7% (3/38)        
remote: Counting objects:  10% (4/38)        
remote: Counting objects:  13% (5/38)        
remote: Counting objects:  15% (6/38)        
remote: Counting objects:  18% (7/38)        
remote: Counting objects:  21% (8/38)        
remote: Counting objects:  23% (9/38)        
remote: Counting objects:  26% (10/38)        
remote: Counting objects:  28% (11/38)        
remote: Counting objects:  31% (12/38)        
remote: Counting objects:  34% (13/38)        
remote: Counting objects:  36% (14/38)        
remote: Counting objects:  39% (15/38)        
remote: Counting objects:  42% (16/38)        
remote: Counting objects:  44% (17/38)        
remote: Counting objects:  47% (18/38)        
remote: Counting objects:  50% (19/38)        
remote: Counting objects:  52% (20/38)        
remote: Counting objects:  55% (21/38)        
remote: Counting objects:  57% (22/38)        
remote: Counting objects:  60% (23/38)        
remote: Counting objects:  63% (24/38)        
remote: Counting objects:  65% (25/38)        
remote: Counting objects:  68% (26/38)        
remote: Counting objects:  71% (27/38)        
remote: Counting objects:  73% (28/38)        
remote: Counting objects:  76% (29/38)        
remote: Counting objects:  78% (30/38)        
remote: Counting objects:  81% (31/38)        
remote: Counting objects:  84% (32/38)        
remote: Counting objects:  86% (33/38)        
remote: Counting objects:  89% (34/38)        
remote: Counting objects:  92% (35/38)        
remote: Counting objects:  94% (36/38)        
remote: Counting objects:  97% (37/38)        
remote: Counting objects: 100% (38/38)        
remote: Counting objects: 100% (38/38), done.        
remote: Compressing objects:   9% (1/11)        
remote: Compressing objects:  18% (2/11)        
remote: Compressing objects:  27% (3/11)        
remote: Compressing objects:  36% (4/11)        
remote: Compressing objects:  45% (5/11)        
remote: Compressing objects:  54% (6/11)        
remote: Compressing objects:  63% (7/11)        
remote: Compressing objects:  72% (8/11)        
remote: Compressing objects:  81% (9/11)        
remote: Compressing objects:  90% (10/11)        
remote: Compressing objects: 100% (11/11)        
remote: Compressing objects: 100% (11/11), done.        
remote: Total 40 (delta 27), reused 28 (delta 27), pack-reused 2        
From https://github.com/python/cpython
 * branch                  main       -> FETCH_HEAD
Note: switching to 'f3ba0a74cd50274acdcd592d4ce8395b92492b7c'.

You are in 'detached HEAD' state. You can look around, make experimental
changes and commit them, and you can discard any commits you make in this
state without impacting any branches by switching back to a branch.

If you want to create a new branch to retain commits you create, you may
do so (now or later) by using -c with the switch command. Example:

  git switch -c <new-branch-name>

Or undo this operation with:

  git switch -

Turn off this advice by setting config variable advice.detachedHead to false

HEAD is now at f3ba0a74cd gh-108416: Mark slow test methods with @requires_resource('cpu') (GH-108421)
Switched to and reset branch 'main'

configure: WARNING: pkg-config is missing. Some dependencies may not be detected correctly.

Timeout (0:15:00)!
Thread 0x00007fd16ce11280 (most recent call first):
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/resource_tracker.py", line 83 in ensure_running
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/resource_tracker.py", line 162 in _send
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/resource_tracker.py", line 159 in unregister
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/synchronize.py", line 88 in _cleanup
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/util.py", line 224 in __call__
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/resource_tracker.py", line 142 in _check_alive
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/resource_tracker.py", line 86 in ensure_running
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/resource_tracker.py", line 162 in _send
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/resource_tracker.py", line 155 in register
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/synchronize.py", line 80 in __init__
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/synchronize.py", line 169 in __init__
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/context.py", line 68 in Lock
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/queues.py", line 343 in __init__
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/context.py", line 113 in SimpleQueue
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/pool.py", line 196 in __init__
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/context.py", line 119 in Pool
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/_test_multiprocessing.py", line 2758 in test_wrapped_exception
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/unittest/case.py", line 589 in _callTestMethod
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/unittest/case.py", line 634 in run
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/unittest/case.py", line 690 in __call__
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/unittest/suite.py", line 122 in run
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/unittest/suite.py", line 84 in __call__
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/unittest/suite.py", line 122 in run
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/unittest/suite.py", line 84 in __call__
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/unittest/suite.py", line 122 in run
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/unittest/suite.py", line 84 in __call__
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/unittest/runner.py", line 240 in run
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/support/__init__.py", line 1114 in _run_suite
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/support/__init__.py", line 1240 in run_unittest
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/libregrtest/runtest.py", line 296 in _test_module
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/libregrtest/runtest.py", line 332 in _runtest_inner2
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/libregrtest/runtest.py", line 375 in _runtest_inner
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/libregrtest/runtest.py", line 250 in _runtest
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/libregrtest/runtest.py", line 280 in runtest
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/libregrtest/main.py", line 362 in rerun_failed_tests
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/libregrtest/main.py", line 807 in _main
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/libregrtest/main.py", line 762 in main
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/libregrtest/main.py", line 826 in main
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/test/__main__.py", line 2 in <module>
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/runpy.py", line 88 in _run_code
  File "/root/buildarea/3.x.angelico-debian-amd64/build/Lib/runpy.py", line 198 in _run_module_as_main
/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/resource_tracker.py:224: UserWarning: resource_tracker: There appear to be 22 leaked semaphore objects to clean up at shutdown: {'/mp-law0hpw0', '/mp-o2b57gy1', '/mp-mxafxfqi', '/mp-z0o8hy1m', '/mp-mohxmw1v', '/mp-4f6x9yf8', '/mp-hb75z1wb', '/mp-xmvxvjpe', '/mp-bug6pzq8', '/mp-g1d5llg2', '/mp-mkfuqet2', '/mp-ii9l5tpt', '/mp-60l6r3f7', '/mp-iaeph47w', '/mp-23zont_j', '/mp-1y_ab24r', '/mp-eiudwvd8', '/mp-widfpy27', '/mp-iqhksnf_', '/mp-l992ab86', '/mp-9549ibtv', '/mp-rfhpfq50'}
  warnings.warn(
/root/buildarea/3.x.angelico-debian-amd64/build/Lib/multiprocessing/resource_tracker.py:238: UserWarning: resource_tracker: '/mp-g1d5llg2': [Errno 2] No such file or directory
  warnings.warn('resource_tracker: %r: %s' % (name, e))
make: *** [Makefile:2027: buildbottest] Error 1

Cannot open file '/root/buildarea/3.x.angelico-debian-amd64/build/test-results.xml' for upload

@serhiy-storchaka

serhiy-storchaka commented Sep 2, 2023

Copy link
Copy Markdown
Member Author

Thank you for your review @gpshead. Could you look also at #108480?

Yhg1s pushed a commit that referenced this pull request Sep 2, 2023
@miss-islington @serhiy-storchaka
[3.12] gh-108416: Mark slow test methods with @requires_resource('cpu… …
dcaacd9 
…') (GH-108421) (#108798)

gh-108416: Mark slow test methods with @requires_resource('cpu') (GH-108421)

Only mark tests which spend significant system or user time,
by itself or in subprocesses.
(cherry picked from commit f3ba0a7)

Co-authored-by: Serhiy Storchaka <storchaka@gmail.com>
serhiy-storchaka added a commit that referenced this pull request Sep 3, 2023
@serhiy-storchaka
[3.11] gh-108416: Mark slow test methods with @requires_resource('cpu… …
76f5219 
…') (GH-108421) (GH-108799)

Only mark tests which spend significant system or user time,
by itself or in subprocesses.
(cherry picked from commit f3ba0a7)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@gpshead gpshead gpshead approved these changes

@vstinner vstinner Awaiting requested review from vstinner

@ambv ambv Awaiting requested review from ambv

Assignees

No one assigned

Labels

skip news tests Tests in the Lib/test dir

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

6 participants

@serhiy-storchaka @vstinner @ambv @gpshead @miss-islington @bedevere-bot