subprocess.Popen() output to logging.StreamHandler()

[Gerard Flanagan]

On Apr 10, 2:11 pm, "sven _" <svens... at gmail.com> wrote:
> Version: Python 2.5.1 (r251:54863, Mar  7 2008, 04:10:12)
>
> My goal is to have stdout and stderr written to a logging handler.
> This code does not work:
>
> # START
> import logging, subprocess
> ch = logging.StreamHandler()
> ch.setLevel(logging.DEBUG)
> subprocess.call(['ls', '-la'], 0, None, None, ch, ch)
> # END
>
> Traceback (most recent call last):
>   File "log.py", line 5, in <module>
>    subprocess.call(['ls', '-la'], 0, None, None, ch, ch)
>   File "/usr/lib/python2.5/subprocess.py", line 443, in call
>    return Popen(*popenargs, **kwargs).wait()
>   File "/usr/lib/python2.5/subprocess.py", line 586, in __init__
>    errread, errwrite) = self._get_handles(stdin, stdout, stderr)
>   File "/usr/lib/python2.5/subprocess.py", line 941, in _get_handles
>    c2pwrite = stdout.fileno()
> AttributeError: StreamHandler instance has no attribute 'fileno'
>
> This is because subprocess.Popen() expects file descriptors to write
> to, and logging.StreamHandler() does not supply it. The StreamHandler
> could supply its own stdout file descriptor, but then Popen() would
> write directly to that file, bypassing all the logging fluff.
>
> A possible solution would be to make a named pipe (os.mkfifo()), have
> Popen() write to that, and then have some horrendous hack run select()
> or similar on the fifo to read from it and finally pass it to
> StreamHandler.
>
> Are there better solutions?
>
> sven


When you create a StreamHandler, it is associated with a particular
stream, eg. sys.stdout.  So when you log an event, the handler picks
it up and writes it to the stream.  But you seem to think that the
reverse situation is true - when something is written to the stream
(from an arbitrary source) then the StreamHandler instance will pick
it up.  This isn't the case - it doesn't work both ways.

I think the only solution is to specifically log each line that you
get back from Popen, as suggested by Thomas Dimson.  You would perhaps
like something like the code below to work but it doesn't (well, it
runs, but the output of the subprocess call bypasses the
Streamhandler).  But then, maybe this is sufficient for you - as
you've seen, you can't set the stdout of the subprocess to the
StreamHandler, but you can set it to the Streamhandler's stream (if it
has a fileno) -

subprocess.call('svn info', stdout=ch.stream)
OR
subprocess.call('svn info', stdout=ch.stream.fileno())

--------------------------------------------------------

import sys
import logging
import subprocess

ECHO_FORMAT = '%(levelname)-8s %(message)s'

class ReverseReverseStreamHandler(logging.StreamHandler):

    def __init__(self, strm):
        logging.StreamHandler.__init__(self, strm)
        self.fileno = strm.fileno

    def write(self, msg):
        print 'This is never called!'
        for line in msg.splitlines():
            self.emit(logging.LogRecord(None, None, "", 0, line, (),
None, None))

root = logging.getLogger()

console = ReverseReverseStreamHandler(sys.stdout)

formatter = logging.Formatter(ECHO_FORMAT)
console.setFormatter(formatter)
root.addHandler(console)
root.setLevel(logging.DEBUG)

logging.info('---------')

subprocess.call('svn info', stdout=console)

logging.info('---------')

--------------------------------------------------------

hth

G.