[buildbot] test_asyncio hangs (killed after 3 hours) on Refleak buildbots

[vstinner]

BPO	44112
Nosy	@vstinner, @asvetlov, @cjerdonek, @1st1, @pablogsal, @erlend-aasland, @shreyanavigyan
Superseder	bpo-38323: asyncio: MultiLoopWatcher has a race condition (test_asyncio: test_close_kill_running() hangs on AMD64 RHEL7 Refleaks 3.x)
Files	wsl_log.txt

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2021-06-04.22:52:58.389>
created_at = <Date 2021-05-12.09:40:34.127>
labels = ['3.11', 'tests', '3.10', 'expert-asyncio']
title = '[buildbot] test_asyncio hangs (killed after 3 hours) on Refleak buildbots'
updated_at = <Date 2021-06-09.21:25:27.860>
user = 'https://github.com/vstinner'

bugs.python.org fields:

activity = <Date 2021-06-09.21:25:27.860>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2021-06-04.22:52:58.389>
closer = 'vstinner'
components = ['Tests', 'asyncio']
creation = <Date 2021-05-12.09:40:34.127>
creator = 'vstinner'
dependencies = []
files = ['50092']
hgrepos = []
issue_num = 44112
keywords = []
message_count = 19.0
messages = ['393491', '393492', '393493', '394923', '395035', '395036', '395037', '395041', '395042', '395048', '395068', '395070', '395091', '395093', '395094', '395095', '395101', '395135', '395480']
nosy_count = 7.0
nosy_names = ['vstinner', 'asvetlov', 'chris.jerdonek', 'yselivanov', 'pablogsal', 'erlendaasland', 'shreyanavigyan']
pr_nums = []
priority = 'normal'
resolution = 'duplicate'
stage = 'resolved'
status = 'closed'
superseder = '38323'
type = None
url = 'https://bugs.python.org/issue44112'
versions = ['Python 3.10', 'Python 3.11']

[vstinner]

Buildbot kills the "test" step because it takes longer than 3 hours, whereas Python regrtest gets a timeout of 3 hour 15 min.

Refleak buildbots should get a longer timeout for the "test" step.

PPC64LE Fedora Rawhide Refleaks 3.10:
https://buildbot.python.org/all/#/builders/603/builds/7

./python ./Tools/scripts/run_tests.py -j 1 -u all -W --slowest --fail-env-changed --timeout=11700 -R 3:3 -u-cpu -j10
WARNING: Disable --verbose3 because it's incompatible with --huntrleaks: see http://bugs.python.org/issue27103
== CPython 3.10.0b1+ (heads/3.10:9a0e65c8e0, May 10 2021, 00:01:01) [GCC 11.1.1 20210428 (Red Hat 11.1.1-1)]
== Linux-5.7.0-0.rc0.git2.1.fc33.ppc64le-ppc64le-with-glibc2.33.9000 little-endian
== cwd: /home/buildbot/buildarea/3.10.cstratak-fedora-rawhide-ppc64le.refleak/build/build/test_python_1529753æ
== CPU count: 8
== encodings: locale=UTF-8, FS=utf-8
Using random seed 1661030
0:00:00 load avg: 3.25 Run tests in parallel using 10 child processes (timeout: 3 hour 15 min, worker timeout: 3 hour 20 min)
0:00:00 load avg: 3.25 [ 1/427] test_tix skipped (resource denied)
(...)
2:58:49 load avg: 0.00 running: test_asyncio (2 hour 58 min)
2:59:19 load avg: 0.00 running: test_asyncio (2 hour 58 min)
2:59:49 load avg: 0.00 running: test_asyncio (2 hour 59 min)

command timed out: 10800 seconds elapsed running [b'make', b'buildbottest', b'TESTOPTS=-R 3:3 -u-cpu -j10 ${BUILDBOT_TESTOPTS}', b'TESTPYTHONOPTS=', b'TESTTIMEOUT=11700'], attempting to kill

[vstinner]

It seems to be a real bug in test_asyncio, since in other builds on the same buildbot worker, test_asyncio takes less than 30 minutes:

• build 8: test_asyncio: 27 min 48 sec
• build 5: test_asyncio: 21 min 44 sec
• build 2: test_asyncio: 20 min 42 sec

[vstinner]

I bet that the hang is a duplicate of the old bpo-38323 "asyncio: MultiLoopWatcher has a race condition (test_asyncio: test_close_kill_running() hangs on AMD64 RHEL7 Refleaks 3.x)" that I reported 2 years ago and is not fixed yet.

[vstinner]

Refleak buildbots should get a longer timeout for the "test" step.

I changed buildbot Test step timeout from 3 hours to 4 hours:

• python/buildmaster-config@9e0c812
• Change Test timeout to 4 hours buildmaster-config#252

[shreyanavigyan]

Victor, this issue is reproducible on Linux. I reproduced it on my WSL. And I've identified the issue is in test_close_kill_running. The patch for resolving the crash in bpo-38323 can be the cause of the newly introduced hang. test_close_kill_running is running and passing and again it is running all over again infinitely. And extending the buildbot timer may not help since it seems it's running infinitely. Even if we look at the buildbot log there is no sign of crash but suddenly buildbot says "timeout!".