asyncio subprocess stdout occasionally lost (3.11.0 → 3.11.1 regression)

[AMDmi3]

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

• GH-100133: fix asyncio subprocess losing stderr and stdout output #100154
• [3.11] GH-100133: fix asyncio subprocess losing stderr and stdout output (GH-100154) #100398

[AMDmi3]

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

[mportesdev]

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

[mportesdev]

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()))

[gvanrossum]

Let’s bisect that repro to a specific commit.

[gvanrossum]

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.

[kumaraditya303]

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

[AMDmi3]

The fix works for me, thank you!