Print output of "time" shell command without losing formatting

Question

For some reason, when I run "time ./" from the terminal, I get this format:

real	0m0.090s
user	0m0.086s
sys	0m0.004s

But when I execute the same command in Python 2.7.6:

result = subprocess.Popen("time ./<binary>", shell = True, stdout = subprocess.PIPE)

...I get this format when I print(result.stderr):

0.09user 0.00system 0:00.09elapsed

Is there any way I can force the first (real, user, sys) format?

Answer 1

From the man time documentation:

After the utility finishes, time writes the total time elapsed, the time consumed by system overhead, and the time used to execute utility to the standard error stream.

Bold emphasis mine. You are capturing the stdout stream, not the stderr stream, so whatever output you see must be the result of something else mangling your Python stderr stream.

Capture stderr:

proc = subprocess.Popen("time ./<binary>", shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
stdout, stderr = proc.communicate()

The stderr variable then holds the time command output.

If this continues to produce the same output, your /bin/bash implementation has a built-in time command that overrides the /usr/bin/time version (which probably outputs everything on one line). You can force the use of the bash builtin by telling Python to run with that:

proc = subprocess.Popen("time ./<binary>", shell=True, executable='/bin/bash',
                        stdout=subprocess.PIPE, stderr=subprocess.PIPE)
stdout, stderr = proc.communicate()

Answer 2

First: Martijn Pieters' answer is correct about needing to capture time's stderr instead of stdout.

Also, at least on older versions of Python like 3.1, a subprocess.Popen object contains several things that could be considered "output". Attempting to print one just results in:

<subprocess.Popen object at 0x2068fd0>

If later versions are print-able, they must do some processing of their contents, probably including mangling the output.

Reading (and Printing) from Popen Object

The Popen object has a stderr field, which is a readable, file-like object. You can read from it like any other file-like object, although it's not recommended. Quoting the big, pink security warning:

Warning

Use communicate() rather than .stdin.write, .stdout.read or .stderr.read to avoid deadlocks due to any of the other OS pipe buffers filling up and blocking the child process.

To print your Popen's contents, you must:

1. communicate() with the sub-process, assigning the 2-tuple it returns (stdout, stderr) to local variable(s).

2. Convert the variable's contents into strings --- by default, it's a bytes object, as if the "file" had been opened in binary mode.

Below is a tiny program that prints the stderr output of a shell command without mangling (not counting the conversion from ASCII to Unicode and back).

#!/usr/bin/env python3

import subprocess

def main():
    result = subprocess.Popen(
      'time sleep 0.2',
      shell=True,
      stderr=subprocess.PIPE,
      )
    stderr = result.communicate()[1]
    stderr_text = stderr.decode('us-ascii').rstrip('\n')
    #print(stderr_text)  # Prints all lines at once.

    # Or, if you want to process output line-by-line...
    lines = stderr_text.split('\n')
    for line in lines:
        print(line)
    return

if "__main__" == __name__:
    main()

This output is on an old Fedora Linux system, running bash with LC_ALL set to "C":

real	0m0.201s
user	0m0.000s
sys	0m0.001s

Note that you'll want to add some error-handling around my script's stderr_text = stderr.decode(...) line... For all I know, time emits non-ASCII characters depending on localization, environment variables, etc.

Alternative: universal_newlines

You can save some of the decoding boilerplate by using the universal_newlines option to Popen. It does the conversion from bytes to strings automatically:

If universal_newlines is True, these file objects will be opened as text streams in universal newlines mode using the encoding returned by locale.getpreferredencoding(False). [...]

def main_universal_newlines():
    result = subprocess.Popen(
      'time sleep 0.2',
      shell=True,
      stderr=subprocess.PIPE,
      universal_newlines=True,
      )
    stderr_text = result.communicate()[1].rstrip('\n')
    lines = stderr_text.split('\n')
    for line in lines:
        print(line)
    return

Note that I still have to strip the last '\n' manually to exactly match the shell's output.