classification
Title: asyncio.create_subprocess_exec() only works with main event loop
Type: behavior Stage: resolved
Components: asyncio Versions: Python 3.9, Python 3.8
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: Tim Froehlich, adefossez, aeros, asvetlov, koobs, miss-islington, pablogsal, rojer, stefan, sth, xtreak, yselivanov
Priority: normal Keywords: patch

Created on 2018-12-30 22:59 by sth, last changed 2020-05-30 02:49 by aeros. This issue is now closed.

Files
File name Uploaded Description Edit
koobs-freebsd-10-non-debug-3x-build-1170.txt koobs, 2019-06-02 12:37
Pull Requests
URL Status Linked Edit
PR 13630 merged asvetlov, 2019-05-28 16:05
PR 13754 merged asvetlov, 2019-06-02 21:18
PR 13793 merged asvetlov, 2019-06-03 23:50
PR 14344 merged asvetlov, 2019-06-24 15:30
PR 14484 merged miss-islington, 2019-06-30 09:55
Messages (17)
msg332771 - (view) Author: Stephan Hohe (sth) * Date: 2018-12-30 22:59
`asyncio.create_subprocess_exec()` accepts a `loop` parameter, but doesn't use it to watch the child process. Instead uses `get_event_loop_policy().get_child_watcher()`, which doesn't doesn't know about `loop` but tries to use the current default event loop.

This fails if there is no current event loop or if that loop isn't running:

```
import asyncio

async def action(loop):
    proc = await asyncio.create_subprocess_exec('echo', loop=loop)
    await proc.wait()

loop = asyncio.new_event_loop()
loop.run_until_complete(action(loop))
loop.close()
```

This crashes because the main event loop never was created:

Traceback (most recent call last):
  File "sample.py", line 8, in <module>
    loop.run_until_complete(action(loop))
  File "/home/sth/devel/cpython.vanilla/Lib/asyncio/base_events.py", line 589, in run_until_complete
    return future.result()
  File "sample.py", line 4, in action
    proc = await asyncio.create_subprocess_exec('echo', loop=loop)
  File "/home/sth/devel/cpython.vanilla/Lib/asyncio/subprocess.py", line 213, in create_subprocess_exec
    transport, protocol = await loop.subprocess_exec(
  File "/home/sth/devel/cpython.vanilla/Lib/asyncio/base_events.py", line 1542, in subprocess_exec
    transport = await self._make_subprocess_transport(
  File "/home/sth/devel/cpython.vanilla/Lib/asyncio/unix_events.py", line 193, in _make_subprocess_transport
    watcher.add_child_handler(transp.get_pid(),
  File "/home/sth/devel/cpython.vanilla/Lib/asyncio/unix_events.py", line 924, in add_child_handler
    raise RuntimeError(
RuntimeError: Cannot add child handler, the child watcher does not have a loop attached


If we do have a current event loop, for example by calling `asyncio.get_event_loop()` before creating out own loop, then we don't get an error, but the program hangs indefinitely since that loop isn't running.

Expected behavior would be that the loop given to create_subprocess_exec() is used to watch the child process.
msg334298 - (view) Author: Alexandre Défossez (adefossez) * Date: 2019-01-24 12:31
Also impacted.

A fix I found is to add `watcher.attach_loop(self)` just after `with events.get_child_watcher() as watcher:` in `_make_subprocess_transport` in `asyncio/unix_events.py`.
msg344270 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2019-06-02 10:56
New changeset 13ed07998ad93dbdd94991ba0451b9b559f07972 by Andrew Svetlov in branch 'master':
bpo-35621: Support running subprocesses in asyncio when loop is executed in non-main thread (#13630)
https://github.com/python/cpython/commit/13ed07998ad93dbdd94991ba0451b9b559f07972
msg344284 - (view) Author: Kubilay Kocak (koobs) (Python triager) Date: 2019-06-02 12:37
New buildbot failure on koobs-freebsd10 that appears related to (includes) this changeset

Full log attached
msg344305 - (view) Author: Karthikeyan Singaravelan (xtreak) * (Python committer) Date: 2019-06-02 19:42
Also seems to occur on Ubuntu : https://buildbot.python.org/all/#/builders/141/builds/1912/steps/5/logs/stdio

karthi@ubuntu-s-1vcpu-1gb-blr1-01:~/cpython$ ./python -m unittest test.test_asyncio.test_unix_events
...................Exception in thread Thread-1:
Traceback (most recent call last):
  File "/home/karthi/cpython/Lib/threading.py", line 923, in _bootstrap_inner
    self.run()
  File "/home/karthi/cpython/Lib/threading.py", line 865, in run
    self._target(*self._args, **self._kwargs)
  File "/home/karthi/cpython/Lib/test/test_asyncio/test_unix_events.py", line 1833, in f
    self.assertIsInstance(watcher, asyncio.SafeChildWatcher)
  File "/home/karthi/cpython/Lib/unittest/case.py", line 1330, in assertIsInstance
    self.fail(self._formatMessage(msg, standardMsg))
  File "/home/karthi/cpython/Lib/unittest/case.py", line 748, in fail
    raise self.failureException(msg)
AssertionError: <asyncio.unix_events.ThreadedChildWatcher object at 0x7f00b357d640> is not an instance of <class 'asyncio.unix_events.SafeChildWatcher'>
../home/karthi/cpython/Lib/asyncio/base_events.py:646: ResourceWarning: unclosed event loop <_UnixSelectorEventLoop running=False closed=False debug=False>
  _warn(f"unclosed event loop {self!r}", ResourceWarning, source=self)
ResourceWarning: Enable tracemalloc to get the object allocation traceback
...............................................................................................
----------------------------------------------------------------------
Ran 116 tests in 1.391s

OK
msg344307 - (view) Author: Karthikeyan Singaravelan (xtreak) * (Python committer) Date: 2019-06-02 20:17
It seems the assertion has to use ThreadedChildWatcher instead of SafeChildWatcher as the default seems to be changed at [0] . If changing assertion fixes the test I am curious why it didn't fail in the primary CI.


[0] https://github.com/python/cpython/commit/13ed07998ad93dbdd94991ba0451b9b559f07972#diff-8441007d39090aec5e09dbfcfa9973b7R1299
msg344313 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2019-06-02 20:42
I cannot reproduce this issue locally :(
msg344314 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2019-06-02 20:45
When I ran the tests, the watcher I get is a SafeChildWatcher
msg344321 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2019-06-02 21:20
Thanks for the report!

The failure depends on tests order execution (maybe you use -jN flag?).
Before default child watcher was SafeChildWatcher, not it is ThreaderChildWather.
The watcher is a global variable (a property of global event loop policy).

The failed test doesn't make sense for default ThreadChildWatcher but still valuable for old default SafeChildWatcher.
I've changed the test to use SafeChildWatcher explicitly.

See https://github.com/python/cpython/pull/13754 for the fix
msg344322 - (view) Author: Pablo Galindo Salgado (pablogsal) * (Python committer) Date: 2019-06-02 21:25
> The failure depends on tests order execution (maybe you use -jN flag?).

Oh, I understand now!

> See https://github.com/python/cpython/pull/13754 for the fix

Thanks for the fix, Andrew! :)
msg344331 - (view) Author: miss-islington (miss-islington) Date: 2019-06-02 22:45
New changeset c6789d6c85a290a35f3839efb52a3d34536dcebe by Miss Islington (bot) (Andrew Svetlov) in branch 'master':
bpo-35621: Fix tests when SafeChildWatcher is expected instead of ThreadedChildWatcher (GH-13754)
https://github.com/python/cpython/commit/c6789d6c85a290a35f3839efb52a3d34536dcebe
msg344500 - (view) Author: miss-islington (miss-islington) Date: 2019-06-04 00:09
New changeset 9535aff9421f0a5639f6e4c4bb0f07a743ea8dba by Miss Islington (bot) (Andrew Svetlov) in branch 'master':
Revert "bpo-35621: Support running subprocesses in asyncio when loop is executed in non-main thread (#13630)" (GH-13793)
https://github.com/python/cpython/commit/9535aff9421f0a5639f6e4c4bb0f07a743ea8dba
msg346924 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2019-06-30 09:55
New changeset 0d671c04c39b52e44597491b893eb0b6c86b3d45 by Andrew Svetlov in branch 'master':
bpo-35621: Support running subprocesses in asyncio when loop is executed in non-main thread  (GH-14344)
https://github.com/python/cpython/commit/0d671c04c39b52e44597491b893eb0b6c86b3d45
msg346925 - (view) Author: miss-islington (miss-islington) Date: 2019-06-30 10:22
New changeset bf8cb31803558f1105efb15b0ee4bd184f3218c8 by Miss Islington (bot) in branch '3.8':
bpo-35621: Support running subprocesses in asyncio when loop is executed in non-main thread  (GH-14344)
https://github.com/python/cpython/commit/bf8cb31803558f1105efb15b0ee4bd184f3218c8
msg348122 - (view) Author: Tim Froehlich (Tim Froehlich) Date: 2019-07-18 17:58
Is it possible to amend the documentation (https://docs.python.org/3.5/library/asyncio-subprocess.html, etc) to include a note that the loop parameter doesn't work? I'm impacted by this bug and lost a few hours to it.
msg370297 - (view) Author: Deomid Ryabkov (rojer) Date: 2020-05-29 11:17
is there a workaround for earlier Python versions that does not involve patching the standard library?
msg370355 - (view) Author: Kyle Stanley (aeros) * (Python committer) Date: 2020-05-30 02:49
> is there a workaround for earlier Python versions that does not involve patching the standard library?

You could potentially try using the new default watcher, `ThreadedChildWatcher`, by implementing it locally and setting it as the child watcher to use (instead of `SafeChildWatcher`) with `set_child_watcher()`. AFAICT, the current implementation should work well for earlier versions of Python that don't have it, we just can't include it earlier than 3.8 since it's a new feature.

See https://github.com/python/cpython/blob/4649202ea75d48e1496e99911709824ca2d3170e/Lib/asyncio/unix_events.py#L1326 for reference.
History
Date User Action Args
2020-05-30 02:49:41aerossetnosy: + aeros
messages: + msg370355
2020-05-29 11:17:53rojersetnosy: + rojer
messages: + msg370297
2019-07-18 17:58:26Tim Froehlichsetnosy: + Tim Froehlich
messages: + msg348122
2019-06-30 10:22:38miss-islingtonsetmessages: + msg346925
2019-06-30 09:56:09asvetlovsetstatus: open -> closed
stage: patch review -> resolved
resolution: fixed
versions: + Python 3.9, - Python 3.6, Python 3.7
2019-06-30 09:55:15miss-islingtonsetpull_requests: + pull_request14301
2019-06-30 09:55:07asvetlovsetmessages: + msg346924
2019-06-24 15:30:16asvetlovsetpull_requests: + pull_request14164
2019-06-04 00:09:22miss-islingtonsetmessages: + msg344500
2019-06-03 23:50:01asvetlovsetpull_requests: + pull_request13678
2019-06-02 22:45:56miss-islingtonsetnosy: + miss-islington
messages: + msg344331
2019-06-02 21:25:09pablogsalsetmessages: + msg344322
2019-06-02 21:20:11asvetlovsetmessages: + msg344321
2019-06-02 21:18:37asvetlovsetstage: resolved -> patch review
pull_requests: + pull_request13635
2019-06-02 20:45:08pablogsalsetmessages: + msg344314
2019-06-02 20:42:45pablogsalsetmessages: + msg344313
2019-06-02 20:17:16xtreaksetmessages: + msg344307
2019-06-02 19:42:56xtreaksetnosy: + xtreak, pablogsal
messages: + msg344305
2019-06-02 12:38:10koobssetstatus: closed -> open
resolution: fixed -> (no value)
2019-06-02 12:37:53koobssetfiles: + koobs-freebsd-10-non-debug-3x-build-1170.txt
nosy: + koobs
messages: + msg344284

2019-06-02 11:16:29asvetlovlinkissue32115 superseder
2019-06-02 11:01:50asvetlovlinkissue35635 superseder
2019-06-02 10:57:09asvetlovsetstatus: open -> closed
resolution: fixed
stage: patch review -> resolved
2019-06-02 10:56:41asvetlovsetmessages: + msg344270
2019-05-28 16:05:23asvetlovsetkeywords: + patch
stage: patch review
pull_requests: + pull_request13530
2019-01-24 12:31:10adefossezsetnosy: + adefossez
messages: + msg334298
2019-01-01 23:59:32stefansetnosy: + stefan
2018-12-30 22:59:38sthcreate