.github/scripts/run_with_env_secrets.py doesn't properly stream output as it executes

[ezyang]

Evidence:

Look at some logs:

2024-08-21T12:48:16.2401317Z ++ export CONDA_PREFIX=/opt/conda/envs/py_3.9
2024-08-21T12:48:16.2401776Z ++ CONDA_PREFIX=/opt/conda/envs/py_3.9
2024-08-21T12:48:16.2402163Z ++ export CONDA_SHLVL=2
2024-08-21T12:48:16.2402476Z ++ CONDA_SHLVL=2
2024-08-21T12:48:16.2402784Z ++ export CONDA_DEFAULT_ENV=py_3.9
2024-08-21T12:48:16.2403157Z ++ CONDA_DEFAULT_ENV=py_3.9
2024-08-21T12:48:16.2403595Z ++ export 'CONDA_PROMPT_MODIFIER=(py_3.9) '
2024-08-21T12:48:16.2404097Z ++ CONDA_PROMPT_MODIFIER='(py_3.9) '
2024-08-21T12:48:16.2404495Z ++ export CONDA_PREFIX_1=/opt/conda
2024-08-21T12:48:16.2404885Z ++ CONDA_PREFIX_1=/opt/conda
2024-08-21T13:01:26.0449789Z ++ export CONDA_EXE=/opt/conda/bin/conda
2024-08-21T13:01:26.0450341Z ++ CONDA_EXE=/opt/conda/bin/conda
2024-08-21T13:01:26.0452960Z ++ export _CE_M=
2024-08-21T13:01:26.0453413Z ++ _CE_M=
2024-08-21T13:01:26.0453841Z ++ export _CE_CONDA=
2024-08-21T13:01:26.0455084Z ++ _CE_CONDA=
2024-08-21T13:01:26.0455635Z ++ export CONDA_PYTHON_EXE=/opt/conda/bin/python
2024-08-21T13:01:26.0456564Z ++ CONDA_PYTHON_EXE=/opt/conda/bin/python
2024-08-21T13:01:26.0457073Z + __conda_hashr
2024-08-21T13:01:26.0467977Z + '[' -n '' ']'
2024-08-21T13:01:26.0468304Z + '[' -n '' ']'
2024-08-21T13:01:26.0468587Z + hash -r
2024-08-21T13:01:26.0476585Z + python3 -m pip install uv==0.1.45
2024-08-21T13:01:26.0476975Z Collecting uv==0.1.45
2024-08-21T13:01:26.0485632Z   Downloading uv-0.1.45-py3-none-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (32 kB)
2024-08-21T13:01:26.0486750Z Downloading uv-0.1.45-py3-none-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (12.8 MB)
2024-08-21T13:01:26.0489178Z �[?25l   �[90m━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━�[0m �[32m0.0/12.8 MB�[0m �[31m?�[0m eta �[36m-:--:--�[0m
2024-08-21T13:01:26.0494581Z �[2K   �[90m━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━

You can see there is a discontinuous jump from 12:48 to 13:01, indicating that buffer flushed.

I looked at the code. There are some suspicious things:

def run_cmd_or_die(cmd):
    print(f"Running command: {cmd}")
    p = subprocess.Popen(
        "/bin/bash",
        stdout=subprocess.PIPE,
        stdin=subprocess.PIPE,
        stderr=subprocess.STDOUT,
        bufsize=1,
        universal_newlines=True,
        errors="backslashreplace",
    )
    p.stdin.write("set -e\n")
    p.stdin.write(cmd)
    p.stdin.write("\nexit $?\n")
    p.stdin.close()

    result = ""
    while p.poll() is None:
        line = p.stdout.readline()
        if line:
            print(line, end="")
        result += line

    # Read any remaining output
    for line in p.stdout:
        print(line, end="")
        result += line

    exit_code = p.returncode
    if exit_code != 0:
        raise RuntimeError(f"Command {cmd} failed with exit code {exit_code}")
    return result

stderr is piped to stdout, which would potentially cause it to be block buffered. The prints are not to stderr, so they might also be block buffered. But also I like... I don't understand why you are doing any of this at all? Like, you're not even doing anything with the result of the second docker exec call, why bother with the log tailer nonsense?

cc @huydhn @lucylq