asyncio: Creating many subprocess generates lots of internal BlockingIOError

[SebastianKreftDeezer]

BPO	21595
Nosy	@gvanrossum, @pitrou, @vstinner, @giampaolo, @1st1
Files	test_subprocess_error.py asyncio_read_from_self.patch asyncio_read_from_self_test.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 2014-06-19.11:00:16.389>
created_at = <Date 2014-05-28.16:18:25.158>
labels = ['expert-asyncio']
title = 'asyncio: Creating many subprocess generates lots of internal BlockingIOError'
updated_at = <Date 2014-06-19.11:10:17.276>
user = 'https://bugs.python.org/SebastianKreftDeezer'

bugs.python.org fields:

activity = <Date 2014-06-19.11:10:17.276>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2014-06-19.11:00:16.389>
closer = 'python-dev'
components = ['asyncio']
creation = <Date 2014-05-28.16:18:25.158>
creator = 'Sebastian.Kreft.Deezer'
dependencies = []
files = ['35385', '35388', '35495']
hgrepos = []
issue_num = 21595
keywords = ['patch']
message_count = 9.0
messages = ['219288', '219299', '219301', '219872', '219873', '219875', '220154', '220965', '220966']
nosy_count = 7.0
nosy_names = ['gvanrossum', 'pitrou', 'vstinner', 'giampaolo.rodola', 'python-dev', 'yselivanov', 'Sebastian.Kreft.Deezer']
pr_nums = []
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue21595'
versions = ['Python 3.4']

[SebastianKreftDeezer]

Using the asyncio.create_subprocess_exec, generates lost of internal error messages. These messages are:

Exception ignored when trying to write to the signal wakeup fd:
BlockingIOError: [Errno 11] Resource temporarily unavailable

Getting the messages depeneds on how many subprocesses are active at the same time. In my system (Debian 7, kernel 3.2.0-4-amd64, python 3.4.1), with 3 or less processes at the same time I don't see any problem, but with 4 or more I got lot of messages.

On the other hand, these error messages seem to be innocuous, as no exception seems to be raised.

Attached is a test script that shows the problem.

It is run as:
bin/python3.4 test_subprocess_error.py <MAX_PROCESSES> <ITERATIONS>

it requires to have the du command.

Let me know if there are any (conceptual) mistakes in the attached code.

[vstinner]

"Exception ignored when trying to write to the signal wakeup fd" message comes from the signal handler in Modules/signalmodule.c. The problem is that Python gets a lot of SIGCHLD signals (the test scripts creates +300 processes per second on my computer). The producer (signal handler writing the signal number into the "self" pipe) is faster than the consumer (BaseSelectorEventLoop._read_from_self callback).

Attached patch should reduce the risk of seeing the message "Exception ignored when trying to write to the signal wakeup fd". The patch reads all pending of the self pipe, instead of just trying to read a signal byte.

The test script doesn't write the error message anymore when the patch is applied (the script creates more than 300 processes per second).

The patch doesn't solve completly the issue. Other possible enhancements:

• Add a flag in the signal handler to notify that a signal was received, and write a single byte until the flag is reset to False. It would avoid to fill the pipe. It requires to implement a custom signal handler implemented in C, different from signal handlers of the Python module.

• Add an higher priority to callbacks of signal handlers. Asyncio doesn't support priority on callbacks right now.

• Increaze the size of the pipe. On Linux, it looks like "fcntl(fd, F_SETPIPE_SZ, size);" can be used. The maximum size is /proc/sys/fs/pipe-max-size (ex: 1 MB of my Fedora 20).

[vstinner]

BaseProactorEventLoop._loop_self_reading() uses an overlapped read of 4096 bytes. I don't understand how it wakes up the event loop. When the operation is done, _loop_self_reading() is scheduled with call_soon() by the Future object. Is it enough to wake up the event loop?

Is BaseProactorEventLoop correct?

--

Oh, I forgot to explain this part of asyncio_read_from_self.patch:

+ data = self._ssock.recv(4096)
+ if not data:
+ break

This break "should never occur". It should only occur if _ssock is no more blocking. But it would be a bug, because this pipe is private and set to non-blocking at its creation.

I chose to add the test because it should not hurt to add it "just in case" (and to avoid an unlimited busy loop).

[vstinner]

Can someone please review asyncio_read_from_self.patch?

[vstinner]

Hum, maybe I need to add a unit test for it.

[vstinner]

asyncio_read_from_self_test.patch: Unit test to check that running the loop once reads all bytes. The unit test is ugly: it calls private methods, and it is completly different on UNIX (selector) and on Windows (proactor).

I would prefer to *not* add such test, and just enhance the code (apply asyncio_read_from_self.patch).

[vstinner]

Can someone please review asyncio_read_from_self.patch?

[python-dev]

New changeset 46c251118799 by Victor Stinner in branch '3.4':
Closes bpo-21595: asyncio.BaseSelectorEventLoop._read_from_self() now reads all
http://hg.python.org/cpython/rev/46c251118799

New changeset 513eea89b80a by Victor Stinner in branch 'default':
(Merge 3.4) Closes bpo-21595: asyncio.BaseSelectorEventLoop._read_from_self() now
http://hg.python.org/cpython/rev/513eea89b80a

[vstinner]

I commited asyncio_read_from_self.patch into Tulip, Python 3.4 and 3.5. If someone is interested to work on more advanced enhancement, please open a new issue.

Oh by, a workaround is to limit the number of concurrent processes.

Without the patch, "./python test_subprocess_error.py 5 1000" (max: 5 concurrenet processes) emits a lot of "BlockingIOError: [Errno 11] Resource temporarily unavailable" message.

With the patch, I start getting messages with 140 concurrent processes, which is much better :-) IMO more than 100 concurrent processes is crazy, don't do that at home :-) I mean processes with a very short lifetime. The limit is the number of SIGCHLD per second, so the number of processes which end at the same second.