Accessing stdout when using “time” in python subpr

Question

I have been doing some manual benchmark tests in my shell using the time command. I would like to scale my benchmarks by writing a python script that both automates the tests and affords me access to the time data so that I can record it in the format of my choosing (likely a csv). I see there is the timeit module, but that seems like it is more for benchmarking python code, where what I am trying to benchmark here are programs run in the command line.

This is what I have been doing manually:

time program -aflag -anotherflag

My initial attempt to implement this in a script looks like:

cmnd = ['time', 'program', 'aflag', 'anotherflag']
p = subprocess.Popen(cmnd, shell=False, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
out, err = p.communicate
print out
print err

I can access the output of time just fine – this is delivered to stderr, however I am not getting program's output as expected in stdout. If I remove time from cmnd and change shell=False to True, I then get the program's output in stdout – however obviously not time's output, which is the whole point.

cmnd = ['program', 'aflag', 'anotherflag']
p = subprocess.Popen(cmnd, shell=True, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
out, err = p.communicate
print out
print err

If I add time back to cmnd with shell=True, I get time's output but program doesn't actually run.

How can I get both working?

Answer 1

Instead of trying to get this to work, why not use the functionality built into Python in the resource module?

import resource
import subprocess

cmd = ['program', 'aflag', 'anotherflag']
p = subprocess.Popen(cmd, shell=False, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
out, err = p.communicate()
usage = resource.getrusage(resource.RUSAGE_CHILDREN)
print out
print err
print usage.ru_utime, usage.ru_stime, usage.ru_utime+usage.ru_stime

---

If you need to distinguish different child processes running simultaneously, getrusage isn't obviously not sufficient. In that case, you need to use wait4 or similar to get per-process resource usage. This makes your use of Popen more complicated. What you'd probably want to do for this case is subclass or fork the subprocess code (but make sure to use subprocess32 backport if you're on 3.1 or earlier to avoid the bugs in communicate—and so that the class actually has the method you want to hook…) and change the _try_wait method to use wait4 instead of waitpid and stash the extra results in, e.g., self.rusage so you can access it later.

I think something like this would work:

import subprocess32

class Popen(subprocess32.Popen):
    def _try_wait(self, wait_flags):
        """All callers to this function MUST hold self._waitpid_lock."""
        try:
            (pid, sts, rusage) = _eintr_retry_call(os.wait4, self.pid, wait_flags)
            if pid == self.pid:
                self.rusage = rusage
        except OSError as e:
            if e.errno != errno.ECHILD:
                raise
            pid = self.pid
            sts = 0
        return (pid, sts)

cmd = ['program', 'aflag', 'anotherflag']
p = Popen(cmd, shell=False, stdout=subprocess32.PIPE, stderr=subprocess32.PIPE)
out, err = p.communicate()
print out
print err
try:
    usage = p.rusage
except AttributeError:
    print 'Child died before we could wait on it, no way to get rusage'        
else:
    print usage.ru_utime, usage.ru_stime, usage.ru_utime+usage.ru_stime