subprocess stderr vs sys.stderr

I'm not sure whether the question is a Python or shell question.

I've got a Python program that uses a subprocess call on a command which can emit an error message on stderr. My own program also uses sys.stderr to log errors. Here's a simple example, with a command (ls *.foobar) that fails:

import sys,subprocess

sys.stderr.write("--Hello\n")
try:
    subprocess.check_call("ls *.foobar",shell=True)
except subprocess.CalledProcessError as e:
    sys.stderr.write("Command failed\n")
sys.stderr.write("--Bye\n")

When I run this code, the ouptut on the console (from stderr) is the following:

--Hello
ls: cannot access '*.foobar': No such file or directory
Command failed
--Bye

If I redirect stderr to a file (e.g. using python myscript.py 2> log), the file contains the following:

ls: cannot access '*.foobar': No such file or directory
--Hello
Command failed
--Bye

Is there a way to keep the order of the messages in the file (other than using an explicit redirection of stderr on a file in the subprocess call) ?

This problem resembles some standard stdout/stderr issues but, here, everything is supposed to be on stderr.

Solution

You need to flush data writter to the stderr descriptor:

sys.stderr.write("--Hello\n")
sys.stderr.flush()

stdio is line buffered when connected to a terminal, and using a fixed buffer when connected to a pipe. You are writing a \n newline character which triggers a flush when connected to the terminal but, but without that per-line flush you don't write enough to stderr to trigger a buffer flush before the final flush when Python exits.

If you use print(..., file=sys.stderr) you can tell print() to issue the flush() call by adding flush=True:

print("--Hello", file=sys.stderr, flush=True)

Another way for you to handle this is to 'capture and release' the stderr output of the child process:

sys.stderr.write("--Hello\n")
try:
    subprocess.check_call("ls *.foobar", shell=True, stderr=subprocess.PIPE)
except subprocess.CalledProcessError as e:
    sys.stderr.write(e.stderr)
    sys.stderr.write("Command failed\n")
sys.stderr.write("--Bye\n")

The stderr=subprocess.PIPE addition tells subprocess to capture the stderr output of the command, and you can find that output as the e.stderr attribute of the CalledProcessError exception.