Decorate \ delegate un objeto File para agregar funcionalidad

He estado escribiendo un pequeño script de Python que ejecuta algunos comandos de shell utilizando el módulo de subprocess y una función auxiliar:

 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) 

Las siguientes líneas leen la salida estándar y el error:

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

Como puede ver, stdout y stderr no se utilizan. Supongamos que quiero escribir los mensajes de salida y de error en un archivo de registro, de forma formateada, por ejemplo:

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

Mi pregunta es, ¿cuál es la forma más pythonica de hacerlo? Pensé en tres opciones:

  1. Hereda el objeto de archivo y anule el método de write .
  2. Use una clase de delegado que implemente write .
  3. Conéctate al PIPE mismo de alguna manera.

ACTUALIZACIÓN: script de prueba de referencia

Estoy revisando los resultados con este script, guardado como test.py :

 #!/usr/bin/python import sys sys.stdout.write('OUT\n') sys.stdout.flush() sys.stderr.write('ERR\n') sys.stderr.flush() 

¿Algunas ideas?

1 y 2 son soluciones razonables, pero sobrescribir a write () no será suficiente.

El problema es que Popen necesita identificadores de archivos para adjuntarse al proceso, por lo que los objetos de archivos de Python no funcionan, tienen que estar a nivel de sistema operativo. Para resolverlo, debe tener un objeto Python que tenga un identificador de archivo de nivel OS. La única forma en que puedo pensar en resolver eso es usar tuberías, de modo que tenga un identificador de archivo de nivel OS para escribir. Pero luego necesitas otro hilo que se asiente y sondea esa tubería para que las cosas se puedan leer para que pueda iniciar sesión. (Entonces, esto es más estrictamente una implementación de 2, ya que delega al registro).

Dicho y hecho:

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

Así que esa clase inicia un canal de nivel de sistema operativo al que Popen puede adjuntar la entrada / salida / error para el subproceso. También inicia un subproceso que sondea el otro extremo de esa tubería una vez por segundo para que se registren las cosas, que luego registra con el módulo de registro.

Posiblemente esta clase debería implementar más cosas para completar, pero funciona en este caso de todos modos.

Código de ejemplo:

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

output.log termina así

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

Probado con Python 2.6, 2.7 y 3.1.

Pienso que cualquier implementación de 1 y 3 necesitaría usar técnicas similares. Es un poco complicado, pero a menos que pueda hacer que el comando de Popen se registre correctamente, no tengo una mejor idea).

Sugeriría la opción 3, con el paquete de biblioteca estándar de registro . En este caso yo diría que los otros 2 fueron una exageración.

1 y 2 no funcionarán. Aquí hay una implementación del principio:

 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) 

La razón por la que no funciona es que Popen nunca llama a stdout.write. Un archivo envuelto funcionará bien cuando llamemos a su método de escritura e incluso se escribirá si se pasa a Popen, pero la escritura se realizará en una capa inferior, omitiendo el método de escritura.

Esta solución simple funcionó para mí:

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

Esto utiliza make_async y read_async de Adam Rosenfield . Mientras que mi respuesta original usaba select.epoll y, por lo tanto, era solo para Linux, ahora usa select.select , que debería funcionar en Unix o Windows.

Esto registra la salida del subproceso a /tmp/test.log cuando se produce:

 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)