Search code examples
pythonperformancesubprocess

Python subprocess check_output much slower than call

I was trying to understand why this is happening. I'm calling a command to restart networking on Ubuntu server 12.04.

Fast execution

When I call the command using one of following three ways it takes around 0.1 seconds to execute:

  1. directly in terminal
  2. python script using os.system
  3. python script using subprocess.call

terminal session:

root@ubuntu:~# time /etc/init.d/networking restart
 * Running /etc/init.d/networking restart
 * Reconfiguring network interfaces...
real    0m0.105s

root@ubuntu:~# time python -c "import os;
> os.system('/etc/init.d/networking restart')"
 * Running /etc/init.d/networking restart
 * Reconfiguring network interfaces...
real    0m0.111s

root@ubuntu:~# time python -c "import subprocess;
> subprocess.call(['/etc/init.d/networking', 'restart'])"
 * Running /etc/init.d/networking restart
 * Reconfiguring network interfaces...
real    0m0.111s

Slow execution

However if I use subprocess.check_output or Popen and try and read the output it takes 23 seconds. Way slower. It seems this dramatic difference only happens when I try and use a function that will return the commands output. I would like to understand why this is happening and find a solution to execute this command and get it's output without it taking so long.

terminal session:

root@ubuntu:~# time python -c "import subprocess;
> print subprocess.check_output(['/etc/init.d/networking', 'restart'])"
 * Running /etc/init.d/networking restart
 * Reconfiguring network interfaces...
real    0m23.201s

root@ubuntu:~# time python -c "from subprocess import Popen, PIPE;
> print Popen(['/etc/init.d/networking', 'restart'], stdout=PIPE).stdout.read()"
 * Running /etc/init.d/networking restart
 * Reconfiguring network interfaces...
real    0m23.201s

Update

One of the comments suggested trying out the tee command. The results where very interesting. In the terminal without any involvement of python if tee is used it takes the same 23 seconds. I am still curious why but at least this might give more of a clue as to what's going on.

root@ubuntu:~# time /etc/init.d/networking restart | tee out.txt
 * Running /etc/init.d/networking restart
 * Reconfiguring network interfaces...
real    0m23.181s
Solution

  • The code below is based on the excellent comment J.F. Sebastian made. The code below runs in 0.1 seconds as expected and returns the output of the command to a string.

    from subprocess import check_call, STDOUT
from tempfile import NamedTemporaryFile

with NamedTemporaryFile() as f:
    check_call(['/etc/init.d/networking', 'restart'], stdout=f, stderr=STDOUT)
    f.seek(0)
    output = f.read()