This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

classification
Title: regrtest fails to stop test_multiprocessing_spawn worker process
Type: Stage: resolved
Components: Tests Versions: Python 3.9
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: miss-islington, vstinner
Priority: normal Keywords: patch

Created on 2019-09-17 20:58 by vstinner, last changed 2022-04-11 14:59 by admin. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 16249 merged vstinner, 2019-09-18 00:25
PR 16250 merged vstinner, 2019-09-18 00:41
PR 16260 merged vstinner, 2019-09-18 12:17
PR 16261 merged miss-islington, 2019-09-18 12:37
Messages (7)
msg352663 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2019-09-17 20:58
I ran tests locally on my laptop. Tests were running for 2 minutes. I interrupted the process by pressing CTRL+c: regrtest failed to stop immediately the worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037>. Then, regrtest main process hangs in threading._shutdown(). I had to press again CTRL+c to unblock it :-(


This bug may be related to bpo-37531 "Fix regrtest timeout for subprocesses: regrtest -jN --timeout=SECONDS".

See also bpo-38190 "regrtest: test suite completes but Tests Result is not displayed and the process hangs" which might be related?


vstinner@apu$ make && ./python -m test -j0 -r
...
0:02:03 load avg: 8.15 [240/419] test_dynamicclassattribute passed -- running: test_multiprocessing_spawn (1 min 17 sec), test_multiprocessing_forkserver (1 min 17 sec), test_gdb (1 min 32 sec), test_multiprocessing_fork (50 sec 894 ms)
0:02:03 load avg: 8.15 [241/419] test_importlib passed -- running: test_multiprocessing_spawn (1 min 17 sec), test_multiprocessing_forkserver (1 min 17 sec), test_gdb (1 min 32 sec), test_multiprocessing_fork (50 sec 998 ms)
0:02:04 load avg: 8.15 [242/419] test_ensurepip passed -- running: test_multiprocessing_spawn (1 min 18 sec), test_multiprocessing_forkserver (1 min 18 sec), test_gdb (1 min 33 sec), test_multiprocessing_fork (51 sec 937 ms)
^C
Kill worker process 6290 running for 2.7 sec
Kill worker process 6290 running for 2.7 sec
Kill worker process 28037 running for 78.3 sec
Kill worker process 6538 running for 1.2 sec
Kill worker process 6538 running for 1.2 sec
Kill worker process 5567 running for 4.6 sec
Kill worker process 5567 running for 4.6 sec
Kill worker process 28020 running for 79.0 sec
Kill worker process 3314 running for 22.5 sec
Kill worker process 3314 running for 22.5 sec
Kill worker process 28020 running for 79.0 sec
Kill worker process 6533 running for 1.4 sec
Kill worker process 6533 running for 1.4 sec
Kill worker process 27563 running for 93.8 sec
Kill worker process 27563 running for 93.8 sec
Kill worker process 31118 running for 52.1 sec
Kill worker process 31118 running for 52.2 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 1.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 2.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 3.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 4.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 5.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 6.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 7.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 8.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 9.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 10.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 11.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 12.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 13.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 14.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 15.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 16.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 17.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 18.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 19.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 20.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 21.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 22.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 23.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 24.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 25.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 26.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 27.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 28.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 29.1 sec
Wait for regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037> for 30.1 sec
Warning -- failed to join a regrtest worker <MultiprocessThread alive test=test_multiprocessing_spawn pid=28037>

== Tests result: INTERRUPTED ==
Test suite interrupted by signal SIGINT.

177 tests omitted:
    test__osx_support test_abstract_numbers test_aifc test_asyncgen
    test_atexit test_audit test_base64 test_binascii test_bisect
    test_buffer test_bz2 test_c_locale_coercion test_calendar
    test_call test_charmapcodec test_clinic test_cmd_line
    test_cmd_line_script test_code test_codecencodings_hk
    test_codecencodings_iso2022 test_codecencodings_jp
    test_codecencodings_kr test_codecmaps_tw test_codecs test_compile
    test_complex test_concurrent_futures test_configparser
    test_contains test_contextlib test_contextlib_async test_copy
    test_copyreg test_coroutines test_crashers test_csv test_ctypes
    test_curses test_decorators test_deque test_dictviews test_dis
    test_doctest test_dtrace test_dynamic test_email test_embed
    test_exception_variations test_exceptions test_faulthandler
    test_file test_finalization test_flufl test_fork1 test_format
    test_future3 test_future5 test_gdb test_genericclass
    test_genericpath test_grp test_heapq test_htmlparser test_httplib
    test_imghdr test_imp test_int test_io test_ioctl test_ipaddress
    test_isinstance test_itertools test_json test_keyword
    test_largefile test_lib2to3 test_linecache test_lltrace
    test_logging test_mailcap test_marshal test_math test_memoryio
    test_multibytecodec test_multiprocessing_fork
    test_multiprocessing_forkserver test_multiprocessing_main_handling
    test_multiprocessing_spawn test_named_expressions test_netrc
    test_numeric_tower test_openpty test_operator test_ordered_dict
    test_os test_ossaudiodev test_parser test_pathlib test_pdb
    test_peepholer test_pickle test_pkg test_plistlib test_popen
    test_poplib test_posixpath test_pow test_print test_profile
    test_property test_pstats test_pyclbr test_pydoc test_random
    test_range test_readline test_regrtest test_repl test_richcmp
    test_robotparser test_sax test_sched test_scope test_script_helper
    test_setcomps test_shelve test_shlex test_site test_smtpd
    test_smtplib test_sndhdr test_socketserver test_source_encoding
    test_spwd test_sqlite test_ssl test_statistics
    test_string_literals test_strptime test_struct test_structmembers
    test_subprocess test_super test_symtable test_syntax test_tabnanny
    test_telnetlib test_tempfile test_threadedtempfile
    test_threading_local test_timeit test_tokenize test_trace
    test_traceback test_tracemalloc test_typechecks test_unicode_file
    test_unicode_file_functions test_unicode_identifiers
    test_unpack_ex test_urllib test_urllib_response test_userlist
    test_userstring test_utf8source test_venv test_wait4 test_warnings
    test_webbrowser test_xml_etree test_yield_from test_zipapp
    test_zipfile test_zipfile64 test_zipimport_support test_zlib

226 tests OK.

16 tests skipped:
    test_devpoll test_kqueue test_msilib test_nis test_smtpnet
    test_startfile test_timeout test_tix test_tk test_ttk_guionly
    test_urllib2net test_urllibnet test_winconsoleio test_winreg
    test_winsound test_xmlrpc_net

Total duration: 2 min 34 sec
Tests result: INTERRUPTED


^CWarning -- Unraisable exception
Exception ignored in: <module 'threading' from '/home/vstinner/python/master/Lib/threading.py'>
Traceback (most recent call last):
  File "/home/vstinner/python/master/Lib/threading.py", line 1390, in _shutdown
    lock.acquire()
KeyboardInterrupt:
msg352664 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2019-09-17 21:02
Moreover, even after I stopped regrtest, two processes are still running in the background :-(

 6535 pts/2    Sl     0:00 /home/vstinner/python/master/python -c from multiprocessing.spawn import spawn_main; spawn_main(tracker_fd=4, pipe_handle=9) --multiprocessing-fork

 6560 pts/2    Sl     0:00 /home/vstinner/python/master/python -c from multiprocessing.spawn import spawn_main; spawn_main(tracker_fd=4, pipe_handle=11) --multiprocessing-fork
msg352701 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2019-09-18 06:29
New changeset da57599af51c602b015b6880123fef6eccdabcf5 by Victor Stinner in branch 'master':
bpo-38203: regrtest: put a 2 min timeout on Python exit (GH-16250)
https://github.com/python/cpython/commit/da57599af51c602b015b6880123fef6eccdabcf5
msg352722 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2019-09-18 12:15
New changeset 0a963fbc9c4cf4569f1eadaa2aa1229bb0081256 by Victor Stinner in branch 'master':
bpo-38203: faulthandler.dump_traceback_later() is always available (GH-16249)
https://github.com/python/cpython/commit/0a963fbc9c4cf4569f1eadaa2aa1229bb0081256
msg352723 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2019-09-18 12:37
New changeset 064e1e384120635330493abf300b1113eadd904c by Victor Stinner in branch '3.8':
bpo-38203: faulthandler.dump_traceback_later() is always available (GH-16260)
https://github.com/python/cpython/commit/064e1e384120635330493abf300b1113eadd904c
msg352724 - (view) Author: miss-islington (miss-islington) Date: 2019-09-18 12:43
New changeset 1a3a48ddaf41dff3c0fcedcfe7ec0940158c568d by Miss Islington (bot) in branch '3.7':
bpo-38203: faulthandler.dump_traceback_later() is always available (GH-16260)
https://github.com/python/cpython/commit/1a3a48ddaf41dff3c0fcedcfe7ec0940158c568d
msg353063 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2019-09-24 10:20
I worked around the issue, but see bpo-37531 for the root issue which is not fixed yet.
History
Date User Action Args
2022-04-11 14:59:20adminsetgithub: 82384
2019-09-24 10:20:20vstinnersetstatus: open -> closed
resolution: fixed
messages: + msg353063

stage: patch review -> resolved
2019-09-18 12:43:20miss-islingtonsetnosy: + miss-islington
messages: + msg352724
2019-09-18 12:37:24miss-islingtonsetpull_requests: + pull_request15855
2019-09-18 12:37:08vstinnersetmessages: + msg352723
2019-09-18 12:17:38vstinnersetpull_requests: + pull_request15854
2019-09-18 12:15:14vstinnersetmessages: + msg352722
2019-09-18 06:29:32vstinnersetmessages: + msg352701
2019-09-18 00:41:35vstinnersetpull_requests: + pull_request15846
2019-09-18 00:25:16vstinnersetkeywords: + patch
stage: patch review
pull_requests: + pull_request15845
2019-09-17 21:02:52vstinnersetmessages: + msg352664
2019-09-17 20:58:38vstinnercreate