Ignored "BlockingIOError: [Errno 11] Resource temporarily unavailable" are still haunting us

[YaroslavHalchenko]

BPO	40634
Nosy	@asvetlov, @1st1

^{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 = None
created_at = <Date 2020-05-15.15:30:02.322>
labels = ['3.7', '3.8', 'expert-asyncio']
title = 'Ignored "BlockingIOError: [Errno 11] Resource temporarily unavailable" are still haunting us'
updated_at = <Date 2020-06-15.12:50:39.417>
user = 'https://bugs.python.org/YaroslavHalchenko'

bugs.python.org fields:

activity = <Date 2020-06-15.12:50:39.417>
actor = 'Yaroslav.Halchenko'
assignee = 'none'
closed = False
closed_date = None
closer = None
components = ['asyncio']
creation = <Date 2020-05-15.15:30:02.322>
creator = 'Yaroslav.Halchenko'
dependencies = []
files = []
hgrepos = []
issue_num = 40634
keywords = []
message_count = 2.0
messages = ['368953', '371540']
nosy_count = 3.0
nosy_names = ['asvetlov', 'Yaroslav.Halchenko', 'yselivanov']
pr_nums = []
priority = 'normal'
resolution = None
stage = None
status = 'open'
superseder = None
type = None
url = 'https://bugs.python.org/issue40634'
versions = ['Python 3.5', 'Python 3.6', 'Python 3.7', 'Python 3.8']

[YaroslavHalchenko]

This is a reincarnation of previous issues such as

• older https://bugs.python.org/issue21595 which partially (with ack on that) addressed the issue awhile back
• more recent https://bugs.python.org/issue38104 which was closed as "wont fix" since "the provided example finishes without any warning" on 3.8 (verified -- true for me with 3.8.3rc1); and with the explanation that "You spawn too many subprocesses that finish virtually at the same time. It leads to wakeup_fd overrun."
• additional similar reports could be found online, e.g. https://stackoverflow.com/a/52391791/1265472 .

In our project we are slowly introducing use of asyncio and have a mix of execution with asyncio and regular subprocess.Popen. We do run lots of short lived processes serially, and I think it should be Ok, i.e. it should not cause underlying libraries to spit out some output to ignore unless we indeed just using them incorrectly somehow.

If we recreate the SelectorEventLoop for every separate execution via asyncio -- no ignored exception messages are displayed. But if we start to reuse the same loop -- they eventually emerge. If I enable asyncio debug and log it along with our own debug messages, the strange thing that they come around the points where we run using regular subprocess.Popen, not asyncio. See datalad/datalad#4527 (comment) for more information.

Unfortunately I do not have (yet) any short script to reproduce it, but I would appreciate possible hints on how to figure out what is actually causing them in our particular case. May be additional logging within asyncio could assist?

[YaroslavHalchenko]

any feedback/ideas/fixes would still be highly appreciated. Thank you!

[kumaraditya303]

I am not sure we can do anything about this as there is no reproducer. I can only suggest you to use asyncio.PidfdChildWatcher which can handle a lot of subprocesses on Linux. Also Andrew commented that this does not happen on 3.8+ #82285 (comment) so closing.

Create a new issue with reproducer if this is still an issue on supported Python versions.

[gvanrossum]

I believe the OP is @yarikoptic.

Question for OP: does this still occur on more recent Python versions? Could you try Kumar's suggestion and report back?

We are aware that child process exit handling in asyncio is imperfect. See e.g. #94597.

[kumaraditya303]

I believe the OP is @yarikoptic.

Oh, I tried the same GitHub username YaroslavHalchenko but there was no account hence I closed.

[kumaraditya303]

FTR before closing I tried the script posted in #82285 and I was only able to reproduce this on 3.7 which is EOL and not on 3.8+.

[gvanrossum]

Oh, I tried the same GitHub username YaroslavHalchenko but there was no account hence I closed.

I found it by using GitHub search, clicking on the 4 user results, and going through all of them. Only one had significant activity, and they had "datalad" in their user description, so I figured that was the OP. :-)

In other cases I've used bpo user list search, but I don't know if you have access to that. In this case there was no GH username.

FTR before closing I tried the script posted in #82285 and I was only able to reproduce this on 3.7 which is EOL and not on 3.8+.

The problem seems due to processes exiting faster than what the watcher can keep up, and since the OP acknowledged that some relieve was provided by 3.8, I imagine it's hard to repro.

[kumaraditya303]

I found it by using GitHub search, clicking on the 4 user results, and going through all of them. Only one had significant activity, and they had "datalad" in their user description, so I figured that was the OP. :-)

Ok, hit and trial :)

The problem seems due to processes exiting faster than what the watcher can keep up, and since the OP acknowledged that some relieve was provided by 3.8, I imagine it's hard to repro.

Yes, hence I suggested to use asyncio.PidfdChildWatcher which can handle a lot of subprocesses since it does not uses wakeup fd mechanism.

[yarikoptic]

I believe the OP is @yarikoptic.

FWIW

• confirming that YaroslavHalchenko on https://bugs.python.org/issue40634 is me.
• original issue is no longer "pressing" for us since we moved back to non-asyncio implementation of subprocesses execution.

[gvanrossum]

Thanks! Then I'll close this issue, given that we already know child watchers aren't optimal.