Python性能分析指南(1)
Python性能分析指南(1)
尽管并非每个你写的Python程序都需要严格的性能分析,但了解一下Python的生态系统中很多优秀的在你需要做性能分析的时候可以使用的工具仍然是一件值得去做的事。
分析一个程序的性能,最终都归结为回答4个基本的问题:
下面,我们将使用一些优秀的工具深入回答这些问题。
使用time工具粗糙定时
首先,我们可以使用快速然而粗糙的工具:古老的unix工具time,来为我们的代码检测运行时间。
- $ time python yourprogram.py
- real 0m1.028s
- user 0m0.001s
- sys 0m0.003s
上面三个输入变量的意义在文章 stackoverflow article 中有详细介绍。简单的说:
- real - 表示实际的程序运行时间
- user - 表示程序在用户态的cpu总时间
- sys - 表示在内核态的cpu总时间
通过sys和user时间的求和,你可以直观的得到系统上没有其他程序运行时你的程序运行所需要的CPU周期。
若sys和user时间之和远远少于real时间,那么你可以猜测你的程序的主要性能问题很可能与IO等待相关。
使用计时上下文管理器进行细粒度计时
我们的下一个技术涉及访问细粒度计时信息的直接代码指令。这是一小段代码,我发现使用专门的计时测量是非常重要的:
timer.py
- import time
- class Timer(object):
- def __init__(self, verbose=False):
- self.verbose = verbose
- def __enter__(self):
- self.start = time.time()
- return self
- def __exit__(self, *args):
- self.end = time.time()
- self.secs = self.end - self.start
- self.msecs = self.secs * 1000 # millisecs
- if self.verbose:
- print 'elapsed time: %f ms' % self.msecs
为了使用它,你需要用Python的with关键字和Timer上下文管理器包装想要计时的代码块。它将会在你的代码块开始执行的时候启动计时器,在你的代码块结束的时候停止计时器。
这是一个使用上述代码片段的例子:
- from timer import Timer
- from redis import Redis
- rdb = Redis()
- with Timer() as t:
- rdb.lpush("foo", "bar")
- print "=> elasped lpush: %s s" % t.secs
- with Timer as t:
- rdb.lpop("foo")
- print "=> elasped lpop: %s s" % t.secs
我经常将这些计时器的输出记录到文件中,这样就可以观察我的程序的性能如何随着时间进化。
使用分析器逐行统计时间和执行频率
Robert Kern有一个称作line_profiler的不错的项目,我经常使用它查看我的脚步中每行代码多快多频繁的被执行。
想要使用它,你需要通过pip安装该python包:
- $ pip install line_profiler
一旦安装完成,你将会使用一个称做“line_profiler”的新模组和一个“kernprof.py”可执行脚本。
想要使用该工具,首先修改你的源代码,在想要测量的函数上装饰@profile装饰器。不要担心,你不需要导入任何模组。kernprof.py脚本将会在执行的时候将它自动地注入到你的脚步的运行时。
primes.py
- @profile
- def primes(n):
- if n==2:
- return [2]
- elif n<2:
- return []
- s=range(3,n+1,2)
- mroot = n ** 0.5
- half=(n+1)/2-1
- i=0
- m=3
- while m <= mroot:
- if s[i]:
- j=(m*m-3)/2
- s[j]=0
- while j<half:
- s[j]=0
- j+=m
- i=i+1
- m=2*i+3
- return [2]+[x for x in s if x]
- primes(100)
一旦你已经设置好了@profile装饰器,使用kernprof.py执行你的脚步。
- $ kernprof.py -l -v fib.py
-l选项通知kernprof注入@profile装饰器到你的脚步的内建函数,-v选项通知kernprof在脚本执行完毕的时候显示计时信息。上述脚本的输出看起来像这样:
- Wrote profile results to primes.py.lprof
- Timer unit: 1e-06 s
- File: primes.py
- Function: primes at line 2
- Total time: 0.00019 s
- Line # Hits Time Per Hit % Time Line Contents
- ==============================================================
- 2 @profile
- 3 def primes(n):
- 4 1 2 2.0 1.1 if n==2:
- 5 return [2]
- 6 1 1 1.0 0.5 elif n<2:
- 7 return []
- 8 1 4 4.0 2.1 s=range(3,n+1,2)
- 9 1 10 10.0 5.3 mroot = n ** 0.5
- 10 1 2 2.0 1.1 half=(n+1)/2-1
- 11 1 1 1.0 0.5 i=0
- 12 1 1 1.0 0.5 m=3
- 13 5 7 1.4 3.7 while m <= mroot:
- 14 4 4 1.0 2.1 if s[i]:
- 15 3 4 1.3 2.1 j=(m*m-3)/2
- 16 3 4 1.3 2.1 s[j]=0
- 17 31 31 1.0 16.3 while j<half:
- 18 28 28 1.0 14.7 s[j]=0
- 19 28 29 1.0 15.3 j+=m
- 20 4 4 1.0 2.1 i=i+1
- 21 4 4 1.0 2.1 m=2*i+3
- 22 50 54 1.1 28.4 return [2]+[x for x in s if x]
寻找具有高Hits值或高Time值的行。这些就是可以通过优化带来最大改善的地方。
评论关闭