捕获过程输出时产生性能

我正在尝试使用posix_spawn而不是fork / exec来获得一些性能增益。 我目前的项目是用Python编写的,所以我使用了这个Python绑定。 此外,我尝试了它的一些分支,之后我在Cython中编写了自己的posix_spawn绑定(以消除一些依赖关系),但获得了几乎相同的结果。

当我只需要在不捕获stdout / stderr的情况下运行进程时,确实有显着的提速。 但是当我确实需要它时(对于我的项目来说这是必要的),posix_spawn调用变得和fork / exec调用一样慢。 此外,它依赖于分配内存的数量与fork / exec相同。 即使进程实际上没有产生任何输出,它也会发生 - 我检查了/ bin / true。 我仍然无法解释这种行为。 对于fork / exec(通过子进程模块),只要输出不是太大,我们是否读取过程输出没有显着差异。

这是我的测试脚本(省略了导入和分析代码)

 # test.py
 def spawn_no_out(args):
    command = args[0]
    pid = posix_spawn(command, args)
    status, rusage = exits(pid)

 def spawn(args):

    # Prepare pipes to capture stdout and stderr
    stdout_read, stdout_write = os.pipe()
    stderr_read, stderr_write = os.pipe()
    fa = FileActions()
    fa.add_dup2(stdout_write, 1)
    fa.add_close(stdout_read)
    fa.add_dup2(stderr_write, 2)
    fa.add_close(stderr_read)

    # Spawn the process
    command = args[0]
    pid = posix_spawn(command, args, file_actions=fa)

    # Read and close file descriptors
    os.close(stdout_write)
    os.close(stderr_write)
    status, rusage = exits(pid)
    out = os.fdopen(stdout_read)
    err = os.fdopen(stderr_read)
    return out, err

 def fork(args):
    return Popen(args, stdout=PIPE, stderr=PIPE).communicate()

 def fork_no_out(args):
    return subprocess.call(args)

 def run_benchmark(func, args, count):
    for _ in xrange(count):
       func(args)
    print "%s: %ds" % (func.__name__, time.time() - start)

 def main():
    # Reads from stdout the number of process spawns and size of allocated memory
    args = ["/bin/true"]
    count = int(sys.argv[1]) if len(sys.argv) > 1 else 1000
    mem_size = int(sys.argv[2]) if len(sys.argv) > 2 else 10000000
    some_allocated_memory = range(mem_size)
    for func in [spawn, spawn_no_out, fork, fork_no_out]:
        run_benchmark(func, args, count)


 if __name__ == "__main__":
    main()

测试输出不分配额外内存:

./test.py 10000 1
spawn: 34s
         3754834 function calls (3754776 primitive calls) in 33.517 seconds

   Ordered by: internal time, cumulative time
   List reduced from 144 to 5 due to restriction 

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    10000   15.475    0.002   15.475    0.002 {posix.wait4}
    10000    5.850    0.001    5.850    0.001 {_cffi__x2c5d2681xf492c09f.posix_spawn}
    10000    3.217    0.000   12.750    0.001 /usr/local/lib/python2.7/dist-packages/posix_spawn-0.1-py2.7.egg/posix_spawn/_impl.py:75(posix_spawn)
    10000    2.242    0.000   33.280    0.003 ./test.py:23(spawn)
   660000    1.777    0.000    3.159    0.000 /usr/local/lib/python2.7/dist-packages/cffi/api.py:212(new)



spawn_no_out: 14s
         3340013 function calls in 14.631 seconds

   Ordered by: internal time, cumulative time
   List reduced from 25 to 5 due to restriction 

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    10000    7.466    0.001    7.466    0.001 {posix.wait4}
    10000    2.012    0.000    2.012    0.000 {_cffi__x2c5d2681xf492c09f.posix_spawn}
    10000    1.658    0.000    6.994    0.001 /usr/local/lib/python2.7/dist-packages/posix_spawn-0.1-py2.7.egg/posix_spawn/_impl.py:75(posix_spawn)
   650000    1.640    0.000    2.919    0.000 /usr/local/lib/python2.7/dist-packages/cffi/api.py:212(new)
   650000    0.496    0.000    0.496    0.000 {_cffi_backend.newp}



fork: 40s
         840094 function calls in 40.745 seconds

   Ordered by: internal time, cumulative time
   List reduced from 53 to 5 due to restriction 

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    10000   19.460    0.002   19.460    0.002 {posix.read}
    10000    6.505    0.001    6.505    0.001 {posix.fork}
    10081    4.667    0.000    4.667    0.000 {built-in method poll}
    10000    2.773    0.000   30.190    0.003 /usr/lib/python2.7/subprocess.py:1187(_execute_child)
    10000    0.814    0.000   32.996    0.003 /usr/lib/python2.7/subprocess.py:650(__init__)



fork_no_out: 38s
         330013 function calls in 38.488 seconds

   Ordered by: internal time, cumulative time
   List reduced from 36 to 5 due to restriction 

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    10000   18.179    0.002   18.179    0.002 {posix.read}
    10000    6.904    0.001    6.904    0.001 {posix.waitpid}
    10000    6.613    0.001    6.613    0.001 {posix.fork}
    10000    2.633    0.000   28.976    0.003 /usr/lib/python2.7/subprocess.py:1187(_execute_child)
    10000    0.880    0.000   30.070    0.003 /usr/lib/python2.7/subprocess.py:650(__init__)

用分配的内存测试10000000个整数列表的内存(必须减少调用次数):

./test.py 1000 10000000
spawn: 20s
         379834 function calls (379776 primitive calls) in 20.022 seconds

   Ordered by: internal time, cumulative time
   List reduced from 144 to 5 due to restriction 

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1000   10.022    0.010   10.022    0.010 {posix.wait4}
     1000    8.705    0.009    8.705    0.009 {_cffi__x2c5d2681xf492c09f.posix_spawn}
     1000    0.334    0.000    9.412    0.009 /usr/local/lib/python2.7/dist-packages/posix_spawn-0.1-py2.7.egg/posix_spawn/_impl.py:75(posix_spawn)
     1000    0.269    0.000   19.998    0.020 ./test.py:18(spawn)
    66000    0.174    0.000    0.318    0.000 /usr/local/lib/python2.7/dist-packages/cffi/api.py:212(new)



spawn_no_out: 1s
         334013 function calls in 1.480 seconds

   Ordered by: internal time, cumulative time
   List reduced from 25 to 5 due to restriction 

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1000    0.755    0.001    0.755    0.001 {posix.wait4}
     1000    0.198    0.000    0.198    0.000 {_cffi__x2c5d2681xf492c09f.posix_spawn}
     1000    0.171    0.000    0.708    0.001 /usr/local/lib/python2.7/dist-packages/posix_spawn-0.1-py2.7.egg/posix_spawn/_impl.py:75(posix_spawn)
    65000    0.167    0.000    0.298    0.000 /usr/local/lib/python2.7/dist-packages/cffi/api.py:212(new)
    65000    0.050    0.000    0.050    0.000 {_cffi_backend.newp}



fork: 18s
         84067 function calls in 18.554 seconds

   Ordered by: internal time, cumulative time
   List reduced from 53 to 5 due to restriction 

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1000    9.399    0.009    9.399    0.009 {posix.read}
     1000    7.815    0.008    7.815    0.008 {posix.fork}
     1054    0.414    0.000    0.414    0.000 {built-in method poll}
     1000    0.274    0.000   17.626    0.018 /usr/lib/python2.7/subprocess.py:1187(_execute_child)
     1000    0.078    0.000   17.871    0.018 /usr/lib/python2.7/subprocess.py:650(__init__)



fork_no_out: 18s
         33013 function calls in 18.732 seconds

   Ordered by: internal time, cumulative time
   List reduced from 36 to 5 due to restriction 

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1000    9.467    0.009    9.467    0.009 {posix.read}
     1000    8.020    0.008    8.020    0.008 {posix.fork}
     1000    0.603    0.001    0.603    0.001 {posix.waitpid}
     1000    0.280    0.000   17.910    0.018 /usr/lib/python2.7/subprocess.py:1187(_execute_child)
     1000    0.072    0.000   18.000    0.018 /usr/lib/python2.7/subprocess.py:650(__init__)

没有分析结果是一样的。 正如我们所看到的,当我们在调用posix_spawn和不用捕获过程输出的情况下,性能有很大差异(1.4s vs 20s!)。 没有额外的沉重电话 - posix.wait4只需要更多时间。 我在这里做错了什么? 有人知道为什么会发生这种情况,以及如何为posix_spawn获得更好的性能?

PS在Linux Mint 17和CentOS 6.5上测试 - 结果相同。

更新 :即使我们将空FileActions对象传递给posix_spawn,但实际上没有读取stdout / stderr,也会发生相同的性能下降:

def spawn(args):
    command = args[0]
    pid = posix_spawn(command, args, file_actions=FileActions())
    status, rusage = exits(pid)

好吧,对于后代 - 看起来如果file_actions被设置并且某些标志没有被设置,posix_spawn只是使用fork:https://sourceware.org/git/?p = glibc.git; a = bllob; f = sysdeps /posix/spawni.c;h=2d3ae941dd19f0348ed95c0b957c68c3c0e9815d;hb=c758a6861537815c759cba2018a3b1abb1943842#l97


从函数的源代码中,链接在alexgorin的答案中,在我看来,这个标志规定了其他参数:

POSIX_SPAWN_USEVFORK

试试吧,让我知道

链接地址: http://www.djcxy.com/p/86471.html

上一篇: spawn performance when capturing process output

下一篇: threaded Python affected by the GIL