How do I duplicate sys.stdout to a log file in pyt

Question

Edit: Since it appears that there's either no solution, or I'm doing something so non-standard that nobody knows - I'll revise my question to also ask: What is the best way to accomplish logging when a python app is making a lot of system calls?

My app has two modes. In interactive mode, I want all output to go to the screen as well as to a log file, including output from any system calls. In daemon mode, all output goes to the log. Daemon mode works great using os.dup2(). I can't find a way to "tee" all output to a log in interactive mode, without modifying each and every system call.

---

In other words, I want the functionality of the command line 'tee' for any output generated by a python app, including system call output.

To clarify:

To redirect all output I do something like this, and it works great:

# open our log file
so = se = open("%s.log" % self.name, 'w', 0)

# re-open stdout without buffering
sys.stdout = os.fdopen(sys.stdout.fileno(), 'w', 0)

# redirect stdout and stderr to the log file opened above
os.dup2(so.fileno(), sys.stdout.fileno())
os.dup2(se.fileno(), sys.stderr.fileno())

The nice thing about this is that it requires no special print calls from the rest of the code. The code also runs some shell commands, so it's nice not having to deal with each of their output individually as well.

Simply, I want to do the same, except duplicating instead of redirecting.

At first thought, I thought that simply reversing the dup2's should work. Why doesn't it? Here's my test:

import os, sys

### my broken solution:
so = se = open("a.log", 'w', 0)
sys.stdout = os.fdopen(sys.stdout.fileno(), 'w', 0)

os.dup2(sys.stdout.fileno(), so.fileno())
os.dup2(sys.stderr.fileno(), se.fileno())
###

print("foo bar")

os.spawnve("P_WAIT", "/bin/ls", ["/bin/ls"], {})
os.execve("/bin/ls", ["/bin/ls"], os.environ)

The file "a.log" should be identical to what was displayed on the screen.

Answer 1

(Ah, just re-read your question and see that this doesn't quite apply.)

Here is a sample program that makes uses the python logging module. This logging module has been in all versions since 2.3. In this sample the logging is configurable by command line options.

In quite mode it will only log to a file, in normal mode it will log to both a file and the console.

import os
import sys
import logging
from optparse import OptionParser

def initialize_logging(options):
    """ Log information based upon users options"""

    logger = logging.getLogger('project')
    formatter = logging.Formatter('%(asctime)s %(levelname)s\t%(message)s')
    level = logging.__dict__.get(options.loglevel.upper(),logging.DEBUG)
    logger.setLevel(level)

    # Output logging information to screen
    if not options.quiet:
        hdlr = logging.StreamHandler(sys.stderr)
        hdlr.setFormatter(formatter)
        logger.addHandler(hdlr)

    # Output logging information to file
    logfile = os.path.join(options.logdir, "project.log")
    if options.clean and os.path.isfile(logfile):
        os.remove(logfile)
    hdlr2 = logging.FileHandler(logfile)
    hdlr2.setFormatter(formatter)
    logger.addHandler(hdlr2)

    return logger

def main(argv=None):
    if argv is None:
        argv = sys.argv[1:]

    # Setup command line options
    parser = OptionParser("usage: %prog [options]")
    parser.add_option("-l", "--logdir", dest="logdir", default=".", help="log DIRECTORY (default ./)")
    parser.add_option("-v", "--loglevel", dest="loglevel", default="debug", help="logging level (debug, info, error)")
    parser.add_option("-q", "--quiet", action="store_true", dest="quiet", help="do not log to console")
    parser.add_option("-c", "--clean", dest="clean", action="store_true", default=False, help="remove old log file")

    # Process command line options
    (options, args) = parser.parse_args(argv)

    # Setup logger format and output locations
    logger = initialize_logging(options)

    # Examples
    logger.error("This is an error message.")
    logger.info("This is an info message.")
    logger.debug("This is a debug message.")

if __name__ == "__main__":
    sys.exit(main())

Answer 2

None of the answers above really seems to answer the problem posed. I know this is an old thread, but I think this problem is a lot simpler than everyone is making it:

class tee_err(object):

 def __init__(self):
    self.errout = sys.stderr

    sys.stderr = self

    self.log = 'logfile.log'
    log = open(self.log,'w')
    log.close()

 def write(self, line):

    log = open(self.log,'a')
    log.write(line)
    log.close()   

    self.errout.write(line)

Now this will repeat everything to the normal sys.stderr handler and your file. Create another class tee_out for sys.stdout.

Answer 3

I know this question has been answered repeatedly, but for this I've taken the main answer from John T's answer and modified it so it contains the suggested flush and followed its linked revised version. I've also added the enter and exit as mentioned in cladmi's answer for use with the with statement. In addition, the documentation mentions to flush files using os.fsync() so I've added that as well. I don't know if you really need that but its there.

import sys, os

class Logger(object):
    "Lumberjack class - duplicates sys.stdout to a log file and it's okay"
    #source: https://stackoverflow.com/q/616645
    def __init__(self, filename="Red.Wood", mode="a", buff=0):
        self.stdout = sys.stdout
        self.file = open(filename, mode, buff)
        sys.stdout = self

    def __del__(self):
        self.close()

    def __enter__(self):
        pass

    def __exit__(self, *args):
        self.close()

    def write(self, message):
        self.stdout.write(message)
        self.file.write(message)

    def flush(self):
        self.stdout.flush()
        self.file.flush()
        os.fsync(self.file.fileno())

    def close(self):
        if self.stdout != None:
            sys.stdout = self.stdout
            self.stdout = None

        if self.file != None:
            self.file.close()
            self.file = None

You can then use it

with Logger('My_best_girlie_by_my.side'):
    print("we'd sing sing sing")

or

Log=Logger('Sleeps_all.night')
print('works all day')
Log.close()

Answer 4

another solution using logging module:

import logging
import sys

log = logging.getLogger('stdxxx')

class StreamLogger(object):

    def __init__(self, stream, prefix=''):
        self.stream = stream
        self.prefix = prefix
        self.data = ''

    def write(self, data):
        self.stream.write(data)
        self.stream.flush()

        self.data += data
        tmp = str(self.data)
        if '\x0a' in tmp or '\x0d' in tmp:
            tmp = tmp.rstrip('\x0a\x0d')
            log.info('%s%s' % (self.prefix, tmp))
            self.data = ''


logging.basicConfig(level=logging.INFO,
                    filename='text.log',
                    filemode='a')

sys.stdout = StreamLogger(sys.stdout, '[stdout] ')

print 'test for stdout'

Answer 5

I'm writing a script to run cmd-line scripts. ( Because in some cases, there just is no viable substitute for a Linux command -- such as the case of rsync. )

What I really wanted was to use the default python logging mechanism in every case where it was possible to do so, but to still capture any error when something went wrong that was unanticipated.

This code seems to do the trick. It may not be particularly elegant or efficient ( although it doesn't use string+=string, so at least it doesn't have that particular potential bottle- neck ). I'm posting it in case it gives someone else any useful ideas.

import logging
import os, sys
import datetime

# Get name of module, use as application name
try:
  ME=os.path.split(__file__)[-1].split('.')[0]
except:
  ME='pyExec_'

LOG_IDENTIFIER="uuu___( o O )___uuu "
LOG_IDR_LENGTH=len(LOG_IDENTIFIER)

class PyExec(object):

  # Use this to capture all possible error / output to log
  class SuperTee(object):
      # Original reference: http://mail.python.org/pipermail/python-list/2007-May/442737.html
      def __init__(self, name, mode):
          self.fl = open(name, mode)
          self.fl.write('\n')
          self.stdout = sys.stdout
          self.stdout.write('\n')
          self.stderr = sys.stderr

          sys.stdout = self
          sys.stderr = self

      def __del__(self):
          self.fl.write('\n')
          self.fl.flush()
          sys.stderr = self.stderr
          sys.stdout = self.stdout
          self.fl.close()

      def write(self, data):
          # If the data to write includes the log identifier prefix, then it is already formatted
          if data[0:LOG_IDR_LENGTH]==LOG_IDENTIFIER:
            self.fl.write("%s\n" % data[LOG_IDR_LENGTH:])
            self.stdout.write(data[LOG_IDR_LENGTH:])

          # Otherwise, we can give it a timestamp
          else:

            timestamp=str(datetime.datetime.now())
            if 'Traceback' == data[0:9]:
              data='%s: %s' % (timestamp, data)
              self.fl.write(data)
            else:
              self.fl.write(data)

            self.stdout.write(data)


  def __init__(self, aName, aCmd, logFileName='', outFileName=''):

    # Using name for 'logger' (context?), which is separate from the module or the function
    baseFormatter=logging.Formatter("%(asctime)s \t %(levelname)s \t %(name)s:%(module)s:%(lineno)d \t %(message)s")
    errorFormatter=logging.Formatter(LOG_IDENTIFIER + "%(asctime)s \t %(levelname)s \t %(name)s:%(module)s:%(lineno)d \t %(message)s")

    if logFileName:
      # open passed filename as append
      fl=logging.FileHandler("%s.log" % aName)
    else:
      # otherwise, use log filename as a one-time use file
      fl=logging.FileHandler("%s.log" % aName, 'w')

    fl.setLevel(logging.DEBUG)
    fl.setFormatter(baseFormatter)

    # This will capture stdout and CRITICAL and beyond errors

    if outFileName:
      teeFile=PyExec.SuperTee("%s_out.log" % aName)
    else:
      teeFile=PyExec.SuperTee("%s_out.log" % aName, 'w')

    fl_out=logging.StreamHandler( teeFile )
    fl_out.setLevel(logging.CRITICAL)
    fl_out.setFormatter(errorFormatter)

    # Set up logging
    self.log=logging.getLogger('pyExec_main')
    log=self.log

    log.addHandler(fl)
    log.addHandler(fl_out)

    print "Test print statement."

    log.setLevel(logging.DEBUG)

    log.info("Starting %s", ME)
    log.critical("Critical.")

    # Caught exception
    try:
      raise Exception('Exception test.')
    except Exception,e:
      log.exception(str(e))

    # Uncaught exception
    a=2/0


PyExec('test_pyExec',None)

Obviously, if you're not as subject to whimsy as I am, replace LOG_IDENTIFIER with another string that you're not like to ever see someone write to a log.

Answer 6

Since you're comfortable spawning external processes from your code, you could use tee itself. I don't know of any Unix system calls that do exactly what tee does.

import subprocess, os, sys

# Unbuffer output
sys.stdout = os.fdopen(sys.stdout.fileno(), 'w', 0)

tee = subprocess.Popen(["tee", "log.txt"], stdin=subprocess.PIPE)
os.dup2(tee.stdin.fileno(), sys.stdout.fileno())
os.dup2(tee.stdin.fileno(), sys.stderr.fileno())

print "\nstdout"
print >>sys.stderr, "stderr"
os.spawnve("P_WAIT", "/bin/ls", ["/bin/ls"], {})
os.execve("/bin/ls", ["/bin/ls"], os.environ)

You could also emulate tee using the multiprocessing package (or use processing if you're using Python 2.5 or earlier).