Python代码cProfile耗时分析及可视化

Python: cProfile 食用方法

import cProfile

# 直接把分析结果打印到控制台
# loading为需要监测的函数，arg为其参数
cProfile.run("loading(arg)")
# 把分析结果保存到文件中
cProfile.run("loading(arg)", filename="result.out")
# 增加排序方式
cProfile.run("loading(arg)", filename="result.out", sort="cumulative")

输出类似：

         1767148 function calls (1751776 primitive calls) in 3.579 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     2824    0.002    0.000    0.014    0.000 <__array_function__ internals>:2(all)
     7574    0.005    0.000    0.050    0.000 <__array_function__ internals>:2(any)
        2    0.000    0.000    0.000    0.000 <__array_function__ internals>:2(argsort)
        2    0.000    0.000    0.000    0.000 <__array_function__ internals>:2(copyto)
       20    0.000    0.000    0.000    0.000 <__array_function__ internals>:2(count_nonzero)
       47    0.000    0.000    0.000    0.000 <__array_function__ internals>:2(cumsum)
     1441    0.001    0.000    0.009    0.000 <__array_function__ internals>:2(prod)
       47    0.000    0.000    0.001    0.000 <__array_function__ internals>:2(unique)
        1    0.000    0.000    0.000    0.000 <string>:1(<module>)
     1908    0.007    0.000    0.007    0.000 BOX_adjacent.py:10(__init__)
     7750    0.061    0.000    0.164    0.000 BOX_adjacent.py:184(Best_Blok_adj)
     7750    0.002    0.000    0.002    0.000 BOX_adjacent.py:277(<listcomp>)
    27042    0.063    0.000    0.426    0.000 BOX_adjacent.py:29(Can_Load_adj)
      318    0.000    0.000    0.000    0.000 BOX_adjacent.py:291(reset)
    95394    0.007    0.000    0.007    0.000 BOX_adjacent.py:51(<lambda>)
    16944    0.001    0.000    0.001    0.000 BOX_adjacent.py:55(<lambda>)
    34047    0.080    0.000    0.237    0.000 BOX_adjacent.py:81(Possible_Oriatation_adj)
    76384/61012    0.080    0.000    0.178    0.000 copy.py:128(deepcopy)
    15372    0.001    0.000    0.001    0.000 copy.py:182(_deepcopy_atomic)
    ...

其中

共有1767148次函数调用，原始调用为1751776次，原始调用说明不包含递归调用。
以standard name进行排序。76384/61012表示发生了递归调用，61012为原始调用次数，76384为递归调用次数
ncalls 函数的被调用次数
tottime 函数总计运行时间，除去函数中调用的函数运行时间
percall 函数运行一次的平均时间，等于tottime/ncalls
cumtime 函数总计运行时间，含调用的函数运行时间
percall 函数运行一次的平均时间，等于cumtime/ncalls
filename:lineno(function) 函数所在的文件名，函数的行号，函数名

可视化工具 graphviz，gprof2dot

pip install graphviz
pip install gprof2dot

gprof2dot -f pstats result.out | dot -Tpng -o result.png

结果如下：

可以看到check_space_contain被调用了太多次，check代码发现用很多重复的调用，所以简单改一下，只调用一次进行赋值，之后直接拿来用，结果累计调用次数直接降低了30%，节省大量时间，类似可改进的地方还有很多。另外在清楚任务执行与调用关系的情况下，可以做多进程增加运行效率。