python性能分析之cProfile+pstats利器

性能问题解决思路

分析耗时代码

用python开发的程序，如果对性能有要求，很容易遇到性能瓶颈，此时，解决问题的第一步应该是分析性能瓶颈出在哪里，即分析耗时最大的代码或函数是什么，而做这个的利器就是cProfile和 pstats。

针对性地优化

如瓶颈在io（包括磁盘文件读写，控制台输出如print，log，网络io），可以使用异步方案：io操作分离+多线程/协程异步

如瓶颈在cpu，可以使用JIT优化，如pypy，numba等，以及多进程

性能分析

cProfile思路 
1.使用cProfile模块生成脚本执行的统计信息文件 
2.使用pstats格式化统计信息，并根据需要做排序分析处理

1.使用cProfile模块生成脚本执行的统计信息文件 

python3 -m cProfile  -o cpf_out.txt mytest.py 

参数说明： 
使用模块当做脚本运行：-m cProfile 
输出参数：cpf_out.txt
测试的python脚本：test.py 

2.python命令行查看统计信息。 
执行python：

import pstats
p=pstats.Stats('./cpf_out.txt')
p.print_stats()
#根据调用次数排序
p.sort_stats('calls').print_stats()
#根据调用总时间排序
p.sort_stats('cumulative').print_stats()

• *Stats类（pstats.Stats）说明 
  strip_dirs() 用以除去文件名前的路径信息。 
  add(filename,[…]) 把profile的输出文件加入Stats实例中统计 
  dump_stats(filename) 把Stats的统计结果保存到文件 
  sort_stats(key,[…]) 最重要的一个函数，用以排序profile的输出 
  reverse_order() 把Stats实例里的数据反序重排 
  print_stats([restriction,…]) 把Stats报表输出到stdout 
  print_callers([restriction,…]) 输出调用了指定的函数的函数的相关信息 
  print_callees([restriction,…]) 输出指定的函数调用过的函数的相关信息

sort_stats支持以下参数： 

         参数 含义 

• ‘calls’ call count 
• ‘cumulative’ cumulative time 
• ‘file’ file name 
• ‘filename’ file name 
• ‘module’ module name 
• ‘ncalls’ call count 
• ‘pcalls’ primitive call count 
• ‘line’ line number 
• ‘name’ function name 
• ‘nfl’ name/file/line 
• ‘stdname’ standard name 
• ‘time’ internal time 
• ‘tottime’ internal time

*一个比较典型的输出结果： 
197 function calls (192 primitive calls) in 0.002 seconds 
Ordered by: standard name 

ncalls tottime percall cumtime percall filename:lineno(function) 
1 0.000 0.000 0.001 0.001 :1() 
1 0.000 0.000 0.001 0.001 re.py:212(compile) 
1 0.000 0.000 0.001 0.001 re.py:268(_compile) 
1 0.000 0.000 0.000 0.000 sre_compile.py:172(_compile_charset) 
1 0.000 0.000 0.000 0.000 sre_compile.py:201(_optimize_charset) 
4 0.000 0.000 0.000 0.000 sre_compile.py:25(_identityfunction) 
3/1 0.000 0.000 0.000 0.000 sre_compile.py:33(_compile) 

输出结果说明：

共有197次函数调用，原始调用为192次，原始调用说明不包含递归调用。 
以standard name进行排序。

ncalls 函数的被调用次数 : 3/1表示发生了递归调用，1为原始调用次数，3为递归调用次数 
tottime 函数总计运行时间，除去函数中调用的函数运行时间 
percall 函数运行一次的平均时间，等于tottime/ncalls 
cumtime 函数总计运行时间，含调用的函数运行时间 
percall 函数运行一次的平均时间，等于cumtime/ncalls 
filename:lineno(function) 函数所在的文件名，函数的行号，函数名

 

 

另一篇参考博客

https://www.mobibrw.com/2017/7176

例子

Python

 

1 2 3 4 5 6 7 8 9 10

import time def func1():     sum = 0     for i in range(1000000):         sum += i def func2():     time.sleep(10)   func1() func2()

运行

Shell

 

1	$ python -m cProfile del.py

运行结果

结果分析
执行了6个函数，总共花费了10.138s，按着运行函数名字排序为结果输出。

运行脚本

Shell

 

1	$ python -m cProfile -o del.out del.py

这里以模块方式直接保存profile结果，可以进一步分析输出结果，运行

Shell

 

1	$ python -c "import pstats; p=pstats.Stats('del.out'); p.print_stats()"

结果（随机）

可以设置排序方式，例如以花费时间多少排序

Shell

 

1	$ python -c "import pstats; p=pstats.Stats('del.out'); p.sort_stats('time').print_stats()"

sort_stats支持以下参数：

Vim

 

1	calls, cumulative, file, line, module, name, nfl, pcalls, stdname, time

pstats模块还支持交互式

分析函数的调用栈可以使用gprof2dot把调用过程输出成图片。

安装命令如下（Ubuntu 16.04）：

Shell

 

1 2	$ sudo apt-get install python graphviz $ sudo pip install gprof2dot

调用命令如下：

Shell

 

1	$ gprof2dot -f pstats del.out | dot -Tpng -o output.png