asyncio subprocess stdout occasionally lost (3.11.0 → 3.11.1 regression)

Bug report

So, I've updated python from 3.11.0 to 3.11.1 and one of my utilities which runs a lot of external processes with asyncio.create_subprocess_exec started failing in different places in weird ways. It turned out that with some probability asyncio.subprocess.Process.communicate() would now return an empty stdout. Here's a repro:

import asyncio

async def main():
    attempt = 1
    while True:
        proc = await asyncio.create_subprocess_exec('/bin/echo', 'test', stdout=asyncio.subprocess.PIPE, stderr=asyncio.subprocess.PIPE)

        stdout, stderr = await proc.communicate()

        text = stdout.decode('utf-8').strip()

        if text != 'test':
            raise RuntimeError(f'FAIL on attempt {attempt}: output="{text}"')

        attempt += 1

asyncio.run(main())

You may have to wait somewhat for the problem to reproduce, but for me it fails in under 15 seconds more or less reliably. Possible output:

RuntimeError: FAIL on attempt 3823: output=""

Your environment

CPython versions tested on: 3.11.1
Operating system and architecture: FreeBSD 13.1 amd64

Linked PRs

@kumaraditya303

@kumaraditya303 FYI, there were some commits to asyncio subprocess from you recently.

I experienced this too, reported it here with some additional info:
https://discuss.python.org/t/python-3-11-1-async-subprocess-stdout-lost-when-piped/21788

For me, the following script always results with an unexpected [b'', b'', b'baz\n'] both in Python 3.11.1 and 3.12.0a3.

import asyncio


async def get_command_stdout(cmd, *args):
    proc = await asyncio.create_subprocess_exec(
        cmd, *args, stdout=asyncio.subprocess.PIPE,
    )
    stdout, _ = await proc.communicate()
    return stdout


async def main():
    return await asyncio.gather(
        get_command_stdout('echo', 'foo'),
        get_command_stdout('echo', 'bar'),
        get_command_stdout('echo', 'baz'),
    )


if __name__ == '__main__':
    print(asyncio.run(main()))

Let’s bisect that repro to a specific commit.

The bisection points to

commit 7015e1379791cbf19908cd1a7c668a5d6e7165d5
Date:   Wed Oct 5 10:15:31 2022

    gh-88050: Fix asyncio subprocess to kill process cleanly when process is blocked (#32073)

We will get it fixed in 3.11.2.

@AMDmi3

Thanks for the bug report, I have a fix for this #100154, can you verify it that it works as you expect? Thanks @AMDmi3

The fix works for me, thank you!

GH-100133: fix `asyncio` subprocess losing `stderr` and `stdout` outp…

pythonGH-100133: fix `asyncio` subprocess losing `stderr` and `stdout…

GH-100133: fix `asyncio` subprocess losing `stderr` and `stdout` outp…

lang/python311: fix asyncio.subprocess regression

Merged main into regmachine branch (#50)

00395: pythonGH-100133: fix `asyncio` subprocess losing `stderr` and …

Add tests for tracing down the issue with bluetoothctl version

lang/python311: fix asyncio.subprocess regression

Navigation Menu

Repository navigation

asyncio subprocess stdout occasionally lost (3.11.0 → 3.11.1 regression) #100133

Bug report

Your environment

Linked PRs

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

asyncio subprocess stdout occasionally lost (3.11.0 → 3.11.1 regression) #100133

Description

Bug report

Your environment

Linked PRs

Activity

AMDmi3 commented on Dec 9, 2022

mportesdev commented on Dec 9, 2022

mportesdev commented on Dec 9, 2022

gvanrossum commented on Dec 9, 2022

gvanrossum commented on Dec 12, 2022

kumaraditya303 commented on Dec 12, 2022

AMDmi3 commented on Dec 12, 2022

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions