asyncio `proc.kill()` and `proc.wait()` are counter intuitive

[piwicode]

Bug report

Bug description:

On Linux proc.wait() does not return after proc.kill() when there as sub/sub processes.
This only happens when the standard streams are piped, it looks like wait() blocks until the pipes are closed.

import asyncio
import os
import time
async def main():
 proc = await asyncio.create_subprocess_exec(
 "/usr/bin/python3", "-c", "import os;os.system('sleep 20')",
 stdout=asyncio.subprocess.PIPE,
 stderr=asyncio.subprocess.PIPE)
 
 time.sleep(1)
 os.system("ps -f --forest --format pid,ppid,pgid,sid,comm")

 print(f">> This python proces pid={os.getpid()} has a `python3` child process, which has a `sleep` child process.")
 print(f">> Kill the `python3` child process pid={proc.pid}")
 proc.kill()

 os.system("ps -f --forest --format pid,ppid,pgid,sid,comm")
 print(f">> The `python3` child process was killed, the `sleep` process gets orfaned.")
 print(f">> Calling `proc.wait()` or `proc.communicate()` does not return until `sleep` process exits.")
 
 await proc.wait()

asyncio.run(main())

I don't know if it's a documentation issue or a bug.

• It would be more intuitive that proc.wait() after a proc.kill() returned when the process exited, and does not depend on other processes completion.
• It would be more intuitive to use have the same behavior when standard streams are piped and when they are not.

CPython versions tested on:

3.11

Operating systems tested on:

Linux

Linked PRs

• gh-119710: Let asyncio Process.wait() finish on only process exit. #151983
• [3.15] gh-119710: fix asyncio Process.wait() to finish on process exit and not wait for closing of pipes (GH-151983) #154170
• [3.14] gh-119710: fix asyncio Process.wait() to finish on process exit and not wait for closing of pipes (GH-151983) #154171
• [3.13] gh-119710: fix asyncio Process.wait() to finish on process exit and not wait for closing of pipes (GH-151983) #154172

[vstinner]

It's a surprising feature. communicate() waits until stdout (and stderr) is closed. If a child process spawns "sleep 20", the "sleep 20" inherits stdout and keeps it open for 20 seconds.

Maybe you should create a new process group and kill the whole process group, rather than only killing the "parent" process (parent of "sleep 20"). See the start_new_session parameter of subprocess.Popen and then use os.killpg().

That's what I did in test.libregrtest to make sure that CTRL+C kills immediately all processes, and not only direct child processes.

[piwicode]

Indeed the process groups can help, if the child process does not create another process group. But that is another story. Here my point is that we should clarify The documentation ton avoid any surprise. The same behavior applies to proc.wait(). For the record, the crurent documentation says "Wait for child process to terminate" which looks missleading to me.

[vstinner]

wait() and communicate() are very different.

[piwicode]

Indeed. This issue is about proc.wait() documentation. I updated the code snippet to male it clearer.

[benzea]

I really consider this a pretty bad bug. It is absolutely impossible to wait for the executed process. I specifically wanted to wait for the launched process and not the pipe to be closed. Unfortunately, with the current API that is pretty much impossible.

There is not even a timeout= parameter for wait(), so I am now resorting to having a second task that specifically closes the pipe using proc.stdout._transport._protocol.pipe.close() (after killing the process just in case). I consider this a really nasty workaround, as I just need to wait for the process to quit. However, adding a second child watch is also not really possible …

Considering we have the mess, maybe one could:

1. Properly document the wait() behaviour
2. Fix Process.wait() to not immediately return if the process already quit (BaseSubprocessTransport._wait needs to test self._finished not self._returncode to be consistent)
3. Add a Process.waitpid() function with the expected behaviour that does not wait for the pipes to be closed
4. Maybe add a close() function that can be used to explicitly close all pipes. Though I suppose that will happen anyway when the object is deleted.

[tapetersen]

I've dug around and the bug seems to be a race condition depending on if proc.wait() was called before or after the process exited and could set its returncode.

import asyncio
import sys
async def main1():
 proc = await asyncio.create_subprocess_exec(
 sys.executable, "-c", "import os;os.system('sleep 5')",
 stdout=asyncio.subprocess.PIPE,
 stderr=asyncio.subprocess.PIPE)

 await asyncio.sleep(0.5)

 proc.kill()
 await asyncio.wait_for(proc.wait(), 2.0)

async def main2():
 proc = await asyncio.create_subprocess_exec(
 sys.executable, "-c", "import os;os.system('sleep 5')",
 stdout=asyncio.subprocess.PIPE,
 stderr=asyncio.subprocess.PIPE)

 await asyncio.sleep(0.5)

 proc.kill()
 while proc.returncode is None:
 await asyncio.sleep(0.1)
 await asyncio.wait_for(proc.wait(), 2.0)

try:
 asyncio.run(main1())
 print("main1 finished")

except asyncio.TimeoutError:
 print("main1 Timed out")

try:
 asyncio.run(main2())
 print("main2 finished")

except asyncio.TimeoutError:
 print("main2 Timed out")

When run gives:

$python test_asyncio_sub.py
main1 Timed out
main2 finished
Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7e6b57e227a0>
Traceback (most recent call last):
 ... # <snip>
 raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7e6b57e227a0>
Traceback (most recent call last):
 ... # <snip>
 raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed

I've checked relevant issues and changes and it seems to boil down to #32073 replacing the notifying of blocked waiters from BaseSubprocessTransport._process_exited with instead closing pipes and delaying notifying readers when the closed pipes eventually leads to the connection_lost callback being triggered.

The pipe-closing was then removed by https://github.com/python/cpython/pull/100154/changes since it led to lost output but didn't re-instate the wakeups.

I've tried simply re-instating the wake-ups in _process_exited (with minor tweaks and confirmed it solves the above as well as allows the rest of the test-suite to still pass (on linux at least)