socketserver.ForkingMixIn.server_close() leaks zombie processes

[vstinner]

BPO	31151
Nosy	@vstinner, @ned-deily
PRs	bpo-31151: Add socketserver.ForkingMixIn.server_close() #3057 bpo-31233, bpo-31151: Document socketserver changes #5417
Files	forkingmixin_sleep.patch

^{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-05-29.22:01:13.402>
created_at = <Date 2017-08-09.00:40:39.921>
labels = ['3.7', 'tests', 'performance']
title = 'socketserver.ForkingMixIn.server_close() leaks zombie processes'
updated_at = <Date 2018-05-29.22:01:13.401>
user = 'https://github.com/vstinner'

bugs.python.org fields:

activity = <Date 2018-05-29.22:01:13.401>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2018-05-29.22:01:13.402>
closer = 'vstinner'
components = ['Tests']
creation = <Date 2017-08-09.00:40:39.921>
creator = 'vstinner'
dependencies = []
files = ['47072']
hgrepos = []
issue_num = 31151
keywords = ['patch']
message_count = 13.0
messages = ['299959', '299960', '300074', '300084', '300106', '302013', '302015', '303041', '311015', '311022', '311093', '316834', '318116']
nosy_count = 2.0
nosy_names = ['vstinner', 'ned.deily']
pr_nums = ['3057', '5417']
priority = None
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'resource usage'
url = 'https://bugs.python.org/issue31151'
versions = ['Python 3.6', 'Python 3.7']

[vstinner]

It seems like test_socketserver leaks child processes on the "x86 Gentoo Refleaks 3.6" buildbot, but I'm unable to reproduce the bug.

http://buildbot.python.org/all/builders/x86%20Gentoo%20Refleaks%203.6/builds/49/steps/test/logs/stdio

0:48:11 load avg: 3.91 [154/405/2] test_socketserver failed -- running: test_decimal (630 sec)
Warning -- reap_children() reaped child process 1044
beginning 6 repetitions
123456
Warning -- reap_children() reaped child process 1104
Warning -- reap_children() reaped child process 1115
.Warning -- reap_children() reaped child process 1170
Warning -- reap_children() reaped child process 1175
Warning -- reap_children() reaped child process 1184
.Warning -- reap_children() reaped child process 1249
.Warning -- reap_children() reaped child process 1311
Warning -- reap_children() reaped child process 1316
...
test_socketserver leaked [1, 1, 1] memory blocks, sum=3

(...)

test_ForkingUnixStreamServer (test.test_socketserver.SocketServerTest) ... creating server
ADDR = /tmp/unix_socket.hqh5x95a
CLASS = <class 'test.test_socketserver.ForkingUnixStreamServer'>
server running
test client 0
test client 1
test client 2
waiting for server
done
Warning -- reap_children() reaped child process 17938
ok

test_ForkingUnixDatagramServer (test.test_socketserver.SocketServerTest) ... creating server
ADDR = /tmp/unix_socket.gry6ulhp
CLASS = <class 'test.test_socketserver.ForkingUnixDatagramServer'>
server running
test client 0
test client 1
test client 2
waiting for server
done
Warning -- reap_children() reaped child process 18212
ok

test_ForkingUDPServer (test.test_socketserver.SocketServerTest) ... creating server
ADDR = ('127.0.0.1', 43415)
CLASS = <class 'socketserver.ForkingUDPServer'>
server running
test client 0
test client 1
test client 2
waiting for server
done
Warning -- reap_children() reaped child process 18281
ok
test_ForkingUnixDatagramServer (test.test_socketserver.SocketServerTest)

[vstinner]

Ah, the master branch is also affected. Example:

http://buildbot.python.org/all/builders/x86%20Gentoo%20Refleaks%203.x/builds/47/steps/test/logs/stdio

1:35:05 load avg: 4.64 [212/406] test_socketserver passed -- running: test_subprocess (370 sec)
beginning 6 repetitions
123456
Warning -- reap_children() reaped child process 4641
.Warning -- reap_children() reaped child process 4708
..Warning -- reap_children() reaped child process 4832
.Warning -- reap_children() reaped child process 4916
Warning -- reap_children() reaped child process 4921
..

[vstinner]

The problem is that socketserver.ForkinMixin doesn't wait until all children completes. It's only calls os.waitpid() in non-blocking module (using os.WNOHANG) after each loop iteration. If a child process completes after the last call to ForkingMixIn.collect_children(), the server leaks zombie processes.

The server must wait until all children completes. Attached PR implements that.

The bug was be reproduced with the attached forkingmixin_sleep.patch.

haypo@selma$ ./python -m test -v -u all test_socketserver --fail-env-changed -m '*Fork*'
(...)
Warning -- reap_children() reaped child process 17093
Warning -- reap_children() reaped child process 17094
(...)

[vstinner]

New changeset aa8ec34 by Victor Stinner in branch 'master':
bpo-31151: Add socketserver.ForkingMixIn.server_close() (bpo-3057)
aa8ec34

[vstinner]

bpo-31010 has been marked as a duplicate of this issue.

[vstinner]

I created a thread on the python-dev mailing list to discuss this issue:
https://mail.python.org/pipermail/python-dev/2017-August/148826.html

[vstinner]

I tag this issue as release blocker as a remainder that we have to agree how to handle threads/processes before Python 3.7 feature freeze.

See also bpo-31233: socketserver.ThreadingMixIn leaks running threads after server_close().