classification
Title: Running test_curses on FreeBSD changes signal handlers
Type: behavior Stage: resolved
Components: FreeBSD Versions: Python 3.7, Python 3.6, Python 2.7
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: koobs, pablogsal, pitrou, serhiy.storchaka, skrah, vstinner
Priority: normal Keywords: patch

Created on 2017-09-29 08:26 by serhiy.storchaka, last changed 2017-10-31 10:45 by vstinner. This issue is now closed.

Files
File name Uploaded Description Edit
bug.py vstinner, 2017-10-30 22:38
Pull Requests
URL Status Linked Edit
PR 4183 merged vstinner, 2017-10-31 00:24
PR 4187 merged vstinner, 2017-10-31 10:18
PR 4188 merged vstinner, 2017-10-31 10:20
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
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