test_multiprocessing_forkserver: TestIgnoreEINTR.test_ignore() fails on Travis CI

[vstinner]

BPO	33532
Nosy	@pitrou, @vstinner, @ned-deily, @applio, @miss-islington
PRs	[WIP DON'T MERGE] bpo-33532: Debug test_multiprocessing_forkserver.test_ignore() on Travis CI #7247 [WIP DON'T MERGE] bpo-33532: Debug test_multiprocessing_forkserver.test_ignore() #7260 [WIP DON'T MERGE] bpo-33532: Debug3 test_multiprocessing_forkserver.test_ignore() #7261 bpo-33532: Fix multiprocessing test_ignore() #7262 [3.7] bpo-33532: Fix multiprocessing test_ignore() (GH-7262) #7264 [2.7] bpo-33532: Fix multiprocessing test_ignore() #7265 [3.6] bpo-33532: Fix multiprocessing test_ignore() (GH-7262) #7266 bpo-33532: Debug test_ignore() on Travis CI #7318 bpo-33532: Fix test_multiprocessing_forkserver.test_ignore() #7319 [3.7] bpo-33532: Fix test_multiprocessing_forkserver.test_ignore() (GH-7319) #7320 [3.6] bpo-33532: Fix test_multiprocessing_forkserver.test_ignore() #7322 [2.7] bpo-33532: Fix test_multiprocessing_forkserver.test_ignore() #7323

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2018-06-20.10:12:32.885>
created_at = <Date 2018-05-16.06:30:24.631>
labels = ['3.8', '3.7', 'tests']
title = 'test_multiprocessing_forkserver: TestIgnoreEINTR.test_ignore() fails on Travis CI'
updated_at = <Date 2018-06-20.10:12:32.883>
user = 'https://github.com/vstinner'

bugs.python.org fields:

activity = <Date 2018-06-20.10:12:32.883>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2018-06-20.10:12:32.885>
closer = 'vstinner'
components = ['Tests']
creation = <Date 2018-05-16.06:30:24.631>
creator = 'vstinner'
dependencies = []
files = []
hgrepos = []
issue_num = 33532
keywords = ['patch']
message_count = 30.0
messages = ['316771', '317985', '318008', '318010', '318215', '318222', '318225', '318226', '318227', '318228', '318232', '318233', '318234', '318236', '318237', '318238', '318239', '318240', '318254', '318255', '318265', '318301', '318409', '318416', '318420', '318421', '318426', '318438', '318441', '320051']
nosy_count = 5.0
nosy_names = ['pitrou', 'vstinner', 'ned.deily', 'davin', 'miss-islington']
pr_nums = ['7247', '7260', '7261', '7262', '7264', '7265', '7266', '7318', '7319', '7320', '7322', '7323']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue33532'
versions = ['Python 2.7', 'Python 3.6', 'Python 3.7', 'Python 3.8']

[vstinner]

https://travis-ci.org/python/cpython/jobs/379560387

======================================================================
ERROR: test_ignore (test.test_multiprocessing_forkserver.TestIgnoreEINTR)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/home/travis/build/python/cpython/Lib/test/_test_multiprocessing.py", line 4359, in test_ignore
    os.kill(p.pid, signal.SIGUSR1)
ProcessLookupError: [Errno 3] No such process

[ned-deily]

FWIW, bpo-29589 seems to be an older example of this failure.

[vstinner]

FWIW, bpo-29589 seems to be an older example of this failure.

It was a failure on Mageia 5 (Linux) at 2017-02-17:

== CPython 3.6.0 (default, Feb 17 2017, 15:26:31) [GCC 4.9.2]
== Linux-4.4.13-desktop-1.mga5-x86_64-with-mageia-5-Official little-endian
== hash algorithm: siphash24 64bit
== cwd: /home/dima/bin/Python-3.6.0/build/test_python_8244
== encodings: locale=UTF-8, FS=utf-8
Run tests sequentially
0:00:00 [1/1] test_multiprocessing_forkserver
...
======================================================================
ERROR: test_ignore (test.test_multiprocessing_forkserver.TestIgnoreEINTR)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/home/dima/bin/Python-3.6.0/Lib/test/_test_multiprocessing.py", line 3728, in test_ignore
    os.kill(p.pid, signal.SIGUSR1)
ProcessLookupError: [Errno 3] No such process

[vstinner]

I am unable to reproduce the issue on Fedora 28 (Linux kernel 4.16.11, glibc 2.27):

I ran 6 jobs in parallel during 10 minutes:

• 2: ./python -m test test_multiprocessing_forkserver -m test_ignore -F
• 2: ./python -m test test_multiprocessing_forkserver -F
• 2: ./python -m test -j16 -r -F

The system load was around 30 which is very high (my CPU has 8 logicial threads, 4 physical cores).

[vstinner]

https://travis-ci.org/python/cpython/jobs/379560387

More info about this failure:

== Linux-4.4.0-112-generic-x86_64-with-debian-jessie-sid little-endian
== CPU count: 48
Run tests in parallel using 4 child processes
(...)
0:07:06 load avg: 24.76 [356/416/3] test_multiprocessing_forkserver failed -- running: test_concurrent_futures (61 sec)

[vstinner]

Davin, Antoine: any idea on this bug?

I ran the full test suite and test_multiprocessing_forkserver in parallel in a Trust VM, but I failed to reproduce the bug.

I did a similar test in a Ubuntu Trusty docker container: again, I'm unable to reproduce the bug.

An Ubuntu Trusty docker container is supposed to be as close as possible to Travis CI, except that my laptop doesn't have 48 CPUs.

[vstinner]

test_ignore() starts to fail more and more often on Travis CI for an unknown reason.

https://travis-ci.org/python/cpython/jobs/385562187

== CPU count: 48
(...)
Run tests in parallel using 4 child processes
(...)
0:07:38 load avg: 128.04 [415/416/1] test_multiprocessing_forkserver failed -- running: test_concurrent_futures (378 sec)
(...)
======================================================================
ERROR: test_ignore (test.test_multiprocessing_forkserver.TestIgnoreEINTR)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/home/travis/build/python/cpython/Lib/test/_test_multiprocessing.py", line 4359, in test_ignore
    os.kill(p.pid, signal.SIGUSR1)
ProcessLookupError: [Errno 3] No such process

[vstinner]

https://travis-ci.org/python/cpython/jobs/379560387

Re-running test 'test_multiprocessing_forkserver' in verbose mode
(...)
======================================================================
ERROR: test_ignore (test.test_multiprocessing_forkserver.TestIgnoreEINTR)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/home/travis/build/python/cpython/Lib/test/_test_multiprocessing.py", line 4359, in test_ignore
    os.kill(p.pid, signal.SIGUSR1)
ProcessLookupError: [Errno 3] No such process

[vstinner]

Python 3.7:

https://travis-ci.org/python/cpython/jobs/385474104

Re-running test 'test_multiprocessing_forkserver' in verbose mode

======================================================================
ERROR: test_ignore (test.test_multiprocessing_forkserver.TestIgnoreEINTR)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/home/travis/build/python/cpython/Lib/test/_test_multiprocessing.py", line 4324, in test_ignore
    os.kill(p.pid, signal.SIGUSR1)
ProcessLookupError: [Errno 3] No such process

[vstinner]

Python 3.7:

https://travis-ci.org/python/cpython/jobs/385458840

Re-running test 'test_multiprocessing_forkserver' in verbose mode

======================================================================
ERROR: test_ignore (test.test_multiprocessing_forkserver.TestIgnoreEINTR)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/home/travis/build/python/cpython/Lib/test/_test_multiprocessing.py", line 4324, in test_ignore
    os.kill(p.pid, signal.SIGUSR1)
ProcessLookupError: [Errno 3] No such process

[vstinner]

I added debug traces in PR 7260. test_ignore() failed, but it may be related to my debug traces, since the failure is different.

test_multiprocessing_fork.test_ignore() failure:

test_ignore (test.test_multiprocessing_fork.TestIgnoreEINTR) ...
parent: pid=20159
parent: start child
parent: p=<Process(Process-3, started daemon)>
parent: p.ident=20176
ERROR

======================================================================
ERROR: test_ignore (test.test_multiprocessing_fork.TestIgnoreEINTR)
----------------------------------------------------------------------

Traceback (most recent call last):
  File "/home/travis/build/python/cpython/Lib/test/_test_multiprocessing.py", line 4389, in test_ignore
    self.assertEqual(conn.recv(), 'ready')
  File "/home/travis/build/python/cpython/Lib/multiprocessing/connection.py", line 250, in recv
    buf = self._recv_bytes()
  File "/home/travis/build/python/cpython/Lib/multiprocessing/connection.py", line 407, in _recv_bytes
    buf = self._recv(4)
  File "/home/travis/build/python/cpython/Lib/multiprocessing/connection.py", line 383, in _recv
    raise EOFError
EOFError

test_multiprocessing_fork.test_ignore() success:

test_ignore (test.test_multiprocessing_fork.TestIgnoreEINTR) ...
parent: pid=11713
parent: start child
parent: p=<Process(Process-3, started daemon)>
parent: p.ident=28998
[INFO/Process-3] child process calling self.run()
child: pid=28998
child: register SIGUSR1 handler, send ready
child: wait 1234
parent: ready received
parent: first SIGUSR1
child: got SIGUSR1
parent: send 1234
parent: wait 1234
child: send back 1234
child: big blocking send
parent: second SIGUSR1
parent: wait bytes
child: got SIGUSR1
child: done
[INFO/Process-3] process shutting down
[INFO/Process-3] process shutting down
[INFO/Process-3] process exiting with exitcode 0
[INFO/Process-3] process exiting with exitcode 0
parent: join child
parent: done
ok

[vstinner]

I added debug traces in PR 7260. test_ignore() failed, but it may be related to my debug traces, since the failure is different.

https://travis-ci.org/python/cpython/jobs/385958924