qinghuan
← 回到知识探索

后端现场 / 可下载小项目

子进程只是在打印日志,为什么 wait 一直等不完?

用一个只输出有限字节的子进程,复现父进程等退出、子进程等管道空位;再同时读取两条输出管道,让同一程序正常结束。

展开本文目录
  1. 下载完整练习包
  2. 管道有容量,等待退出不会替你读取内容
  3. 固定输出总量,避免把实验变成无边界任务
  4. 同时处理两条管道,再等待子进程结束
  5. 输出内容、退出码和是否回收要分别记录
  6. 实际运行,核对两条输出长度与完整字节
  7. 换成 Java:waitFor 之外要同时读取两条输出
  8. 本次排查:方法返回了,还要核对是否真的读完整
  9. 输出很大时,改用受控保存方式
  10. 记住这三点
  11. 别把例子用过头
  12. 自己试一小步
  13. 查原始资料
开始前,会这些就够了
  • 知道一个程序可以启动另一个进程。
  • 能读懂 Python 函数、异常处理与字节串。
  • 允许本机 Python 启动同一脚本作为子进程,无第三方依赖。
  • 需要补基础时:先认识进程与文件资源
遇到不熟悉的词,先看这 1 个解释
管道
进程之间传递字节的一条有限容量通道。一方持续往里写,另一方不读取,通道装满后写入就可能等不到空位。
打开完整术语小抄 ↗

服务启动一个转换工具,并把它的标准输出和标准错误接到管道里。主程序决定先等工具退出,再统一读取日志。小文件时一直成功,输出一多却不动了:等待关系可能是主程序自己安排出来的。

这次子进程没有网络请求,也没有无限循环,只向两条管道各写一 MiB 内容。我们先让父进程不读,观察短等待超时,再开始读取;同一个子进程随后可以正常结束,输出也完整保留下来。

把例子带到自己的电脑上

下载完整练习包

需要 Python 3.10 或更新版本,无第三方依赖;制作时实测 Windows / Python 3.14.0。另附可选 Java 标准库版本,需 JDK 17 或更新版本;实测 JDK 17 与 21。下方命令运行基础 Python 标准库示例;可选对照的环境和命令见对应 README。下载 ZIP 后选择“全部提取”,进入能看到 README.md 的文件夹。

下载 ZIP · 14 个文件
包里有什么
  • demo.py:完整可运行示例
  • README.md:运行说明与独立练习
  • observed.stdout.txt:本次实际输出
  • verification.json:源码和产物验证记录
  • SHA256SUMS.txt:内容摘要
  • java/:Java 源码、中文 README、JDK 17/21 输出和验证记录
  • supplement-verification.json:附加实现的独立复跑记录

在这个文件夹打开 PowerShell,逐行运行

python --version
python -B demo.py

解压到独立练习文件夹,在含 demo.py 的目录打开终端运行。Windows本机两个自建Python子进程,有限stdout/stderr各1MiB,wait短超时、communicate排空与9项检查;未测试任意工具、无限日志或孙进程树 压缩包的 java/ 子目录另附 Java 标准库版本、中文 README、两份实测输出和验证记录;进入 java/ 后按 README 编译运行。

找不到命令或文件时,先按 README 检查环境和所在目录。文中标出的阅读时间只估算文章篇幅,安装环境和动手练习可按自己的节奏进行。

管道有容量,等待退出不会替你读取内容

管道可以理解为生产者与读取者之间的一段有限空间。子进程不断写入,父进程若不读取,空间可能装满。此时子进程的写入操作等待有人腾出位置,因而无法走到最后的退出步骤。

父进程同时卡在 wait,打算等子进程退出后才读取。于是形成一个具体的等待圈:父进程等退出,退出要先完成写入,写入又等父进程读取。调大等待时间不会改变这条依赖,只会让现象更晚被看见。

这与子进程计算慢是不同的诊断方向。首先检查你是否接走了 stdout 或 stderr,却没有安排持续读取;也不要从 CPU 使用率低直接跳到某个外部服务故障。

固定输出总量,避免把实验变成无边界任务

本脚本启动的始终是自己,命令参数用列表传递,shell=False。子分支先在临时目录写一个 ready 标记,再向 stdout 和 stderr 交替输出十六块,每块六万五千五百三十六字节。两条管道合计两 MiB,是明确的有限数据。

父进程等 ready 标记出现后才执行 0.25 秒的 wait 探针,以排除子程序根本还没走到输出阶段的情况。这个数字是实验的保护等待,不是生产超时建议,也不是对子进程速度的测量。

每次写入后都 flush,只是把用户态缓冲的影响减小,不能替父进程从管道取走数据。不要把“加了 flush”与“管道已经排空”当成同一个步骤。

同时处理两条管道,再等待子进程结束

短等待超时后,父进程改用 communicate。它会处理 stdout 和 stderr 的读取,并等待子进程退出。在这份有限输出实验中,两条结果都完整返回,子进程退出码为零;先前的 wait 超时没有自动杀死它。

第二次启动相同子进程时,直接使用 communicate,得到同样的两份字节内容。程序逐字节比较结果,既没有只看日志最后一行,也没有只验证“返回了非空字符串”。这样才能发现少读一段或只读其中一条的错误。

只先读完 stdout、再读 stderr 也未必安全:子进程可能正在往 stderr 写,等待那条管道腾出位置,而 stdout 的 EOF 又需要等它退出。这个程序交替写两条输出,正好提醒你处理的是两条独立通道。

输出内容、退出码和是否回收要分别记录

本例故意向 stderr 写字母 E,但正常退出码仍是零。标准错误是一个输出通道,不是“只要有任何字节就代表进程失败”的自动判定器。实际工具怎样报告错误,应以它自己的接口约定为准。

同样,wait 超时表示这次等待没有在期限内完成,不表示进程已被回收。脚本的 finally 会检查仍存活的自建子进程,必要时结束它,再完成通信和关闭管道;不会把等待超时当成清理完成。

这里没有子进程再创建孙进程,也没有需要提交的业务副作用。真实进程树、取消策略和产物完整性需要另做设计,不能仅复制一个 kill 调用就承诺所有后续工作都已停止。

实际运行,核对两条输出长度与完整字节

保存为 demo.py,执行 python -B demo.py。不要自己传 --child 参数,正常入口会创建临时标记并完成两次受控运行。在 Windows 上,程序使用隐藏子进程窗口的创建选项,不会弹出额外终端。

本次 Python 3.14.0、Windows 实跑中,先等待的路径确实超时,随后读出 stdout 与 stderr 各 1048576 字节;直接读取的路径得到相同结果。九项检查完成后才打印 children_reaped=True,临时目录也已经清理。

展开收起代码 · 小实验python · 89 行

长行可在代码区域内左右滚动,按 Tab 可把焦点移入代码区。

小实验 · python
"""Bounded child output; wait without reading versus communicate.

Only launches this same Python file. No shell, arbitrary command, or network.
"""
from pathlib import Path
from tempfile import TemporaryDirectory
import os
import subprocess
import sys
import time

BLOCK_SIZE = 65536
BLOCKS = 16


def child(marker):
    Path(marker).write_text("ready", encoding="ascii")
    for _ in range(BLOCKS):
        sys.stdout.buffer.write(b"O" * BLOCK_SIZE)
        sys.stdout.buffer.flush()
        sys.stderr.buffer.write(b"E" * BLOCK_SIZE)
        sys.stderr.buffer.flush()


def run_child(marker, wait_first):
    kwargs = {}
    if os.name == "nt":
        kwargs["creationflags"] = subprocess.CREATE_NO_WINDOW
    process = subprocess.Popen(
        [sys.executable, "-u", str(Path(__file__).resolve()), "--child", str(marker)],
        stdin=subprocess.DEVNULL, stdout=subprocess.PIPE, stderr=subprocess.PIPE,
        shell=False, **kwargs,
    )
    timed_out = False
    try:
        ready_deadline = time.monotonic() + 5
        while not marker.exists():
            if process.poll() is not None or time.monotonic() >= ready_deadline:
                raise RuntimeError("child did not reach the output stage")
            time.sleep(0.01)
        if wait_first:
            try:
                process.wait(timeout=0.25)
            except subprocess.TimeoutExpired:
                timed_out = True
        # This drains BOTH pipes while waiting for this finite child to exit.
        output, errors = process.communicate(timeout=5)
        return timed_out, output, errors, process.returncode
    finally:
        if process.poll() is None:
            process.kill()
            process.communicate(timeout=5)
        if process.stdout is not None:
            process.stdout.close()
        if process.stderr is not None:
            process.stderr.close()


def main():
    checks = 0

    def check(condition, message):
        nonlocal checks
        if not condition:
            raise AssertionError(message)
        checks += 1

    expected_size = BLOCK_SIZE * BLOCKS
    with TemporaryDirectory(prefix="qinghuan-pipes-") as folder:
        root = Path(folder)
        delayed = run_child(root / "first.ready", wait_first=True)
        direct = run_child(root / "second.ready", wait_first=False)
        check(delayed[0], "wait without reading should time out for this output size")
        check(not direct[0], "the direct path does not use the blocking wait probe")
        for label, (_, output, errors, code) in zip(("rescued", "direct"), (delayed, direct)):
            check(code == 0, f"{label}: child must exit normally after draining")
            check(output == b"O" * expected_size, f"{label}: stdout must be complete")
            check(errors == b"E" * expected_size, f"{label}: stderr must be complete")
            print(f"{label}: stdout={len(output)}; stderr={len(errors)}; exit={code}")
        check(delayed[1:3] == direct[1:3], "both paths must recover identical finite output")
        print("wait_before_drain=timeout; communicate_after_timeout=completed")
    print(f"PASS checks={checks}; children_reaped=True; temporary_files_cleaned=True")


if __name__ == "__main__":
    if len(sys.argv) == 3 and sys.argv[1] == "--child":
        child(sys.argv[2])
    else:
        main()

怎样运行:在独立练习文件夹中执行 python -B demo.py。2026-10-17 已在 Windows、Python 3.14.0 运行此份源码并通过自带检查。Windows本机两个自建Python子进程,有限stdout/stderr各1MiB,wait短超时、communicate排空与9项检查;未测试任意工具、无限日志或孙进程树

运行后对照结果
rescued: stdout=1048576; stderr=1048576; exit=0
direct: stdout=1048576; stderr=1048576; exit=0
wait_before_drain=timeout; communicate_after_timeout=completed
PASS checks=9; children_reaped=True; temporary_files_cleaned=True

换成 Java:waitFor 之外要同时读取两条输出

Java 的 Process.waitFor 也只等待进程结束。本例先让当前类作为子进程向 stdout 与 stderr 各写一 MiB;父进程只做一次短等待时返回 false,随后启动两个读取任务,分别消费 getInputStream 和 getErrorStream,子进程才能完成输出并正常退出。

这些流的名字从父进程角度命名:getInputStream 读到子进程的标准输出,getErrorStream 读到标准错误,getOutputStream 则写向子进程的标准输入。实验不需要输入,因此先关闭最后这一条流。两个任务都用 read(byte[]) 循环持续读取,并限制最多一 MiB;主线程先检查最早完成的读取任务,及时保留失败原因,随后逐字节比较两份输出、独立检查退出码。

Windows 分支使用当前 JDK 的 javaw.exe,由 ProcessBuilder 直接传参数启动自身,没有经过 shell。Java 标准 API 没有与 Python creationflags 一样的 CREATE_NO_WINDOW 设置项;此处通过无关联控制台窗口的启动器实现该需求。异常清理仍会结束存活子进程、等待退出、关闭流并回收读取线程。

保存为 SubprocessPipesDemo.java,按下方两条命令编译运行。Windows 的 JDK 17.0.20.1 与 21.0.12 各通过 9 项检查,stdout/stderr 都完整保留。示例仍把结果收集到内存,因此总量固定为两 MiB;没有测试无限日志或会创建孙进程的外部工具。

展开收起代码 · 小实验java · 174 行

长行可在代码区域内左右滚动,按 Tab 可把焦点移入代码区。

小实验 · java
import java.io.ByteArrayOutputStream;
import java.io.Closeable;
import java.io.IOException;
import java.io.InputStream;
import java.nio.file.Files;
import java.nio.file.Path;
import java.util.Arrays;
import java.util.concurrent.CompletionService;
import java.util.concurrent.ExecutorCompletionService;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.Future;
import java.util.concurrent.TimeUnit;

/** Starts only this class as a child, with finite stdout and stderr. */
public final class SubprocessPipesDemo {
    private static final int BLOCK_SIZE = 65536;
    private static final int BLOCKS = 16;
    private static int checks;

    private record Result(boolean waitTimedOut, byte[] stdout, byte[] stderr, int exit) {}
    private record Captured(String channel, byte[] bytes) {}

    private static void check(boolean condition, String message) {
        if (!condition) throw new AssertionError(message);
        checks++;
    }

    private static byte[] repeated(byte value, int length) {
        byte[] data = new byte[length];
        Arrays.fill(data, value);
        return data;
    }

    private static void child(Path marker) throws IOException {
        Files.writeString(marker, "ready");
        byte[] out = repeated((byte) 'O', BLOCK_SIZE);
        byte[] err = repeated((byte) 'E', BLOCK_SIZE);
        for (int i = 0; i < BLOCKS; i++) {
            System.out.write(out);
            System.out.flush();
            System.err.write(err);
            System.err.flush();
        }
        if (System.out.checkError() || System.err.checkError()) {
            throw new IOException("child output stream failed");
        }
    }

    private static void closeQuietly(Closeable resource) {
        try {
            resource.close();
        } catch (IOException ignored) {
            // Original execution/cleanup failure is more informative.
        }
    }

    private static byte[] drainPipe(InputStream stream) throws IOException {
        int expected = BLOCK_SIZE * BLOCKS;
        ByteArrayOutputStream captured = new ByteArrayOutputStream(expected);
        byte[] buffer = new byte[8192];
        int count;
        // Positive-length reads avoid the pipe's FileInputStream.readAllBytes path.
        while ((count = stream.read(buffer, 0, buffer.length)) != -1) {
            if (count <= 0 || captured.size() > expected - count) {
                throw new IOException("unexpected zero read or output beyond the fixed limit");
            }
            captured.write(buffer, 0, count);
        }
        if (captured.size() != expected) {
            throw new IOException("output ended early: " + captured.size() + " of " + expected);
        }
        return captured.toByteArray();
    }

    private static Result runChild(Path marker, boolean waitFirst) throws Exception {
        boolean windows = System.getProperty("os.name").startsWith("Windows");
        String launcher = windows ? "javaw.exe" : "java";
        Path java = Path.of(System.getProperty("java.home"), "bin", launcher);
        if (!Files.isRegularFile(java)) throw new IOException("missing Java launcher: " + java);
        Process process = new ProcessBuilder(java.toString(), "-cp",
                System.getProperty("java.class.path"), SubprocessPipesDemo.class.getName(),
                "--child", marker.toString()).start();
        ExecutorService readers = Executors.newFixedThreadPool(2, task -> {
            Thread thread = new Thread(task, "child-pipe-reader");
            thread.setDaemon(true);
            return thread;
        });
        try {
            process.getOutputStream().close(); // No input is needed by this child.
            long readyDeadline = System.nanoTime() + TimeUnit.SECONDS.toNanos(5);
            while (!Files.exists(marker)) {
                if (!process.isAlive() || System.nanoTime() >= readyDeadline) {
                    throw new IOException("child did not reach the output stage");
                }
                Thread.sleep(10);
            }
            boolean timedOut = waitFirst && !process.waitFor(250, TimeUnit.MILLISECONDS);
            // Drain both pipes and observe whichever reader finishes/fails first.
            CompletionService<Captured> completed = new ExecutorCompletionService<>(readers);
            completed.submit(() -> new Captured("stdout", drainPipe(process.getInputStream())));
            completed.submit(() -> new Captured("stderr", drainPipe(process.getErrorStream())));
            long deadline = System.nanoTime() + TimeUnit.SECONDS.toNanos(5);
            byte[] stdout = null;
            byte[] stderr = null;
            for (int i = 0; i < 2; i++) {
                Future<Captured> finished = completed.poll(
                        Math.max(0, deadline - System.nanoTime()), TimeUnit.NANOSECONDS);
                if (finished == null) throw new IOException("pipe readers exceeded the guard");
                Captured capture = finished.get(); // Propagate a reader failure immediately.
                if (capture.channel().equals("stdout")) stdout = capture.bytes();
                else stderr = capture.bytes();
            }
            if (!process.waitFor(Math.max(0, deadline - System.nanoTime()), TimeUnit.NANOSECONDS)) {
                throw new IOException("child did not exit after its output was drained");
            }
            return new Result(timedOut, stdout, stderr, process.exitValue());
        } finally {
            try {
                if (process.isAlive()) {
                    process.destroyForcibly();
                    if (!process.waitFor(5, TimeUnit.SECONDS)) {
                        throw new IOException("child did not terminate during cleanup");
                    }
                }
            } finally {
                closeQuietly(process.getOutputStream());
                closeQuietly(process.getInputStream());
                closeQuietly(process.getErrorStream());
                readers.shutdownNow();
                if (!readers.awaitTermination(5, TimeUnit.SECONDS)) {
                    throw new IOException("pipe readers did not terminate");
                }
            }
        }
    }

    public static void main(String[] args) throws Exception {
        if (args.length == 2 && args[0].equals("--child")) {
            child(Path.of(args[1]));
            return;
        }
        Path folder = Files.createTempDirectory("qinghuan-java-pipes-");
        Path first = folder.resolve("first.ready");
        Path second = folder.resolve("second.ready");
        try {
            Result delayed = runChild(first, true);
            Result direct = runChild(second, false);
            check(delayed.waitTimedOut(), "waitFor without reading should time out");
            check(!direct.waitTimedOut(), "direct path does not use the wait-only probe");
            byte[] out = repeated((byte) 'O', BLOCK_SIZE * BLOCKS);
            byte[] err = repeated((byte) 'E', BLOCK_SIZE * BLOCKS);
            Result[] results = {delayed, direct};
            String[] labels = {"rescued", "direct"};
            for (int i = 0; i < results.length; i++) {
                Result result = results[i];
                check(result.exit() == 0, labels[i] + ": normal exit required");
                check(Arrays.equals(result.stdout(), out), labels[i] + ": complete stdout required");
                check(Arrays.equals(result.stderr(), err), labels[i] + ": complete stderr required");
                System.out.println(labels[i] + ": stdout=" + result.stdout().length
                        + "; stderr=" + result.stderr().length + "; exit=" + result.exit());
            }
            check(Arrays.equals(delayed.stdout(), direct.stdout())
                    && Arrays.equals(delayed.stderr(), direct.stderr()), "both paths must agree");
            System.out.println("waitFor_before_drain=timeout; two_readers_after_timeout=completed");
        } finally {
            Files.deleteIfExists(first);
            Files.deleteIfExists(second);
            Files.deleteIfExists(folder);
        }
        System.out.println("PASS checks=" + checks
                + "; children_reaped=true; readers_stopped=true; temporary_files_cleaned=true");
    }
}

怎样运行:javac -encoding UTF-8 --release 17 SubprocessPipesDemo.java java -cp . SubprocessPipesDemo

运行后对照结果
rescued: stdout=1048576; stderr=1048576; exit=0
direct: stdout=1048576; stderr=1048576; exit=0
waitFor_before_drain=timeout; two_readers_after_timeout=completed
PASS checks=9; children_reaped=true; readers_stopped=true; temporary_files_cleaned=true

本次排查:方法返回了,还要核对是否真的读完整

InputStream.readAllBytes 的 API 约定是读到流结束。排查本例旧实现时,在这台 Windows 机器的 Microsoft JDK 17.0.20.1 中捕获到提前返回:一条 stderr 读取任务正常返回了 65536 字节,同一条流随后仍能读到字节。这个数量也是一次写入块的大小,不能把它当成所有系统固定的管道容量。

继续对照本机 Microsoft JDK 17.0.20.1 与 21.0.12 的源码、字节码和四字节诊断探针,确认两套实现均存在这样一条路径:readAllBytes 回退到父类后,再调用子类的 readNBytes;后者按当时的长度快照分配空间,可能在读满这一份空间后返回。探针验证了这条路径能发生;原失败过程没有记录两次长度查询的精确时序,因此它对原现场的解释仍是有证据的推断。

交付代码使用非空缓冲区循环 read(byte[]),直到返回 -1,并分别检查总长度、完整内容和子进程退出码。它绕过上述长度快照分支,也便于逐块设置上限;两套本机 JDK 均已重新运行通过。这段排查说明特定实现与 API 约定的差异,不表示所有版本或所有 InputStream 都有同一问题。

输出很大时,改用受控保存方式

communicate 会把捕获的输出放进内存,因此本例明确限制总量。若工具可能持续输出大量内容,可把流直接重定向到合适文件,或安排并行、持续的读取与容量管理;不能靠把有限实验里的块数改成无限来获得生产方案。

Java Process 文档也提醒标准输入输出的有限缓冲可能让进程阻塞。本文的 Java 对照补充沿用同一等待关系,明确安排两条流的读取与资源回收,并已在 Windows 的 JDK 17 和 21 实际编译运行。它仍只验证有限输出,不代表任意外部工具都已验证。

记住这三点

  • wait 等待退出,不负责从你捕获的管道中读取输出。
  • stdout 与 stderr 都需要安排读取,flush 不能代替对端消费。
  • 有限输出可用 communicate;大或无限输出应设计另外的保存和容量策略。

别把例子用过头

  • 把超时时间加大,却不改变双方互相等待的顺序。
  • 只处理 stdout,忽略 stderr 同样可能写满。
  • 认为 wait 或 communicate 超时就自动结束了子进程。
  • 将本例两 MiB 的内存捕获方式用于无上限日志。

自己试一小步

如果转换工具只有 stderr 会连续输出,你怎样证明读取策略仍能让它正常结束,并保留失败原因?

  1. 另存脚本,把子进程输出改成有界的 stderr 多块输出,并自行定义非零退出码。
  2. 分别观察只等待、正确排空与超时清理三条路径。
  3. 为日志完整性和退出状态设计独立检查。
  4. 记录实验结束时是否仍有自己创建的子进程或未关闭的管道。

做到这些,就算完成

  • 输出总量有上限,错误路径也有超时和清理。
  • 非零退出码、stderr 非空与读取不完整被分别记录。
  • 不要把捕获到部分日志当作完整转换产物。

查原始资料

想确认一个细节,先看这份资料对应的部分,不必从头读完所有文档。