Это хорошее решение, но оно хранит stdout \ stderr в стороне до завершения процесса, а затем записывает их в файл журнала. Это означает, что временные метки указывают время регистрации, а не время событий, и теряют порядок событий (все сообщения стандартного вывода записываются, а затем записываются все сообщения стандартного ввода).

ал небольшой скрипт Python, который выполняет некоторые команды оболочки, используяsubprocess модуль и вспомогательная функция:

import subprocess as sp
def run(command, description):
    """Runs a command in a formatted manner. Returns its return code."""
    start=datetime.datetime.now()
    sys.stderr.write('%-65s' % description)
    s=sp.Popen(command, shell=True, stderr=sp.PIPE, stdout=sp.PIPE)
    out,err=s.communicate()
    end=datetime.datetime.now()
    duration=end-start
    status='Done' if s.returncode==0 else 'Failed'
    print '%s (%d seconds)' % (status, duration.seconds)

Следующие строки читают стандартный вывод и ошибку:

    s=sp.Popen(command, shell=True, stderr=sp.PIPE, stdout=sp.PIPE)
    out,err=s.communicate()

Как видите, stdout и stderr не используются. Предположим, что я хочу записать выходные данные и сообщения об ошибках в файл журнала в отформатированном виде, например:

[STDOUT: 2011-01-17 14:53:55] <message>
[STDERR: 2011-01-17 14:53:56] <message>

У меня вопрос, какой самый Pythonic способ сделать это? Я думал о трех вариантах:

Унаследовать объект файла и переопределитьwrite метод.Используйте класс Delegate, который реализуетwrite.Подключиться кPIPE сам в некотором роде.

ОБНОВЛЕНИЕ: эталонный тестовый скрипт

Я проверяю результаты с помощью этого скрипта, сохраненного какtest.py:

#!/usr/bin/python
import sys

sys.stdout.write('OUT\n')
sys.stdout.flush()
sys.stderr.write('ERR\n')
sys.stderr.flush()

Есть идеи?

 TryPyPy27 янв. 2011 г., 22:49
Я сдаюсь. Мне удалось обернуть (разделить на подклассы) файл, чтобы записи добавляли метку времени и заголовок файла, но Popen работает с fds, и я не вижу, где происходят записи. Похоже, это простоos.execvp и ручка stdout где-то волшебная. Поэтому я вложил в подкласс Popen, но он игнорирует тот факт, что ему были переданы упакованные файлы и карта fd: title.

Ответы на вопрос(5)

1 и 2 не будут работать. Вот реализация принципа:

import subprocess
import time

FileClass = open('tmptmp123123123.tmp', 'w').__class__

class WrappedFile(FileClass):
    TIMETPL = "%Y-%m-%d %H:%M:%S"
    TEMPLATE = "[%s: %s] "

    def __init__(self, name, mode='r', buffering=None, title=None):
        self.title = title or name

        if buffering is None:
            super(WrappedFile, self).__init__(name, mode)
        else:
            super(WrappedFile, self).__init__(name, mode, buffering)

    def write(self, s):
        stamp = time.strftime(self.TIMETPL)
        if not s:
            return 
        # Add a line with timestamp per line to be written
        s = s.split('\n')
        spre = self.TEMPLATE % (self.title, stamp)
        s = "\n".join(["%s %s" % (spre, line) for line in s]) + "\n"
        super(WrappedFile, self).write(s)

Причина, по которой это не работает, в том, что Popen никогда не вызывает stdout.write. Обернутый файл будет работать нормально, когда мы вызываем его метод записи, и даже записывается в него, если передается в Popen, но запись происходит на более низком уровне, пропуская метод записи.

протоколирование стандартный пакет библиотеки. В этом случае я бы сказал, что остальные 2 были излишними.

 Adam Matan17 янв. 2011 г., 18:21
Как бы вы перенаправилиPIPE?

Make_async и read_async Адама Розенфилда, В то время как мой оригинальный ответ использовалсяselect.epoll и таким образом был только для Linux, теперь он используетselect.select, который должен работать под Unix или Windows.

Это записывает вывод из подпроцесса в/tmp/test.log как это происходит:

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

def make_async(fd):
    # https://stackoverflow.com/a/7730201/190597
    '''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):
    # https://stackoverflow.com/a/7730201/190597
    '''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_process(proc,stdout_logger,stderr_logger):
    loggers = { proc.stdout: stdout_logger, proc.stderr:  stderr_logger }
    def log_fds(fds):
        for fd in fds:
            out = read_async(fd)
            if out.strip():
                loggers[fd].info(out)
    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

if __name__=='__main__':
    formatter = logging.Formatter('[%(name)s: %(asctime)s] %(message)s')
    handler = logging.FileHandler('/tmp/test.log','w')
    handler.setFormatter(formatter)

    stdout_logger=logging.getLogger('STDOUT')
    stdout_logger.setLevel(logging.DEBUG)
    stdout_logger.addHandler(handler)

    stderr_logger=logging.getLogger('STDERR')
    stderr_logger.setLevel(logging.DEBUG)
    stderr_logger.addHandler(handler)        

    proc = subprocess.Popen(shlex.split('ls -laR /tmp'),
                            stdout=subprocess.PIPE,
                            stderr=subprocess.PIPE)
    log_process(proc,stdout_logger,stderr_logger)
 Adam Matan17 янв. 2011 г., 21:46
Это хорошее решение, но оно хранит stdout \ stderr в стороне до завершения процесса, а затем записывает их в файл журнала. Это означает, что временные метки указывают время регистрации, а не время событий, и теряют порядок событий (все сообщения стандартного вывода записываются, а затем записываются все сообщения стандартного ввода).

Это простое решение сработало для меня:

import sys
import datetime
import tempfile
import subprocess as sp
def run(command, description):
    """Runs a command in a formatted manner. Returns its return code."""
    with tempfile.SpooledTemporaryFile(8*1024) as so:
        print >> sys.stderr, '%-65s' % description
        start=datetime.datetime.now()
        retcode = sp.call(command, shell=True, stderr=sp.STDOUT, stdout=so)
        end=datetime.datetime.now()
        so.seek(0)
        for line in so.readlines():
            print >> sys.stderr,'logging this:', line.rstrip()
        duration=end-start
        status='Done' if retcode == 0 else 'Failed'
        print >> sys.stderr, '%s (%d seconds)' % (status, duration.seconds)

REF_SCRIPT = r"""#!/usr/bin/python
import sys

sys.stdout.write('OUT\n')
sys.stdout.flush()
sys.stderr.write('ERR\n')
sys.stderr.flush()
"""

SCRIPT_NAME = 'refscript.py'

if __name__ == '__main__':
    with open(SCRIPT_NAME, 'w') as script:
        script.write(REF_SCRIPT)
    run('python ' + SCRIPT_NAME, 'Reference script')
 Apalala03 февр. 2011 г., 18:39
@ Адам Матан. Это работает с вашим справочным скриптом тоже. Смотрите правки. Я использую Ubuntu 10.10 и Python 2.6.6).
 Apalala03 февр. 2011 г., 22:41
Обратите внимание, что этот эксперимент не позволяет добавлять временные метки к выводу, o он, вероятно, бесполезен.
 Apalala03 февр. 2011 г., 18:06
@ Adam Matan Я попробовал это сrun('ls /nonexistent', 'Does not exist') проверить наstderrи это сработало. Вы должны убедиться, что этоstderr=sp.SDOUT в призыве кPopen, Кстати, я изменяю код, чтобы удалитьs.poll() петля, потому что это, вероятно, ненужная, быстрая петля.
 Adam Matan03 февр. 2011 г., 11:14
Это работает со смешанными ошибками \ результатами вывода? Это не удалось для моего справочного скрипта (см. Обновление выше).
Решение Вопроса

но переопределения write () будет недостаточно.

Проблема в том, что Popen нужны файловые дескрипторы для присоединения к процессу, поэтому файловые объекты Python не работают, они должны быть на уровне ОС. Чтобы решить эту проблему, у вас должен быть объект Python, имеющий дескриптор файла уровня os. Единственный способ решить эту проблему - использовать каналы, так что у вас есть дескриптор файла уровня os для записи. Но тогда вам нужен другой поток, который сидит и опрашивает этот канал, чтобы что-то было прочитано, чтобы он мог его записать. (Так что это более строго реализация 2, поскольку она делегирует ведение журнала).

Сказано и сделано:

import io
import logging
import os
import select
import subprocess
import time
import threading

LOG_FILENAME = 'output.log'
logging.basicConfig(filename=LOG_FILENAME,level=logging.DEBUG)

class StreamLogger(io.IOBase):
    def __init__(self, level):
        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(1)
        self._run = None

    def write(self, data):
        return logging.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(1)
            os.close(self.pipe[0])
            os.close(self.pipe[1])

Таким образом, этот класс запускает канал уровня ОС, к которому Popen может прикрепить stdin / out / error для подпроцесса. Он также запускает поток, который опрашивает другой конец этого канала раз в секунду, чтобы что-то регистрировалось, а затем регистрирует его с помощью модуля регистрации.

Возможно, этот класс должен реализовать больше вещей для полноты, но в любом случае он работает.

Пример кода:

with StreamLogger(logging.INFO) as out:
    with StreamLogger(logging.ERROR) as err:
        subprocess.Popen("ls", stdout=out, stderr=err, shell=True)

output.log заканчивается примерно так:

INFO:root:output.log
INFO:root:streamlogger.py
INFO:root:and
INFO:root:so
INFO:root:on

Протестировано с Python 2.6, 2.7 и 3.1.

Я думаю, что любая реализация 1 и 3 должна использовать аналогичные методы. Это немного усложняется, но если вы не сможете правильно сделать журнал команд Popen, у меня нет лучшей идеи).

 Lennart Regebro02 февр. 2011 г., 01:13
Я не пробовал это в Windows, но если нет, то замените select тем, что вы делаете, чтобы проверить, есть ли что-то, что можно прочитать на канале под Windows.
 Lennart Regebro03 февр. 2011 г., 11:58
@ Adam Matan: Нет, он работает с «ls», как вы видите, поэтому в принципе это звучит. Я не знаю, как работает ваш простой скрипт на Python, поэтому я не могу объяснить, почему это не сработало, хотя теперь я вижу ошибку: он не печатает оставшуюся часть буфера при выходе, так что это может быть. Положить вself.write(buf.decode()) последний в методе сбрасывателя. Возможно, поместите sleep (1) первым в цикл тоже.
 Adam Matan03 февр. 2011 г., 11:08
Это замечательно, но не работает (output.txt пуст) при запуске простых сценариев Python, которые печатают что-то для stdout и что-то для stderr. Любая идея?
 Nas Banov02 февр. 2011 г., 00:52
это будет работать на Windows ?! у меня есть сомнения, потому чтоselect на win только для сокетов, а не для файлов.
 senderle31 янв. 2011 г., 01:29
+1: это похоже на то, что я собирался предложить, но я не мог заставить поток ведения журнала вести себя правильно.

Ваш ответ на вопрос