Home Original page

Issue 31629: Running test_curses on FreeBSD changes signal handlers

Created on 2017-09-29 08:26 by serhiy.storchaka, last changed 2022-04-11 14:58 by admin. This issue is now closed.

Messages (14) msg303309 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2017-09-29 08:26 
test_multiprocessing_fork fails only if run all tests on FreeBSD. It is passed successfully if run it separately.

$ ./python -m test -vuall
...
======================================================================
FAIL: test_many_processes (test.test_multiprocessing_fork.WithProcessesTestProcess)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/home/serhiy/py/cpython3.7-debug/Lib/test/_test_multiprocessing.py", line 505, in test_many_processes
    self.assertEqual(p.exitcode, -signal.SIGTERM)
AssertionError: 1 != -15

======================================================================
FAIL: test_terminate (test.test_multiprocessing_fork.WithProcessesTestProcess)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/home/serhiy/py/cpython3.7-debug/Lib/test/_test_multiprocessing.py", line 360, in test_terminate
    self.assertEqual(exitcode, -signal.SIGTERM)
AssertionError: 1 != -15

----------------------------------------------------------------------

test_subprocess hangs, perhaps due to the same cause.
msg305241 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-30 17:37 
test_many_processes() was added by bpo-30589. Antoine Pitrou commented:

"In the end, I'm glad I added a stress test (test_many_processes) as part of this issue.".

I confirm that test_multiprocessing_fork fails with "./python -m test -vuall" on FreeBSD CURRENT (I tested on Koobs's buildbot worker). I'm currently trying to bisect the issue. It's not easy since test_curses does randomly crash and running +200 tests sequentially is slow.
msg305242 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-30 17:40 
Latest change in test_many_processes(): commit e6cfdefa0c2f5bda177e49b228c2c7528f7c239c of bpo-31510 which was specific to macOS.
msg305243 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-30 17:41 
See also commit c08177a1ccad2ed0d50898c2731b518c631aed14 of bpo-30703.
msg305253 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-30 21:33 
Running these two tests is enough to reproduce the issue:

test.test_curses.TestCurses.test_new_curses_panel
test.test_multiprocessing_fork.WithProcessesTestProcess.test_many_processes

Command:

CURRENT-amd64% ./python -m test -vuall test_curses  test_multiprocessing_fork  -m test.test_curses.TestCurses.test_new_curses_panel -m test.test_multiprocessing_fork.WithProcessesTestProcess.test_many_processes
msg305257 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-30 22:38 
The bug can be reproduced with attached bug.py.

With "curses.initscr(); curses.endwin()", the exit code becomes 1.

Without, the child processes exits with code -15 (-SIGTERM).
msg305260 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2017-10-30 23:50 
I have tracked the issue down to the call inside the call to initscr in _cursesmodule.c. The issue *seems* related to the fact that all processes are sharing the same initialization of the curses internal structures, that (probably) is also related to an error that happens when calling initscr multiple times. Notice that:

def sleep_some():
    curses.initscr()
    curses.endwin()
    time.sleep(100)

(without calling initscr in the parent)

yields the correct results:

-15 -15
-15 -15
-15 -15

while doing the same but interleaving one all to initscr after the first fork:

for p in procs:
    p.start()
    curses.initscr()

yields correct results for the first child but incorrect for the rest:

-15 -15
1 -15
1 -15

It seems that forking (because spawn or forkserver always works) after doing the call to initscr does something to the child that makes it unable to handle/receive SIGTERM. The exit statuses of this last round are:

[pid 27105] +++ killed by SIGTERM +++
[pid 27104] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_KILLED, si_pid=27105, si_uid=1000, si_status=SIGTERM, si_utime=0, si_stime=0} ---
[pid 27106] +++ exited with 1 +++
[pid 27104] --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=27106, si_uid=1000, si_status=1, si_utime=0, si_stime=0} ---
[pid 27107] +++ exited with 1 +++
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=27107, si_uid=1000, si_status=1, si_utime=0, si_stime=0} ---
msg305261 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2017-10-31 00:11 
Also, it seems that calling initscr registers signal handlers for SIGTERM:

Without calling initscr:

...


rt_sigaction(SIGINT, {sa_handler=0x55d9351a9155, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f7d22b36da0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f7d22b36da0}, {sa_handler=0x55d9351a9155, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f7d22b36da0}, 8) = 0
sigaltstack(NULL, {ss_sp=0x55d93743a1c0, ss_flags=0, ss_size=8192}) = 0
sigaltstack({ss_sp=NULL, ss_flags=SS_DISABLE, ss_size=0}, NULL) = 0

...

Calling initscr:

...

 rt_sigaction(SIGTERM, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0                                                                                                                                                                                                        rt_sigaction(SIGTERM, {sa_handler=0x7f28d6affed0, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f28d7c8eda0}, NULL, 8) = 0
 rt_sigaction(SIGWINCH, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0                                                                                                                                                                                                           rt_sigaction(SIGWINCH, {sa_handler=0x7f1046394ec0, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f1047523da0}, NULL, 8) = 0
...
msg305264 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-31 00:42 
Pablo Galindo Salgado:
> Also, it seems that calling initscr registers signal handlers for SIGTERM: (...)

The problem is that endwin() doesn't restore the old handler.

Attached PR 4183 fixes the bug, it saves/restores signal handlers:

./python -m test -vuall test_curses  test_multiprocessing_fork -m test.test_curses.TestCurses.test_new_curses_panel -m test.test_multiprocessing_fork.WithProcessesTestProcess.test_many_processes
msg305274 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2017-10-31 06:59 
Thank you Victor and Pablo! Great work!
msg305281 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-31 10:14 
New changeset 19f68301a1295a9c30d9f28b8f1479cdcccd75aa by Victor Stinner in branch 'master':
bpo-31629: Add support.SaveSignals (#4183)
https://github.com/python/cpython/commit/19f68301a1295a9c30d9f28b8f1479cdcccd75aa
msg305282 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-31 10:44 
New changeset 1d481822a6295e6739da2d5cca0fdbede51fda22 by Victor Stinner in branch '2.7':
bpo-31629: Add support.SaveSignals (#4183) (#4188)
https://github.com/python/cpython/commit/1d481822a6295e6739da2d5cca0fdbede51fda22
msg305283 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-31 10:45 
New changeset 41efc402f154e48e95dde2993901648edcb24069 by Victor Stinner in branch '3.6':
bpo-31629: Add support.SaveSignals (#4183) (#4187)
https://github.com/python/cpython/commit/41efc402f154e48e95dde2993901648edcb24069
msg305284 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-10-31 10:45 
Thanks Serhiy Storchaka for the bug report and Pablo Galindo Salgado for the analysis!
History Date User Action Args 2022-04-11 14:58:52adminsetgithub: 75810 2017-10-31 10:45:56vstinnersetstatus: open -> closed
versions: + Python 2.7, Python 3.6
messages: + msg305284

resolution: fixed
stage: patch review -> resolved

2017-10-31 10:45:04vstinnersetmessages: + msg305283 2017-10-31 10:44:58vstinnersetmessages: + msg305282 2017-10-31 10:20:35vstinnersetpull_requests: + pull_request4158 2017-10-31 10:18:16vstinnersetpull_requests: + pull_request4157 2017-10-31 10:14:07vstinnersetmessages: + msg305281 2017-10-31 06:59:33serhiy.storchakasetmessages: + msg305274 2017-10-31 00:42:10vstinnersetmessages: + msg305264
title: test_many_processes() of test_multiprocessing_fork fails randomly on FreeBSD -> Running test_curses on FreeBSD changes signal handlers 2017-10-31 00:24:00vstinnersetkeywords: + patch
stage: patch review
pull_requests: + pull_request4154 2017-10-31 00:11:25pablogsalsetmessages: + msg305261 2017-10-30 23:50:14pablogsalsetnosy: + pablogsal
messages: + msg305260
2017-10-30 22:38:54vstinnersetfiles: + bug.py

messages: + msg305257

2017-10-30 21:33:57vstinnersetmessages: + msg305253 2017-10-30 17:41:34vstinnersetmessages: + msg305243 2017-10-30 17:40:40vstinnersetmessages: + msg305242 2017-10-30 17:38:10vstinnersettitle: test_multiprocessing_fork failure on FreeBSD -> test_many_processes() of test_multiprocessing_fork fails randomly on FreeBSD 2017-10-30 17:37:46vstinnersetnosy: + pitrou
messages: + msg305241
2017-09-29 08:26:05serhiy.storchakacreate