classification
Title: test_signal.test_interprocess_signal() race condition
Type: Stage: resolved
Components: Tests Versions: Python 3.8, Python 3.7, Python 3.6
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: miss-islington, pablogsal, vstinner
Priority: normal Keywords: patch

Created on 2018-12-06 12:36 by vstinner, last changed 2018-12-11 13:07 by vstinner. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 11087 merged pablogsal, 2018-12-10 22:53
PR 11113 merged miss-islington, 2018-12-11 11:32
PR 11114 merged miss-islington, 2018-12-11 11:32
Messages (6)
msg331233 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-12-06 12:35
test_signal.test_interprocess_signal() has a race condition:

with self.subprocess_send_signal(pid, "SIGUSR1") as child: # here
    self.wait_signal(child, 'SIGUSR1', SIGUSR1Exception)

The test only except SIGUSR1Exception inside wait_signal(), but the signal can be sent during subprocess_send_signal() call. assertRaises(SIGUSR1Exception) should surround these two lines instead. wait_signal() shouldn't handle the signal.

Or wait_signal() should call subprocess_send_signal().


It seems like Python 2.7 has the proper design. It might be a regression introduced by myself in:

commit 32eb840a42ec0e131daac48d43aa35290e72571e
Author: Victor Stinner <victor.stinner@gmail.com>
Date:   Tue Mar 15 11:12:35 2016 +0100

    Issue #26566: Rewrite test_signal.InterProcessSignalTests
    
    * Add Lib/test/signalinterproctester.py
    * Don't disable the garbage collector anymore
    * Don't use os.fork() with a subprocess to not inherit existing signal handlers
      or threads: start from a fresh process
    * Don't use UNIX kill command to send a signal but Python os.kill()
    * Use a timeout of 10 seconds to wait for the signal instead of 1 second
    * Always use signal.pause(), instead of time.wait(1), to wait for a signal
    * Use context manager on subprocess.Popen
    * remove code to retry on EINTR: it's no more needed since the PEP 475
    * remove unused function exit_subprocess()
    * Cleanup the code


FAIL: test_interprocess_signal (test.test_signal.PosixTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/home/buildbot/python/3.7.koobs-freebsd10.nondebug/build/Lib/test/test_signal.py", line 62, in test_interprocess_signal
    assert_python_ok(script)
  File "/usr/home/buildbot/python/3.7.koobs-freebsd10.nondebug/build/Lib/test/support/script_helper.py", line 157, in assert_python_ok
    return _assert_python(True, *args, **env_vars)
  File "/usr/home/buildbot/python/3.7.koobs-freebsd10.nondebug/build/Lib/test/support/script_helper.py", line 143, in _assert_python
    res.fail(cmd_line)
  File "/usr/home/buildbot/python/3.7.koobs-freebsd10.nondebug/build/Lib/test/support/script_helper.py", line 84, in fail
    err))
AssertionError: Process return code is 1
command line: ['/usr/home/buildbot/python/3.7.koobs-freebsd10.nondebug/build/python', '-X', 'faulthandler', '-I', '/usr/home/buildbot/python/3.7.koobs-freebsd10.nondebug/build/Lib/test/signalinterproctester.py']

stdout:
---

---

stderr:
---
E/usr/home/buildbot/python/3.7.koobs-freebsd10.nondebug/build/Lib/subprocess.py:858: ResourceWarning: subprocess 64567 is still running
  ResourceWarning, source=self)
ResourceWarning: Enable tracemalloc to get the object allocation traceback

======================================================================
ERROR: test_interprocess_signal (__main__.InterProcessSignalTests)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/home/buildbot/python/3.7.koobs-freebsd10.nondebug/build/Lib/test/signalinterproctester.py", line 68, in test_interprocess_signal
    with self.subprocess_send_signal(pid, "SIGUSR1") as child:
  File "/usr/home/buildbot/python/3.7.koobs-freebsd10.nondebug/build/Lib/test/signalinterproctester.py", line 50, in subprocess_send_signal
    return subprocess.Popen(args)
  File "/usr/home/buildbot/python/3.7.koobs-freebsd10.nondebug/build/Lib/subprocess.py", line 775, in __init__
    restore_signals, start_new_session)
  File "/usr/home/buildbot/python/3.7.koobs-freebsd10.nondebug/build/Lib/subprocess.py", line 1476, in _execute_child
    part = os.read(errpipe_read, 50000)
  File "/usr/home/buildbot/python/3.7.koobs-freebsd10.nondebug/build/Lib/test/signalinterproctester.py", line 22, in sigusr1_handler
    raise SIGUSR1Exception
SIGUSR1Exception

----------------------------------------------------------------------
Ran 1 test in 0.223s

FAILED (errors=1)
---

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

Ran 43 tests in 31.872s

FAILED (failures=1, skipped=2)
test test_signal failed
msg331288 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-12-07 10:27
I forgot the URL to the build:
https://buildbot.python.org/all/#/builders/170/builds/175
msg331613 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2018-12-11 11:32
New changeset 2ab2afd387084ba38a37f5944fcb0675113b64dc by Pablo Galindo in branch 'master':
bpo-35426: Eliminate race condition in test_interprocess_signal (GH-11087)
https://github.com/python/cpython/commit/2ab2afd387084ba38a37f5944fcb0675113b64dc
msg331614 - (view) Author: miss-islington (miss-islington) Date: 2018-12-11 11:50
New changeset f7404a5a08b70ec171279a277c1817e82430fa83 by Miss Islington (bot) in branch '3.7':
bpo-35426: Eliminate race condition in test_interprocess_signal (GH-11087)
https://github.com/python/cpython/commit/f7404a5a08b70ec171279a277c1817e82430fa83
msg331615 - (view) Author: miss-islington (miss-islington) Date: 2018-12-11 11:56
New changeset 869e23e0af806ed3a10d0484827cb1b5f5cd5e5f by Miss Islington (bot) in branch '3.6':
bpo-35426: Eliminate race condition in test_interprocess_signal (GH-11087)
https://github.com/python/cpython/commit/869e23e0af806ed3a10d0484827cb1b5f5cd5e5f
msg331618 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-12-11 13:07
Thanks Pablo Galindo for the quick fix!
History
Date User Action Args
2018-12-11 13:07:03vstinnersetstatus: open -> closed
resolution: fixed
messages: + msg331618

stage: patch review -> resolved
2018-12-11 11:56:52miss-islingtonsetmessages: + msg331615
2018-12-11 11:50:36miss-islingtonsetnosy: + miss-islington
messages: + msg331614
2018-12-11 11:32:39miss-islingtonsetpull_requests: + pull_request10343
2018-12-11 11:32:27miss-islingtonsetpull_requests: + pull_request10342
2018-12-11 11:32:14pablogsalsetnosy: + pablogsal
messages: + msg331613
2018-12-10 22:53:50pablogsalsetkeywords: + patch
stage: patch review
pull_requests: + pull_request10319
2018-12-07 10:27:48vstinnersetmessages: + msg331288
2018-12-06 12:36:00vstinnercreate