This issue tracker has been migrated to GitHub, and is currently read-only.
For more information, see the GitHub FAQs in the Python's Developer Guide.

Author kyleam
Recipients Yaroslav.Halchenko, asvetlov, kyleam, yselivanov
Date 2020-08-27.11:23:43
SpamBayes Score -1.0
Marked as misclassified Yes
Message-id <1598527424.43.0.494817679442.issue41594@roundup.psfhosted.org>
In-reply-to
Content
I should have thought to provide the output of when debug=True is
passed to asyncio.run().  Here it is, with the python on my Debian
system:

    $ python3 -V
    Python 3.7.3
    
    $ python3 reproducer.py
    Iteration:   1 of 100
    Failed on iteration 1
    logfile: /tmp/asyncio-debug-rqfsxyth.log
    
    $ cat /tmp/asyncio-debug-rqfsxyth.log 
    DEBUG: Starting iteration 1
    DEBUG: Using selector: EpollSelector
    DEBUG: execute program 'printf' stdout=<pipe>
    DEBUG: process 'printf' created: pid 20488
    DEBUG: process 20488 exited with returncode 0
    INFO: <_UnixSubprocessTransport pid=20488 running> exited with return code 0
    DEBUG: Read pipe 8 connected: (<_UnixReadPipeTransport fd=8 polling>, <ReadSubprocessPipeProto fd=1 pipe=<_UnixReadPipeTransport fd=8 polling>>)
    DEBUG: process_exited() called
    INFO: execute program 'printf': <_UnixSubprocessTransport pid=20488 returncode=0 stdout=<_UnixReadPipeTransport fd=8 polling>>
    DEBUG: pipe_data_received(): fd=1, data=b'ok'
    DEBUG: Close <_UnixSelectorEventLoop running=False closed=False debug=True>
    DEBUG: Failed on iteration 1

And with a python built from a recent commit (8e19c8be8701):

    $ python -V
    Python 3.10.0a0
    
    $ python reproducer.py
    Iteration:   1 of 100
    Failed on iteration 1
    logfile: /tmp/asyncio-debug-9eyhuas4.log
    
    $ cat /tmp/asyncio-debug-9eyhuas4.log 
    DEBUG: Starting iteration 1
    DEBUG: Using selector: EpollSelector
    DEBUG: execute program 'printf' stdout=<pipe>
    DEBUG: process 'printf' created: pid 20524
    DEBUG: process 20524 exited with returncode 0
    INFO: <_UnixSubprocessTransport pid=20524 running> exited with return code 0
    DEBUG: Read pipe 8 connected: (<_UnixReadPipeTransport fd=8 polling>, <ReadSubprocessPipeProto fd=1 pipe=<_UnixReadPipeTransport fd=8 polling>>)
    DEBUG: process_exited() called
    INFO: execute program 'printf': <_UnixSubprocessTransport pid=20524 returncode=0 stdout=<_UnixReadPipeTransport fd=8 polling>>
    DEBUG: pipe_data_received(): fd=1, data=b'ok'
    DEBUG: Close <_UnixSelectorEventLoop running=False closed=False debug=True>
    DEBUG: Failed on iteration 1

---

It looks like I can work around the issue (i.e. I don't observe any
lost output) by adding this line to the attached script:

    diff --git a/reproducer.py b/reproducer.py
    index 5e04c36..a462898 100644
    --- a/reproducer.py
    +++ b/reproducer.py
    @@ -25,6 +25,7 @@ async def get_stdout():
         transport, protocol = await loop.subprocess_exec(
             lambda: Protocol(exit_future),
             "printf", "ok", stdin=None, stderr=None)
    +    await asyncio.ensure_future(transport._wait())
         await exit_future
         transport.close()
         return bytes(protocol.output)
History
Date User Action Args
2020-08-27 11:23:44kyleamsetrecipients: + kyleam, asvetlov, Yaroslav.Halchenko, yselivanov
2020-08-27 11:23:44kyleamsetmessageid: <1598527424.43.0.494817679442.issue41594@roundup.psfhosted.org>
2020-08-27 11:23:44kyleamlinkissue41594 messages
2020-08-27 11:23:43kyleamcreate