分别记录 stdout 和 stderr 时截断的输出日志文件

我在上下文管理器中设置了一个子进程命令，该命令通过我自己的记录器将 stdout 和 stderr 通过管道传输到单独的文件。这是此处给出的答案的变体：https://stackoverflow.com/a/4838875/4844311 https://stackoverflow.com/a/4838875/4844311

我的代码如下：

import logging
import subprocess

with StreamLogger(logging.DEBUG, my_out_logger) as out:
    with StreamLogger(logging.ERROR, my_err_logger) as err:
        p = subprocess.Popen(cmd, shell=False, stdout=out, stderr=err)
        p.communicate()
        p.wait()

where my_out_logger and my_err_logger是带有记录到文件等的句柄的记录对象。

StreamLogger 代码与上面链接中给出的代码类似：

import io
import os
import threading
import select
import time

class StreamLogger(io.IOBase):
    def __init__(self, level, logger):
        self.logger = logger
        self.level = level
        self.pipe = os.pipe()
        self.thread = threading.Thread(target=self._flusher)
        self.thread.start()

    def _flusher(self):
        self._run = True
        buf = b''
        while self._run:
            for fh in select.select([self.pipe[0]], [], [], 0)[0]:
                buf += os.read(fh, 1024)
                while b'\n' in buf:
                    data, buf = buf.split(b'\n', 1)
                    self.write(data.decode())
            time.sleep(0.01)
        self._run = None

    def write(self, data):
        return self.logger.log(self.level, data)

    def fileno(self):
        return self.pipe[1]

    def close(self):
        if self._run:
            self._run = False
            while self._run is not None:
                time.sleep(0.01)
            os.close(self.pipe[0])
            os.close(self.pipe[1])

我的代码与上面链接中的答案提供的代码之间的唯一显着区别是，我的代码将日志记录消息发送到根据其句柄进行重定向的记录器，而不是直接记录，如链接中的代码所示。

这段代码大部分时间都工作正常。

但我注意到，每隔一段时间就会有一个被截断的输出日志文件。看起来输出文件是由FileHandler in my_out_logger在写入所有标准输出内容之前正在关闭。

我不确定为什么会发生这种情况或在哪里修复代码。现在我刚刚添加了一个time.sleep(0.3)之间的声明p.communicate() and p.wait()这减少了截断文件的频率，但这似乎是一个丑陋的解决方案。

我宁愿了解出了什么问题并正确修复它。我欢迎任何建议或见解。

我想我终于想通了。 这里的问题是StreamLogger代码无法显式检查以确保stdout已全部写完。一旦主线程运行subprocess收到一个returncode，它退出上下文管理器，调用__exit__()的方法StreamLogger，继承自IOBase（源代码here https://pythonhosted.org/experimentdb/_modules/io.html）。这调用close()这改变了self._run归因于False。这会导致轮询管道的线程停止循环，无论管道中仍有什么内容。

这对于大多数具有小到中等输出的命令来说效果很好stdout，其中之间没有滞后时间returncode返回并写入输出。但就我而言，我正在运行一个程序subprocess大量文本写入stdout。因此，在主线程告诉子线程停止轮询管道之前，存在一种与时间的竞赛，尝试清除管道。

这里的两个关键变量是从管道读取的缓冲区的大小以及轮询管道的频率。我通过增加缓冲区大小解决了我的问题os.read()到 4096，并且还删除了time.sleep() in the while循环中_flusher()方法。这最大化了可以从管道读取的数据量，并且在我的例子中确保在日志记录循环停止之前完全记录输出。