test_logging: test_post_fork_child_no_deadlock() failed with timeout on AMD64 Arch Linux Asan Debug 3.10

[vstinner]

BPO	46711
Nosy	@vstinner, @sobolevn
PRs	bpo-46711: increase timeout for test_logging::test_post_fork_child_no_deadlock #31274

^{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 = None
created_at = <Date 2022-02-10.13:43:47.841>
labels = ['tests', '3.10']
title = 'test_logging: test_post_fork_child_no_deadlock() failed with timeout on AMD64 Arch Linux Asan Debug 3.10'
updated_at = <Date 2022-02-11.09:48:27.341>
user = 'https://github.com/vstinner'

bugs.python.org fields:

activity = <Date 2022-02-11.09:48:27.341>
actor = 'sobolevn'
assignee = 'none'
closed = False
closed_date = None
closer = None
components = ['Tests']
creation = <Date 2022-02-10.13:43:47.841>
creator = 'vstinner'
dependencies = []
files = []
hgrepos = []
issue_num = 46711
keywords = ['patch']
message_count = 1.0
messages = ['413000']
nosy_count = 2.0
nosy_names = ['vstinner', 'sobolevn']
pr_nums = ['31274']
priority = 'normal'
resolution = None
stage = 'patch review'
status = 'open'
superseder = None
type = None
url = 'https://bugs.python.org/issue46711'
versions = ['Python 3.10']

• PR: gh-90867: test.support.wait_process() uses LONG_TIMEOUT #99071

• PR: [3.11] gh-90867: test.support.wait_process() uses LONG_TIMEOUT (#99071) #99098

• PR: [3.10] [3.11] gh-90867: test.support.wait_process() uses LONG_TIMEOUT (GH-99071) (GH-99098) #99099

[vstinner]

The test calls support.wait_process() which uses SHORT_TIMEOUT.

wait_process() should use LONG_TIMEOUT, or the ASAN buildbot should increase its timeout (regrtest --timeout parameter).

IMO using LONG_TIMEOUT is fine: it's ok if the test takes 2 minutes instead of 1 second, it's only important that it completes :-) The test should not measure the *performance* of the code, only if the code is valid. When tests are run in parallel, the buildbot system load can be very high. In this case, the system load was 1.70:

0:35:49 load avg: 1.70 [255/421/1] test_logging failed (1 failure) (1 min 18 sec)

AMD64 Arch Linux Asan Debug 3.10:
https://buildbot.python.org/all/#/builders/621/builds/466

======================================================================
FAIL: test_post_fork_child_no_deadlock (test.test_logging.HandlerTest)
Ensure child logging locks are not held; bpo-6721 & bpo-36533.
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/buildbot/buildarea/3.10.pablogsal-arch-x86_64.asan_debug/build/Lib/test/test_logging.py", line 750, in test_post_fork_child_no_deadlock
    support.wait_process(pid, exitcode=0)
  File "/buildbot/buildarea/3.10.pablogsal-arch-x86_64.asan_debug/build/Lib/test/support/__init__.py", line 1971, in wait_process
    raise AssertionError(f"process {pid} is still running "
AssertionError: process 406366 is still running after 52.5 seconds

[hauntsaninja]

Thanks, looks like we've completed this

[vstinner]

Yep, I fixed it with commit f09da28, backported to 3.11 and 3.10.