test_tools: test_freeze_simple_script() times out after 15 min: --with-lto --enable-optimizations (s390x LTO buildbots)

Reproduction:

make clean && ./configure --with-lto --enable-optimizations && make
./python.exe -E ./Tools/scripts/run_tests.py -j 1 -u all -W --slowest --fail-env-changed --timeout=900 -j2 --junit-xml test-results.xml -j6 -v test_tools -m test.test_tools.test_freeze.TestFreeze.test_freeze_simple_script

Env:

Fedora in the test suite: https://buildbot.python.org/all/#/builders/545/builds/3524
Macos, locally

Traceback:

» ./python.exe -E  ./Tools/scripts/run_tests.py -j 1 -u all -W --slowest --fail-env-changed --timeout=900 -j2 --junit-xml test-results.xml -j6 -v test_tools
/Users/sobolev/Desktop/cpython/python.exe -u -W default -bb -E -E -m test -r -w -j 1 -u all -W --slowest --fail-env-changed --timeout=900 -j2 --junit-xml test-results.xml -j6 -v test_tools
== CPython 3.12.0a6+ (heads/main:1fd603fad2, Mar 27 2023, 09:38:01) [Clang 11.0.0 (clang-1100.0.33.16)]
== macOS-10.14.6-x86_64-i386-64bit little-endian
== Python build: release LTO+PGO
== cwd: /Users/sobolev/Desktop/cpython/build/test_python_89351æ
== CPU count: 4
== encodings: locale=UTF-8, FS=utf-8
Using random seed 5597523
0:00:00 load avg: 1.77 Run tests in parallel using 6 child processes (timeout: 15 min, worker timeout: 20 min)
0:00:30 load avg: 2.74 running: test_tools (30.0 sec)
0:01:00 load avg: 3.09 running: test_tools (1 min)
0:01:30 load avg: 2.95 running: test_tools (1 min 30 sec)
0:02:00 load avg: 3.15 running: test_tools (2 min)
0:02:30 load avg: 3.15 running: test_tools (2 min 30 sec)
0:03:00 load avg: 3.19 running: test_tools (3 min)
0:03:30 load avg: 4.23 running: test_tools (3 min 30 sec)
0:04:00 load avg: 4.75 running: test_tools (4 min)
0:04:30 load avg: 4.91 running: test_tools (4 min 30 sec)
0:05:00 load avg: 3.85 running: test_tools (5 min)
0:05:30 load avg: 4.70 running: test_tools (5 min 30 sec)
0:06:00 load avg: 4.65 running: test_tools (6 min)
0:06:30 load avg: 3.73 running: test_tools (6 min 30 sec)
0:07:00 load avg: 3.65 running: test_tools (7 min)
0:07:30 load avg: 3.33 running: test_tools (7 min 30 sec)
0:08:00 load avg: 3.28 running: test_tools (8 min)
0:08:30 load avg: 3.01 running: test_tools (8 min 30 sec)
0:09:00 load avg: 3.82 running: test_tools (9 min)
0:09:30 load avg: 4.18 running: test_tools (9 min 30 sec)
0:10:00 load avg: 3.76 running: test_tools (10 min)
0:10:30 load avg: 3.58 running: test_tools (10 min 30 sec)
0:11:00 load avg: 4.73 running: test_tools (11 min)
0:11:30 load avg: 4.45 running: test_tools (11 min 30 sec)
0:12:00 load avg: 4.22 running: test_tools (12 min)
0:12:30 load avg: 3.22 running: test_tools (12 min 30 sec)
0:13:00 load avg: 2.67 running: test_tools (13 min)
0:13:30 load avg: 4.42 running: test_tools (13 min 30 sec)
0:14:00 load avg: 4.41 running: test_tools (14 min)
0:14:30 load avg: 3.99 running: test_tools (14 min 30 sec)
0:15:00 load avg: 5.46 running: test_tools (15 min)
0:15:02 load avg: 5.46 [1/1/1] test_tools crashed (Exit code 1)
Timeout (0:15:00)!
Thread 0x0000000113c4d5c0 (most recent call first):
  File "/Users/sobolev/Desktop/cpython/Lib/selectors.py", line 415 in select
  File "/Users/sobolev/Desktop/cpython/Lib/subprocess.py", line 2075 in _communicate
  File "/Users/sobolev/Desktop/cpython/Lib/subprocess.py", line 1207 in communicate
  File "/Users/sobolev/Desktop/cpython/Lib/subprocess.py", line 550 in run
  File "/Users/sobolev/Desktop/cpython/Tools/freeze/test/freeze.py", line 25 in _run_quiet
  File "/Users/sobolev/Desktop/cpython/Tools/freeze/test/freeze.py", line 180 in prepare
  File "/Users/sobolev/Desktop/cpython/Lib/test/test_tools/test_freeze.py", line 27 in test_freeze_simple_script
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/case.py", line 579 in _callTestMethod
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/case.py", line 623 in run
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/case.py", line 678 in __call__
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 122 in run
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 84 in __call__
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 122 in run
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 84 in __call__
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 122 in run
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 84 in __call__
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 122 in run
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 84 in __call__
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 122 in run
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 84 in __call__
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/runner.py", line 208 in run
  File "/Users/sobolev/Desktop/cpython/Lib/test/support/__init__.py", line 1106 in _run_suite
  File "/Users/sobolev/Desktop/cpython/Lib/test/support/__init__.py", line 1232 in run_unittest
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/runtest.py", line 281 in _test_module
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/runtest.py", line 317 in _runtest_inner2
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/runtest.py", line 360 in _runtest_inner
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/runtest.py", line 219 in _runtest
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/runtest.py", line 265 in runtest
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/runtest_mp.py", line 98 in run_tests_worker
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/main.py", line 732 in _main
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/main.py", line 711 in main
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/main.py", line 775 in main
  File "/Users/sobolev/Desktop/cpython/Lib/test/regrtest.py", line 43 in _main
  File "/Users/sobolev/Desktop/cpython/Lib/test/regrtest.py", line 47 in <module>
  File "<frozen runpy>", line 88 in _run_code
  File "<frozen runpy>", line 198 in _run_module_as_main

== Tests result: FAILURE ==

10 slowest tests:

1 test failed:
    test_tools
0:15:02 load avg: 5.46
0:15:02 load avg: 5.46 Re-running failed tests in verbose mode
0:15:02 load avg: 5.46 Re-running test_tools in verbose mode
test_freeze_simple_script (test.test_tools.test_freeze.TestFreeze.test_freeze_simple_script) ... Timeout (0:15:00)!
Thread 0x000000010b8a55c0 (most recent call first):
  File "/Users/sobolev/Desktop/cpython/Lib/selectors.py", line 415 in select
  File "/Users/sobolev/Desktop/cpython/Lib/subprocess.py", line 2075 in _communicate
  File "/Users/sobolev/Desktop/cpython/Lib/subprocess.py", line 1207 in communicate
  File "/Users/sobolev/Desktop/cpython/Lib/subprocess.py", line 550 in run
  File "/Users/sobolev/Desktop/cpython/Tools/freeze/test/freeze.py", line 25 in _run_quiet
  File "/Users/sobolev/Desktop/cpython/Tools/freeze/test/freeze.py", line 180 in prepare
  File "/Users/sobolev/Desktop/cpython/Lib/test/test_tools/test_freeze.py", line 27 in test_freeze_simple_script
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/case.py", line 579 in _callTestMethod
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/case.py", line 623 in run
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/case.py", line 678 in __call__
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 122 in run
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 84 in __call__
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 122 in run
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 84 in __call__
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 122 in run
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 84 in __call__
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 122 in run
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 84 in __call__
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 122 in run
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/suite.py", line 84 in __call__
  File "/Users/sobolev/Desktop/cpython/Lib/unittest/runner.py", line 208 in run
  File "/Users/sobolev/Desktop/cpython/Lib/test/support/__init__.py", line 1106 in _run_suite
  File "/Users/sobolev/Desktop/cpython/Lib/test/support/__init__.py", line 1232 in run_unittest
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/runtest.py", line 281 in _test_module
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/runtest.py", line 317 in _runtest_inner2
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/runtest.py", line 360 in _runtest_inner
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/runtest.py", line 235 in _runtest
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/runtest.py", line 265 in runtest
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/main.py", line 353 in rerun_failed_tests
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/main.py", line 756 in _main
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/main.py", line 711 in main
  File "/Users/sobolev/Desktop/cpython/Lib/test/libregrtest/main.py", line 775 in main
  File "/Users/sobolev/Desktop/cpython/Lib/test/__main__.py", line 2 in <module>
  File "<frozen runpy>", line 88 in _run_code
  File "<frozen runpy>", line 198 in _run_module_as_main

Looks like timeout is killing this test. I tried to increase it, it helped:

» ./python.exe -E  ./Tools/scripts/run_tests.py -j 1 -u all -W --slowest --fail-env-changed --timeout=1800 -j2 --junit-xml test-results.xml -j6 -v test_tools -m test.test_tools.test_freeze.TestFreeze.test_freeze_simple_script
/Users/sobolev/Desktop/cpython/python.exe -u -W default -bb -E -E -m test -r -w -j 1 -u all -W --slowest --fail-env-changed --timeout=1800 -j2 --junit-xml test-results.xml -j6 -v test_tools -m test.test_tools.test_freeze.TestFreeze.test_freeze_simple_script
== CPython 3.12.0a6+ (heads/main:1fd603fad2, Mar 27 2023, 09:38:01) [Clang 11.0.0 (clang-1100.0.33.16)]
== macOS-10.14.6-x86_64-i386-64bit little-endian
== Python build: release LTO+PGO
== cwd: /Users/sobolev/Desktop/cpython/build/test_python_39615æ
== CPU count: 4
== encodings: locale=UTF-8, FS=utf-8
Using random seed 1597906
0:00:00 load avg: 2.79 Run tests in parallel using 6 child processes (timeout: 30 min, worker timeout: 35 min)
0:01:00 load avg: 3.25 running: test_tools (1 min)
0:01:30 load avg: 3.33 running: test_tools (1 min 30 sec)
0:02:00 load avg: 3.41 running: test_tools (2 min)
0:02:30 load avg: 3.59 running: test_tools (2 min 30 sec)
0:03:00 load avg: 3.33 running: test_tools (3 min)
0:03:30 load avg: 3.43 running: test_tools (3 min 30 sec)
0:04:00 load avg: 3.08 running: test_tools (4 min)
0:04:30 load avg: 2.80 running: test_tools (4 min 30 sec)
0:05:00 load avg: 5.62 running: test_tools (5 min)
0:05:30 load avg: 5.53 running: test_tools (5 min 30 sec)
0:06:00 load avg: 4.24 running: test_tools (6 min)
0:06:30 load avg: 3.55 running: test_tools (6 min 30 sec)
0:07:00 load avg: 4.57 running: test_tools (7 min)
0:07:30 load avg: 4.09 running: test_tools (7 min 30 sec)
0:08:00 load avg: 3.80 running: test_tools (8 min)
0:08:30 load avg: 4.14 running: test_tools (8 min 30 sec)
0:09:00 load avg: 7.55 running: test_tools (9 min)
0:09:30 load avg: 7.24 running: test_tools (9 min 30 sec)
0:10:00 load avg: 5.84 running: test_tools (10 min)
0:10:30 load avg: 4.38 running: test_tools (10 min 30 sec)
0:11:00 load avg: 4.52 running: test_tools (11 min)
0:11:30 load avg: 4.17 running: test_tools (11 min 30 sec)
0:12:00 load avg: 4.23 running: test_tools (12 min)
0:12:30 load avg: 4.35 running: test_tools (12 min 30 sec)
0:13:00 load avg: 4.11 running: test_tools (13 min)
0:13:30 load avg: 3.37 running: test_tools (13 min 30 sec)
0:14:00 load avg: 3.12 running: test_tools (14 min)
0:14:30 load avg: 3.73 running: test_tools (14 min 30 sec)
0:15:00 load avg: 3.18 running: test_tools (15 min)
0:15:30 load avg: 2.94 running: test_tools (15 min 30 sec)
0:16:00 load avg: 4.23 running: test_tools (16 min)
0:16:30 load avg: 4.90 running: test_tools (16 min 30 sec)
0:17:00 load avg: 4.58 running: test_tools (17 min)
0:17:30 load avg: 4.44 running: test_tools (17 min 30 sec)
0:18:00 load avg: 5.53 running: test_tools (18 min)
0:18:30 load avg: 4.19 running: test_tools (18 min 30 sec)
0:19:00 load avg: 3.39 running: test_tools (19 min)
0:19:30 load avg: 2.78 running: test_tools (19 min 30 sec)
0:19:55 load avg: 2.72 [1/1] test_tools passed (19 min 55 sec)

== Tests result: SUCCESS ==

1 test OK.

10 slowest tests:
- test_tools: 19 min 55 sec

Total duration: 19 min 55 sec
Tests result: SUCCESS

So, should be increase this timeout in CI? Or should we try optimizing this test somehow?

Linked PRs

@kumaraditya303

CC @kumaraditya303 as freeze expert

@sobolevn

Let's first increase the timeout to unblock the CI and then think about improving the test.

@sobolevn Can you send a PR for it?

@ericsnowcurrently

One moment, I think I found something interesting. Right now it has this decorator:

@support.skip_if_buildbot('not all buildbots have enough space')
class TestFreeze(unittest.TestCase):

    def test_freeze_simple_script(self): ...

It was introduced in #29222 by @ericsnowcurrently

I think that it should not be tested in buildbots at all!
Let's take some recent commit (361a3ea) and examine it:

s390x Fedora LTO + PGO 3.x is failing: https://buildbot.python.org/all/#/builders/545/builds/3541 because of this test
All others do pass saying 0:03:50 load avg: 0.65 [163/433] test_tools passed

But, since we only skip a test case, not all file - it won't be reported anyway.

So, my guess is: maybe s390x Fedora LTO + PGO 3.x is not configured properly?
It looks like skip_if_buildbot does not work for this exact worker.

I will try to run this test explicitly with module-level skip and I hope I will be able to find the problem.

pythongh-103053: Skip the whole `test_freeze` module in tests on buil…

pythongh-103053: Skip `test_tools` on `s390x` and with PGO enabled

@erlend-aasland

First failure that I was able to find: c3a1783

CC @erlend-aasland

@sobolevn

@sobolevn, does gh-103213 fix this issue?

I would be able to check next week, I have a conference to make right now :(

No worries; enjoy the conference :)

I don’t see much difference (Python 3.11.3 on openSUSE/Tumbleweed):

[ 2235s] ======================================================================
[ 2235s] ERROR: test_freeze_simple_script (test.test_tools.test_freeze.TestFreeze.test_freeze_simple_script)
[ 2235s] ----------------------------------------------------------------------
[ 2235s] Traceback (most recent call last):
[ 2235s]   File "/home/abuild/rpmbuild/BUILD/Python-3.11.3/Lib/test/test_tools/test_freeze.py", line 27, in test_freeze_simple_script
[ 2235s]     outdir, scriptfile, python = helper.prepare(script, outdir)
[ 2235s]                                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
[ 2235s]   File "/home/abuild/rpmbuild/BUILD/Python-3.11.3/Tools/freeze/test/freeze.py", line 183, in prepare
[ 2235s]     _run_quiet([MAKE, '-C', builddir, 'install'])
[ 2235s]   File "/home/abuild/rpmbuild/BUILD/Python-3.11.3/Tools/freeze/test/freeze.py", line 25, in _run_quiet
[ 2235s]     return subprocess.run(
[ 2235s]            ^^^^^^^^^^^^^^^
[ 2235s]   File "/home/abuild/rpmbuild/BUILD/Python-3.11.3/Lib/subprocess.py", line 571, in run
[ 2235s]     raise CalledProcessError(retcode, process.args,
[ 2235s] subprocess.CalledProcessError: Command '['/usr/bin/make', '-C', '/tmp/tmpwh6sh465/python-build', 'install']' returned non-zero exit status 2.
[ 2235s] 
[ 2235s] ----------------------------------------------------------------------

Complete build log

Isn’t the solution to extend

cpython/Lib/test/support/__init__.py

Line 396 in 5b05b01

isbuildbot = getpass.getuser().lower() == 'buildbot'

to cover other build environments? For me (at openSUSE with our build environment) it was enough just to add this patch:

--- a/Lib/test/support/__init__.py
+++ b/Lib/test/support/__init__.py
@@ -388,7 +388,7 @@ def skip_if_buildbot(reason=None):
     if not reason:
         reason = 'not suitable for buildbots'
     try:
-        isbuildbot = getpass.getuser().lower() == 'buildbot'
+        isbuildbot = getpass.getuser().lower() in ['buildbot', 'abuild']
     except (KeyError, EnvironmentError) as err:
         warnings.warn(f'getpass.getuser() failed {err}.', RuntimeWarning)
         isbuildbot = False

If those tests are problematic in the buildbot here, why to expect they won’t fail in other limited build environments, so extending the list of those seems legitimate.

Some recent logs suggest that the test is running out of disk space on /tmp/. Is it trying to compile all of CPython there? I don't think /tmp/ is a good place for big files, it might be a ramdisk.

pythongh-103053: Fix make check-clean-src: check "python" program (py…

gh-103053: Fix test_tools.test_freeze on FreeBSD (#110451)

pythongh-103053: Fix test_tools.test_freeze on FreeBSD (pythonGH-110451)

pythongh-103053: Run tools test_freeze on buildbot

[3.11] gh-103053: Fix make check-clean-src: check "python" program (G…

pythongh-103053: Run tools test_freeze on buildbot

[3.12] gh-103053: Fix make check-clean-src: check "python" program (G…

[3.12] gh-103053: Fix test_tools.test_freeze on FreeBSD (GH-110451) (#…

[3.11] gh-103053: Fix test_tools.test_freeze on FreeBSD (GH-110451) (#…

pythongh-103053: Skip test_freeze_simple_script() on PGO build (pytho…

pythongh-103053: Fix make check-clean-src: check "python" program (py…

pythongh-103053: Fix test_tools.test_freeze on FreeBSD (python#110451)

Navigation Menu

Repository navigation

test_tools: test_freeze_simple_script() times out after 15 min: --with-lto --enable-optimizations (s390x LTO buildbots) #103053

Linked PRs

30 remaining items

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

test_tools: test_freeze_simple_script() times out after 15 min: --with-lto --enable-optimizations (s390x LTO buildbots) #103053

Description

Linked PRs

Activity

sobolevn commented on Mar 28, 2023

kumaraditya303 commented on Apr 1, 2023

sobolevn commented on Apr 1, 2023

sobolevn commented on Apr 7, 2023

erlend-aasland commented on Apr 28, 2023

sobolevn commented on Apr 28, 2023

erlend-aasland commented on Apr 28, 2023

mcepl commented on May 2, 2023

mcepl commented on May 3, 2023

encukou commented on May 15, 2023

30 remaining items

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions