Message355157
I'm able to reproduce the issue locally using the command:
./python -m test test_asyncio --match=test.test_asyncio.test_subprocess.SubprocessMultiLoopWatcherTests.test_close_kill_running -v -F -j20 --timeout=30.0
Example:
...
0:00:47 load avg: 14.35 [287] test_asyncio passed -- running: test_asyncio (31.1 sec)
0:00:47 load avg: 14.35 [288] test_asyncio passed -- running: test_asyncio (31.3 sec)
0:00:47 load avg: 14.35 [289/1] test_asyncio crashed (Exit code 1)
Timeout (0:00:30)!
Thread 0x00007f3bbd098740 (most recent call first):
File "/home/vstinner/python/master/Lib/selectors.py", line 468 in select
File "/home/vstinner/python/master/Lib/asyncio/base_events.py", line 1837 in _run_once
File "/home/vstinner/python/master/Lib/asyncio/base_events.py", line 589 in run_forever
File "/home/vstinner/python/master/Lib/asyncio/base_events.py", line 621 in run_until_complete
File "/home/vstinner/python/master/Lib/test/test_asyncio/test_subprocess.py", line 484 in test_close_kill_running
...
I added some debug traces.
Logs when it works:
---
0:01:39 load avg: 21.21 [512] test_asyncio passed -- running: test_asyncio (31.0 sec)
test_close_kill_running (test.test_asyncio.test_subprocess.SubprocessMultiLoopWatcherTests) ... MultiLoopChildWatcher: attach_loop <_UnixSelectorEventLoop running=False closed=False debug=False>
MultiLoopChildWatcher: SIGCHLD signal registered
MultiLoopChildWatcher: attach_loop None
MultiLoopChildWatcher: attach_loop None
MultiLoopChildWatcher: SIGCHLD signal registered
ok
----------------------------------------------------------------------
Ran 1 test in 0.054s
OK
MultiLoopChildWatcher: _do_waitpid 27887
MultiLoopChildWatcher: _do_waitpid (0, 0)
kill 27887 9
MultiLoopChildWatcher: _sig_chld
MultiLoopChildWatcher: _do_waitpid_all
MultiLoopChildWatcher: _do_waitpid 27887
MultiLoopChildWatcher: _do_waitpid (27887, 9)
MultiLoopChildWatcher: _do_waitpid: call (<bound method _UnixSelectorEventLoop._child_watcher_callback of <_UnixSelectorEventLoop running=True closed=False debug=False>>, <_UnixSelectorEventLoop running=True closed=False debug=False>)
---
Logs when it hangs:
---
0:01:40 load avg: 21.21 [514/1] test_asyncio crashed (Exit code 1)
test_close_kill_running (test.test_asyncio.test_subprocess.SubprocessMultiLoopWatcherTests) ... MultiLoopChildWatcher: attach_loop <_UnixSelectorEventLoop running=False closed=False debug=False>
MultiLoopChildWatcher: SIGCHLD signal registered
MultiLoopChildWatcher: _do_waitpid 26010
MultiLoopChildWatcher: _do_waitpid (0, 0)
kill 26010 9
Timeout (0:00:30)!
Thread 0x00007f4b73f35740 (most recent call first):
File "/home/vstinner/python/master/Lib/selectors.py", line 468 in select
File "/home/vstinner/python/master/Lib/asyncio/base_events.py", line 1837 in _run_once
File "/home/vstinner/python/master/Lib/asyncio/base_events.py", line 589 in run_forever
File "/home/vstinner/python/master/Lib/asyncio/base_events.py", line 621 in run_until_complete
File "/home/vstinner/python/master/Lib/test/test_asyncio/test_subprocess.py", line 484 in test_close_kill_running
...
---
It seems like sometimes, MultiLoopChildWatcher._sig_chld() is not called. |
|
Date |
User |
Action |
Args |
2019-10-22 21:38:49 | vstinner | set | recipients:
+ vstinner, asvetlov, yselivanov |
2019-10-22 21:38:49 | vstinner | set | messageid: <1571780329.27.0.401942187775.issue38323@roundup.psfhosted.org> |
2019-10-22 21:38:49 | vstinner | link | issue38323 messages |
2019-10-22 21:38:49 | vstinner | create | |
|