Skip to content

asyncio warnings and errors triggered by stressful code #109490

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
shoffmeister opened this issue Sep 16, 2023 · 3 comments
Closed

asyncio warnings and errors triggered by stressful code #109490

shoffmeister opened this issue Sep 16, 2023 · 3 comments
Labels
topic-asyncio type-bug An unexpected behavior, bug, or error

Comments

@shoffmeister
Copy link

shoffmeister commented Sep 16, 2023

Bug report

Bug description:

Running the code below yields many lines of unwanted error output of the kind

Loop <_UnixSelectorEventLoop running=False closed=True debug=False> that handles pid 842379 is closed

and also runtime exceptions after all user code has completed of the kind

Exception ignored in: <function BaseSubprocessTransport.__del__ at 0x7f9558756340>
Traceback (most recent call last):
  File "/usr/lib64/python3.11/asyncio/base_subprocess.py", line 126, in __del__
    self.close()
  File "/usr/lib64/python3.11/asyncio/base_subprocess.py", line 104, in close
    proto.pipe.close()
  File "/usr/lib64/python3.11/asyncio/unix_events.py", line 566, in close
    self._close(None)
  File "/usr/lib64/python3.11/asyncio/unix_events.py", line 590, in _close
    self._loop.call_soon(self._call_connection_lost, exc)
  File "/usr/lib64/python3.11/asyncio/base_events.py", line 761, in call_soon
    self._check_closed()
  File "/usr/lib64/python3.11/asyncio/base_events.py", line 519, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed

This apparently is caused by having asyncio.wait_for with a TIMEOUT_SECS at an absurdly low value - which is that low to be able to reliably provoke the problem - IOW, this misbehaviour seems to depend on timeout errors being raised.

Of particular note is the time.sleep(2) at the end which I use to delay process termination; this makes the problem visible on stderr. Note that the exit code of the Python process is always 0 (watch --errexit --interval=0 python debugger-bug.py).

The implementation is cobbled together from an example in the Python documentation (with fixes applied) and from StackOverflow for throttling best practices with a Semaphore.

I am running this on Fedora Linux 38, Python 3.11.5, on an Intel 11800H CPU, lots of memory spare, within VMware Workstation.

import asyncio
import sys
import time

TASK_COUNT: int = 50
TASK_THROTTLE_COUNT: int = 7

TIMEOUT_SECS: float = 0.00001


async def get_date(i: int) -> str:
    # print(f"Starting task #{i}")

    code = "import datetime; print(datetime.datetime.now())"

    proc = await asyncio.create_subprocess_exec(
        sys.executable, "-c", code, stdout=asyncio.subprocess.PIPE
    )

    try:
        stdout, _ = await asyncio.wait_for(proc.communicate(), TIMEOUT_SECS)
    except asyncio.TimeoutError:
        return "TIMEOUT"

    line = stdout.decode("ascii").rstrip()

    # Wait for the subprocess exit.
    await proc.wait()
    return line


async def throttled_get_date(sem: asyncio.Semaphore, i: int):
    async with sem:  # semaphore limits num of simultaneous downloads
        return await get_date(i)


async def run_throttled():
    sem = asyncio.Semaphore(TASK_THROTTLE_COUNT)

    tasks = [asyncio.create_task(throttled_get_date(sem, i)) for i in range(TASK_COUNT)]

    return await asyncio.gather(*tasks)


async def run_unthrottled():
    tasks = [asyncio.create_task(get_date(i)) for i in range(TASK_COUNT)]
    return await asyncio.gather(*tasks)


def shell_to_get_date():

    start = time.time()
    date = asyncio.run(run_throttled())
    duration = time.time() - start

    print(f"Current dates: {date} - {duration} secs")
    if len(date) != TASK_COUNT:
        raise Exception


if __name__ == "__main__":
    shell_to_get_date()
    print("done")
    time.sleep(2)

CPython versions tested on:

3.11

Operating systems tested on:

Linux

@shoffmeister shoffmeister added the type-bug An unexpected behavior, bug, or error label Sep 16, 2023
@github-project-automation github-project-automation bot moved this to Todo in asyncio Sep 16, 2023
@sorcio
Copy link
Contributor

sorcio commented Sep 16, 2023

The warning is confusing because it doesn't clearly point to the issue. Here's a simpler snippet that will reproduce the messages you see:

async def main():
    await asyncio.create_subprocess_exec("sleep", "0.1", stdin=asyncio.subprocess.PIPE)
    # subprocess is not awaited on nor terminated

asyncio.run(main())
time.sleep(0.5)

This code, just like yours, is launching a process and then forgetting about it. In your case, it's the early return on timeout that causes this. You have to decide what to do with the process you have created. Python doesn't really have an option to forget about a process and let it run in background till the end, because it would be incorrect in most cases. So you might either wait for the process to exit (like in the example you copied from), or make it exit. For example by terminating or killing it, but you might have other options to request a clean shutdown.

You probably saw a number of ResourceWarning: subprocess nnn is still running in the output. These are supposed to be informative enough to let you know of the error. I guess Python could do better at reporting this. The RuntimeError can also be avoided probably.

@shoffmeister
Copy link
Author

shoffmeister commented Sep 17, 2023

Indeed, there is a defect in my example code - thank you for pointing this out! This makes this bug report here invalid.

But then ... ;)

In my original code I never got ResourceWarning: subprocess nnn is still running, neither on the command-line nor inside the Visual Studio Code Python debugger.

Python doesn't really have an option to forget about a process and let it run in background till the end, because it would be incorrect in most cases.

I have now tried implementing a robust way to clean up on a process taking "too much of a time to complete" and noticed a few things:

  • the documentation for the various asyncio ways to create subprocesses does not mention that those subprocesses should be gone (awaited or terminated or killed) by the time the Python program ends - the warnings (whenever they come) come as a bit of surprise

  • asyncio.wait_for(process.wait(), PROVOCATIVELY_LOW_TIMEOUT) causes (other) strange errors coming out of the runtime later on - and it really seems prudent calling .wait() with a timeout as otherwise it could (theoretically) block forever

  • as you allude above, there is no .abandon() or .forget()method on asyncio.subprocess.Process (https://docs.python.org/3/library/asyncio-subprocess.html), next to .terminate() and .kill(). Such a method would simply drop the reference to the subprocess (for instance closing open process handles or dropping the PID). Sometimes abandoning might be the right solution, leaving a subprocess zombie around?

  • having async with asyncio.create_subprocess_exec() as proc: support could be an ergonomic way to enforce .wait()?

I have arrived at

    proc = await asyncio.create_subprocess_exec(
    try:
        stdout, _ = await asyncio.wait_for(proc.communicate(), TIMEOUT_SECS)
        ...
    except asyncio.TimeoutError:
        ...
        proc.kill()  # rudely turn off the lights

    exit_code = await proc.wait()

for now, but may like (the non-existing) proc.abandon() better. The above snippet also lacks try/finally to really hit .wait(), FWIW. That's a lot of boilerplate to "just" safely run a process in async mode.

@sorcio
Copy link
Contributor

sorcio commented Sep 18, 2023

I think the bug report still has value because the RuntimeError is probably an issue, because finalization is not done correctly after the loop is closed.

The warning from ThreadedChildWatcher ("Loop ... that handles pid ... is closed") is also a bit dubious because it provides little actionable information to users.

(Note I'm not a CPython maintainer. I'm just a contributor who happened to look into the same code paths recently)


Note to myself or whoever is gonna investigate this: the child watcher holds a strong reference to the subprocess transport, so I think the destructor is never going to be called before the process has actually exited. Whatever the intention was with killing the process on __del__, I'm not sure it's respected, at least on Unix. Maybe it's for cleanup on shutdown?


@shoffmeister

In my original code I never got ResourceWarning: subprocess nnn is still running

Right, sorry. These warnings are ignored by default and you can run with python -Wdefault or similar to see them.

the documentation for the various asyncio ways to create subprocesses does not mention that those subprocesses should be gone (awaited or terminated or killed) by the time the Python program ends

(More accurately: before any reference to the child process.) It could be informative to mention it in the docs in some way. subprocess.Popen mentions that the destructor emits a ResourceWarning if the process is still running, so something along the same lines maybe.

  • as you allude above, there is no .abandon() or .forget()method on asyncio.subprocess.Process (https://docs.python.org/3/library/asyncio-subprocess.html), next to .terminate() and .kill(). Such a method would simply drop the reference to the subprocess (for instance closing open process handles or dropping the PID). Sometimes abandoning might be the right solution, leaving a subprocess zombie around?

I think this is a niche use case that probably does not warrant support from the high-level API. It can still be done by using lower level APIs, e.g. subprocess.Popen() directly, but also loop.subprocess_exec(), suppressing warnings (which, again, are not shown by default). Still, why would you do that, given that it's pretty cheap to just monitor these processes and ensure they are disposed of correctly?

  • having async with asyncio.create_subprocess_exec() as proc: support could be an ergonomic way to enforce .wait()?

I don't mind the idea in general. An async context manager would have the same limitation in case the event loop is closed before the context is exited. And wait() might be problematic in interaction with pipes (see the warning in the docs) and it's unclear to me how it should behave on cancellation. An other idea might be a (non-async) context manager that calls terminate()/kill(), but I don't know if it would be helpful in support of the common use cases.

That's a lot of boilerplate to "just" safely run a process in async mode.

Adding a timeout to the execution of a child process is not something that generalizes well, though, because you need knowledge of the program you are executing. Is it safe to kill? Does it need a specific signal? Does it have a way to trigger clean shutdown? How safe is it to kill it during shutdown? When is it safe to close the pipes, and other shared resources? Monitoring processes usually takes same application-specific code.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
topic-asyncio type-bug An unexpected behavior, bug, or error
Projects
Status: Done
Development

No branches or pull requests

4 participants