Dekorieren \ Delegat ein File-Objekt hinzufügen Funktionalität

Question

Ich habe einen kleinen Python-Skript geschrieben, das einige Shell-Befehle mit dem subprocess Modul und eine Hilfsfunktion ausführt:

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) 

die folgenden Zeilen liest die Standardausgabe und Fehler:

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

Wie Sie sehen können, werden stdout und stderr nicht verwendet. Nehmen wir an, dass ich die Ausgabe und Fehlermeldungen in eine Protokolldatei, in einer Art und Weise formatiert schreiben möchten, z.B .:

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

Meine Frage ist, was ist die Pythonic Weg, es zu tun? Ich dachte an drei Optionen:

1. Übernehmen Sie das Dateiobjekt und überschreiben Sie die write Methode. Verwenden Sie eine Delegate-Klasse, die write implementiert.
2. Verbinden Sie sich mit der PIPE selbst in irgendeiner Weise.

UPDATE: Referenz-Testskript

ich die Ergebnisse mit diesem Skript überprüft, gespeichert als test.py:

#!/usr/bin/python 
import sys 

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

Irgendwelche Ideen?

Answer 1

1 und 2 sind sinnvolle Lösungen, aber überschreiben write() wird nicht ausreichen.

Das Problem ist, dass Popen Datei-Handles benötigt, um an den Prozess anzuhängen, damit Python-Dateiobjekte nicht funktionieren, sie müssen Betriebssystemebene sein. Um das zu lösen, müssen Sie ein Python-Objekt mit einem Dateihandle auf Betriebssystemebene haben. Der einzige Weg, wie ich das lösen kann, ist die Verwendung von Pipes, also haben Sie einen Dateigriff auf os-Ebene, auf den geschrieben werden kann. Aber dann brauchst du einen anderen Thread, der sitzt und diese Pipe abruft, damit Dinge eingelesen werden können, damit sie es protokollieren kann. (Dies ist also eine strengere Implementierung von 2, da es an die Protokollierung delegiert wird).

Gesagt getan:

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]) 

Damit Klasse startet ein os level Rohr, das Popen der stdin/out/Fehler für die Subprozess anbringen. Es startet auch einen Thread, der das andere Ende dieser Pipe einmal pro Sekunde abfragt, um Dinge zu protokollieren, die dann mit dem Protokollierungsmodul protokolliert werden.

Möglicherweise sollte diese Klasse mehr Dinge für die Vollständigkeit implementieren, aber es funktioniert in diesem Fall sowieso.

Beispielcode:

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

output.log endet wie so up:

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

mit Python Getestete 2.6, 2.7 und 3.1.

Ich würde denken, jede Implementierung von 1 und 3 müsste ähnliche Techniken verwenden. Es ist ein bisschen beteiligt, aber wenn Sie den Popen-Befehl nicht korrekt selbst protokollieren können, habe ich keine bessere Idee).

Answer 2

Ich würde Option 3 vorschlagen, mit der logging Standardbibliothek Paket. In diesem Fall würde ich sagen, die anderen 2 waren Overkill.

Answer 3

Verwendet Adam Rosenfield's make_async and read_async. Während meine ursprüngliche Antwort select.epoll war und somit nur Linux war, wird jetzt select.select verwendet, was unter Unix oder Windows funktionieren sollte.

Dieser protokolliert die Ausgabe von der Subprozess zu /tmp/test.log, wie sie auftritt:

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) 

Answer 4

1 und 2 wird nicht funktionieren. Hier ist eine Implementierung des Prinzips:

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) 

Der Grund ist es nicht funktioniert, ist, dass Popen nie stdout.write nennt. Eine umgebrochene Datei funktioniert gut, wenn wir ihre Schreibmethode aufrufen und wird sogar geschrieben, wenn sie an Popen übergeben wird, aber der Schreibvorgang findet in einer niedrigeren Ebene statt und überspringt die Schreibmethode.

Answer 5

Diese einfache Lösung für mich gearbeitet:

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')