Program called with subprocess - logger messages are not printed?

Question

there's a problem getting messages from a program's logger, if this program is called with subprocess.

Here's the program BooFoo.py that uses logger to print messages to a file and console window:

import logging
LOG_FILENAME = 'example.log'
logging.basicConfig(filename=LOG_FILENAME,level=logging.DEBUG)
logger = logging.getLogger('main')
logger.addHandler(logging.StreamHandler())
print 'print foo'
logger.info('logger boo')

Here's the program CallBooFoo.py:

import subprocess
proc = subprocess.Popen(['python BooFoo.py'], bufsize=512, stdin = None, 
     stdout = subprocess.PIPE, stderr = subprocess.PIPE, shell=True)
proc_out, proc_err = proc.communicate()
print proc_out

"logger boo" does not get printed with CallBooFoo.py. Any idea how to fix this? Using os.system works, but is not a solution due to some other reasons.

Answer 1

logging.StreamHandler defaults to writing to standard error, not standard output. You can change this to standard output by using logging.StreamHandler(sys.stdout) instead.

You can also keep your code as is, and print the value of proc_err instead of (or in addition to) proc_out in the calling process. This will show the standard error of the child process.

If you need to see both stdout and stderr mixed together, you can change the calling process to:

proc = subprocess.Popen(['python BooFoo.py'], bufsize=512, stdin = None, 
     stdout = subprocess.PIPE, stderr = subprocess.STDOUT, shell=True)
proc_out, proc_err = proc.communicate()
print proc_out