虽然并非你编写的每个 Python 程序都要求一个严格的性能分析,但是让人放心的是,当问题发生的时候,Python 生态圈有各种各样的工具可以处理这类问题。
分析程序的性能可以归结为回答四个基本问题:
- 正运行的多快
- 速度瓶颈在哪里
- 内存使用率是多少
- 内存泄露在哪里
下面,我们将用一些神奇的工具深入到这些问题的答案中去。
用 time 粗粒度的计算时间
让我们开始通过使用一个快速和粗暴的方法计算我们的代码:传统的 unix time 工具。
1
2
3
4
|
$ time python yourprogram.py
real 0m1 . 028s
user 0m0 . 001s
sys 0m0 . 003s
|
三个输出测量值之间的详细意义在这里 * article,但简介在这:
- real — 指的是实际耗时
- user — 指的是内核之外的 CPU 耗时
- sys — 指的是花费在内核特定函数的 CPU 耗时
你会有你的应用程序用完了多少 CPU 周期的即视感,不管系统上其他运行的程序添加的系统和用户时间。
如果 sys 和 user 时间之和小于 real 时间,然后你可以猜测到大多数程序的性能问题最有可能与 IO wait 相关。
用 timing context 管理器细粒度的计算时间
我们下一步的技术包括直接嵌入代码来获取细粒度的计时信息。下面是我进行时间测量的代码的一个小片段
timer.py
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
|
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 上下文管理器来包装你想计算的代码。当您的代码块开始执行,它将照顾启动计时器,当你的代码块结束的时候,它将停止计时器。
这个代码片段示例:
1
2
3
4
5
6
7
8
9
10
11
|
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
|
为了看看我的程序的性能随着时间的演化的趋势,我常常记录这些定时器的输出到一个文件中。
使用 profiler 逐行计时和分析执行的频率
罗伯特·克恩有一个不错的项目称为 line_profiler , 我经常使用它来分析我的脚本有多快,以及每行代码执行的频率:
为了使用它,你可以通过使用 pip 来安装它:
1
|
pip install line_profiler
|
安装完成后,你将获得一个新模块称为 line_profiler 和 kernprof.py 可执行脚本。
为了使用这个工具,首先在你想测量的函数上设置 @profile 修饰符。不用担心,为了这个修饰符,你不需要引入任何东西。kernprof.py 脚本会在运行时自动注入你的脚本。
primes.py
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
|
@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 运行这个脚本。
1
|
kernprof.py - l - v fib.py
|
-l 选项告诉 kernprof 把修饰符 @profile 注入你的脚本,-v 选项告诉 kernprof 一旦你的脚本完成后,展示计时信息。这是一个以上脚本的类似输出:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
|
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
|
寻找 hits 值比较高的行或是一个高时间间隔。这些地方有最大的优化改进空间。
它使用了多少内存?
现在我们掌握了很好我们代码的计时信息,让我们继续找出我们的程序使用了多少内存。我们真是非常幸运, F* Pedregosa 仿照 Robert Kern 的 line_profiler 实现了一个很好的内存分析器 [memory profiler][5]。
首先通过 pip 安装它:
1
2
|
$ pip install - U memory_profiler
$ pip install psutil
|
在这里建议安装 psutil 是因为该包能提升 memory_profiler 的性能。
想 line_profiler 一样, memory_profiler 要求在你设置 @profile 来修饰你的函数:
1
2
3
4
|
@profile
def primes(n):
...
...
|
运行如下命令来显示你的函数使用了多少内存:
1
|
$ python - m memory_profiler primes.py
|
一旦你的程序退出,你应该可以看到这样的输出:
Filename: primes.py
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
|
Line # Mem usage Increment Line Contents
= = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = = =
2 @profile
3 7.9219 MB 0.0000 MB def primes(n):
4 7.9219 MB 0.0000 MB if n = = 2 :
5 return [ 2 ]
6 7.9219 MB 0.0000 MB elif n< 2 :
7 return []
8 7.9219 MB 0.0000 MB s = range ( 3 ,n + 1 , 2 )
9 7.9258 MB 0.0039 MB mroot = n * * 0.5
10 7.9258 MB 0.0000 MB half = (n + 1 ) / 2 - 1
11 7.9258 MB 0.0000 MB i = 0
12 7.9258 MB 0.0000 MB m = 3
13 7.9297 MB 0.0039 MB while m < = mroot:
14 7.9297 MB 0.0000 MB if s[i]:
15 7.9297 MB 0.0000 MB j = (m * m - 3 ) / 2
16 7.9258 MB - 0.0039 MB s[j] = 0
17 7.9297 MB 0.0039 MB while j<half:
18 7.9297 MB 0.0000 MB s[j] = 0
19 7.9297 MB 0.0000 MB j + = m
20 7.9297 MB 0.0000 MB i = i + 1
21 7.9297 MB 0.0000 MB m = 2 * i + 3
22 7.9297 MB 0.0000 MB return [ 2 ] + [x for x in s if x]
|
line_profiler 和 memory_profiler 的 IPython 快捷命令
line_profiler 和 memory_profiler 一个鲜为人知的特性就是在 IPython 上都有快捷命令。你所能做的就是在 IPython 上键入以下命令:
1
2
|
% load_ext memory_profiler
% load_ext line_profiler
|
这样做了以后,你就可以使用魔法命令 %lprun 和 %mprun 了,它们表现的像它们命令行的副本,最主要的不同就是你不需要给你需要分析的函数设置 @profile 修饰符。直接在你的 IPython 会话上继续分析吧。
1
2
3
|
In [ 1 ]: from primes import primes
In [ 2 ]: % mprun - f primes primes( 1000 )
In [ 3 ]: % lprun - f primes primes( 1000 )
|
这可以节省你大量的时间和精力,因为使用这些分析命令,你不需要修改你的源代码。
哪里内存溢出了?
cPython的解释器使用引用计数来作为它跟踪内存的主要方法。这意味着每个对象持有一个计数器,当增加某个对象的引用存储的时候,计数器就会增加,当一个引用被删除的时候,计数器就是减少。当计数器达到0, cPython 解释器就知道该对象不再使用,因此解释器将删除这个对象,并且释放该对象持有的内存。
内存泄漏往往发生在即使该对象不再使用的时候,你的程序还持有对该对象的引用。
最快速发现内存泄漏的方式就是使用一个由 Marius Gedminas 编写的非常好的称为 [objgraph][6] 的工具。
这个工具可以让你看到在内存中对象的数量,也定位在代码中所有不同的地方,对这些对象的引用。
开始,我们首先安装 objgraph
1
|
pip install objgraph
|
一旦你安装了这个工具,在你的代码中插入一个调用调试器的声明。
1
|
import pdb; pdb.set_trace()
|
哪个对象最常见
在运行时,你可以检查在运行在你的程序中的前20名最普遍的对象
1
2
3
4
5
6
7
8
9
10
11
12
13
14
|
(pdb) import objgraph
(pdb) objgraph.show_most_common_types()
MyBigFatObject 20000
tuple 16938
function 4310
dict 2790
wrapper_descriptor 1181
builtin_function_or_method 934
weakref 764
list 634
method_descriptor 507
getset_descriptor 451
type 439
|
哪个对象被增加或是删除了?
我们能在两个时间点之间看到哪些对象被增加或是删除了。
1
2
3
4
5
6
7
8
9
10
11
12
|
(pdb) import objgraph
(pdb) objgraph.show_growth()
.
.
.
(pdb) objgraph.show_growth() # this only shows objects that has been added or deleted since last show_growth() call
traceback 4 + 2
KeyboardInterrupt 1 + 1
frame 24 + 1
list 667 + 1
tuple 16969 + 1
|
这个泄漏对象的引用是什么?
继续下去,我们还可以看到任何给定对象的引用在什么地方。让我们以下面这个简单的程序举个例子。
1
2
3
|
x = [ 1 ]
y = [x, [x], { "a" :x}]
import pdb; pdb.set_trace()
|
为了看到持有变量 X 的引用是什么,运行 objgraph.show_backref() 函数:
1
2
|
(pdb) import objgraph
(pdb) objgraph.show_backref([x], filename = "/tmp/backrefs.png" )
|
该命令的输出是一个 PNG 图片,被存储在 /tmp/backrefs.png,它应该看起来像这样:
backrefs (1)
盒子底部有红色字体就是我们感兴趣的对象,我们可以看到它被符号 x 引用了一次,被列表 y 引用了三次。如果 x 这个对象引起了内存泄漏,我们可以使用这种方法来追踪它的所有引用,以便看到为什么它没有被自动被收回。
回顾一遍,objgraph 允许我们:
- 显示占用 Python 程序内存的前 N 个对象
- 显示在一段时期内哪些对象被增加了,哪些对象被删除了
- 显示我们脚本中获得的所有引用
Effort vs precision
在这篇文章中,我展示了如何使用一些工具来分析一个python程序的性能。通过这些工具和技术的武装,你应该可以获取所有要求追踪大多数内存泄漏以及在Python程序快速识别瓶颈的信息。
和许多其他主题一样,运行性能分析意味着要在付出和精度之间的平衡做取舍。当有疑问是,用最简单的方案,满足你当前的需求。