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, asvetlov, koobs, miss-islington, pablogsal, stefan, sth, xtreak, yselivanov
Priority: normal Keywords: patch

Created on 2018-12-30 22:59 by sth, last changed 2019-07-18 17:58 by Tim Froehlich. 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 (15)
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 triager) 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 triager) 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.
History
Date User Action Args
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