Python日志与子进程的输出和错误流

Question

我想启动一个Python进程，并把子进程的错误信息记录到父脚本的日志对象里。理想情况下，我希望把所有的日志信息统一到一个文件里。我能否以某种方式访问日志类的输出流？我知道的一个解决办法是使用proc log来记录日志。正如下面的回答所说，我可以从proc.stdin和stderr中读取，但这样会出现重复的日志头。我在想有没有办法直接把日志类底层的文件描述符传递给子进程？

logging.basicConfig(filename="test.log",level=logging.DEBUG)
logging.info("Started")
procLog = open(os.path.expanduser("subproc.log"), 'w')
proc = subprocess.Popen(cmdStr, shell=True, stderr=procLog, stdout=procLog)
proc.wait()
procLog.flush()

Answer 1

根据 Adam Rosenfield的代码，你可以这样做：

1. 使用 select.select 来阻塞，直到有输出可以从 proc.stdout 或 proc.stderr 读取。
2. 读取并记录这些输出，然后
3. 重复这个过程，直到这个程序结束。

注意，下面的代码会写入 /tmp/test.log 并运行命令 ls -laR /tmp。你可以根据自己的需要进行修改。

（顺便说一下，通常 /tmp 目录里有一些普通用户无法读取的文件夹，所以运行 ls -laR /tmp 会同时产生标准输出和错误输出。下面的代码能够正确地将这两种输出交替处理。）

import logging
import subprocess
import shlex
import select
import fcntl
import os
import errno
import contextlib

logger = logging.getLogger(__name__)

def make_async(fd):
    '''add the O_NONBLOCK flag to a file descriptor'''
    fcntl.fcntl(fd, fcntl.F_SETFL, fcntl.fcntl(fd, fcntl.F_GETFL) | os.O_NONBLOCK)

def read_async(fd):
    '''read some data from a file descriptor, ignoring EAGAIN errors'''
    try:
        return fd.read()
    except IOError, e:
        if e.errno != errno.EAGAIN:
            raise e
        else:
            return ''

def log_fds(fds):
    for fd in fds:
        out = read_async(fd)
        if out:
            logger.info(out)

@contextlib.contextmanager
def plain_logger():
    root = logging.getLogger()    
    hdlr = root.handlers[0]
    formatter_orig = hdlr.formatter
    hdlr.setFormatter(logging.Formatter('%(message)s'))
    yield 
    hdlr.setFormatter(formatter_orig)

def main():
    # fmt = '%(name)-12s: %(levelname)-8s %(message)s'
    logging.basicConfig(filename = '/tmp/test.log', mode = 'w',
                        level = logging.DEBUG)

    logger.info("Started")
    cmdStr = 'ls -laR /tmp'

    with plain_logger():
        proc = subprocess.Popen(shlex.split(cmdStr),
                                stdout = subprocess.PIPE, stderr = subprocess.PIPE)
        # without `make_async`, `fd.read` in `read_async` blocks.
        make_async(proc.stdout)
        make_async(proc.stderr)
        while True:
            # Wait for data to become available 
            rlist, wlist, xlist = select.select([proc.stdout, proc.stderr], [], [])
            log_fds(rlist)
            if proc.poll() is not None:
                # Corner case: check if more output was created
                # between the last call to read_async and now                
                log_fds([proc.stdout, proc.stderr])                
                break

    logger.info("Done")

if __name__ == '__main__':
    main()

---

编辑：

你可以将 stdout 和 stderr 重定向到 logfile = open('/tmp/test.log', 'a')。不过这样做有一个小麻烦，就是如果有其他日志记录器也在写入 /tmp/test.log，那么它就无法知道子进程正在写什么，这样日志文件可能会变得混乱。

如果在子进程运行时你没有进行日志记录，那么唯一的问题就是在子进程结束后，日志记录器在文件中的位置不对。你可以通过调用

handler.stream.seek(0, 2)

来解决这个问题，这样记录器就会从文件的末尾继续写入。

---

import logging
import subprocess
import contextlib
import shlex

logger = logging.getLogger(__name__)

@contextlib.contextmanager
def suspended_logger():
    root = logging.getLogger()    
    handler = root.handlers[0]
    yield 
    handler.stream.seek(0, 2)

def main():
    logging.basicConfig(filename = '/tmp/test.log', filemode = 'w',
                        level = logging.DEBUG)

    logger.info("Started")
    with suspended_logger():
        cmdStr = 'test2.py 1>>/tmp/test.log 2>&1'
        logfile = open('/tmp/test.log', 'a')
        proc = subprocess.Popen(shlex.split(cmdStr),
                                stdout = logfile,
                                stderr = logfile)
        proc.communicate()
    logger.info("Done")

if __name__ == '__main__':
    main()