Python性能分析指南

2013-9-12 10:29| 发布者: 天空之城| 查看: 24269| 评论:1|原作者: 网络转载|来自:开源中国

摘要: 尽管并非每个你写的Python程序都需要严格的性能分析，但了解一下Python的生态系统中很多优秀的在你需要做性能分析的时候可以使用的工具仍然是一件值得去做的事。

英文原文：A guide to analyzing Python performance

 尽管并非每个你写的Python程序都需要严格的性能分析，但了解一下Python的生态系统中很多优秀的在你需要做性能分析的时候可以使用的工具仍然是一件值得去做的事。

分析一个程序的性能，最终都归结为回答4个基本的问题：

1. 程序运行速度有多快？
2. 运行速度瓶颈在哪儿？
3. 程序使用了多少内存？
4. 内存泄露发生在哪里？

下面，我们将使用一些优秀的工具深入回答这些问题。

 使用time工具粗糙定时

首先，我们可以使用快速然而粗糙的工具：古老的unix工具time，来为我们的代码检测运行时间。

1$ time python yourprogram.py

2 

3real    0m1.028s

4user    0m0.001s

5sys     0m0.003s

上面三个输入变量的意义在文章 stackoverflow article 中有详细介绍。简单的说：

• real - 表示实际的程序运行时间
• user - 表示程序在用户态的cpu总时间
• sys - 表示在内核态的cpu总时间

通过sys和user时间的求和，你可以直观的得到系统上没有其他程序运行时你的程序运行所需要的CPU周期。

若sys和user时间之和远远少于real时间，那么你可以猜测你的程序的主要性能问题很可能与IO等待相关。

 使用计时上下文管理器进行细粒度计时

我们的下一个技术涉及访问细粒度计时信息的直接代码指令。这是一小段代码，我发现使用专门的计时测量是非常重要的：

timer.py

01import time

02 

03class Timer(object):

04    def__init__(self, verbose=False):

05        self.verbose= verbose

06 

07    def__enter__(self):

08        self.start= time.time()

09        returnself

10 

11    def__exit__(self,*args):

12        self.end= time.time()

13        self.secs= self.end- self.start

14        self.msecs= self.secs* 1000  # millisecs

15        ifself.verbose:

16            print'elapsed time: %f ms' % self.msecs

为了使用它，你需要用Python的with关键字和Timer上下文管理器包装想要计时的代码块。它将会在你的代码块开始执行的时候启动计时器，在你的代码块结束的时候停止计时器。

这是一个使用上述代码片段的例子：

01from timer import Timer

02from redis import Redis

03rdb =Redis()

04 

05with Timer() as t:

06    rdb.lpush("foo","bar")

07print "=> elasped lpush: %s s" % t.secs

08 

09with Timer as t:

10    rdb.lpop("foo")

11print "=> elasped lpop: %s s" % t.secs

我经常将这些计时器的输出记录到文件中，这样就可以观察我的程序的性能如何随着时间进化。 

 使用分析器逐行统计时间和执行频率

Robert Kern有一个称作line_profiler的不错的项目，我经常使用它查看我的脚步中每行代码多快多频繁的被执行。

想要使用它，你需要通过pip安装该python包：

1$ pip install line_profiler

一旦安装完成，你将会使用一个称做“line_profiler”的新模组和一个“kernprof.py”可执行脚本。

想要使用该工具，首先修改你的源代码，在想要测量的函数上装饰@profile装饰器。不要担心，你不需要导入任何模组。kernprof.py脚本将会在执行的时候将它自动地注入到你的脚步的运行时。

primes.py

01@profile

02def primes(n):

03    ifn==2:

04        return[2]

05    elifn<2:

06        return[]

07    s=range(3,n+1,2)

08    mroot= n **0.5

09    half=(n+1)/2-1

10    i=0

11    m=3

12    whilem <= mroot:

13        ifs[i]:

14            j=(m*m-3)/2

15            s[j]=0

16            whilej<half:

17                s[j]=0

18                j+=m

19        i=i+1

20        m=2*i+3

21    return[2]+[xfor x ins if x]

22primes(100)

一旦你已经设置好了@profile装饰器，使用kernprof.py执行你的脚步。

1$ kernprof.py -l -v fib.py

-l选项通知kernprof注入@profile装饰器到你的脚步的内建函数，-v选项通知kernprof在脚本执行完毕的时候显示计时信息。上述脚本的输出看起来像这样：

01Wrote profile results to primes.py.lprof

02Timer unit: 1e-06 s

03 

04File: primes.py

05Function: primes at line 2

06Total time: 0.00019 s

07 

08Line #      Hits         Time  Per Hit   % Time  Line Contents

09==============================================================

10     2                                           @profile

11     3                                           def primes(n):

12     4         1            2      2.0      1.1     if n==2:

13     5                                                  return [2]

14     6         1            1      1.0      0.5     elif n<2:

15     7                                                  return []

16     8         1            4      4.0      2.1      s=range(3,n+1,2)

17     9         1           10     10.0      5.3      mroot = n ** 0.5

18    10         1            2      2.0      1.1      half=(n+1)/2-1

19    11         1            1      1.0      0.5      i=0

20    12         1            1      1.0      0.5      m=3

21    13         5            7      1.4      3.7     while m <= mroot:

22    14         4            4      1.0      2.1         if s[i]:

23    15         3            4      1.3      2.1              j=(m*m-3)/2

24    16         3            4      1.3      2.1              s[j]=0

25    17        31           31      1.0     16.3             while j<half:

26    18        28           28      1.0     14.7                  s[j]=0

27    19        28           29      1.0     15.3                  j+=m

28    20         4            4      1.0      2.1          i=i+1

29    21         4            4      1.0      2.1          m=2*i+3

30    22        50           54      1.1     28.4     return [2]+[x forx in s if x]

寻找具有高Hits值或高Time值的行。这些就是可以通过优化带来最大改善的地方。 

 程序使用了多少内存？

现在我们对计时有了较好的理解，那么让我们继续弄清楚程序使用了多少内存。我们很幸运，Fabian Pedregosa模仿Robert Kern的line_profiler实现了一个不错的内存分析器。

首先使用pip安装:

1$ pip install-U memory_profiler

2$ pip installpsutil

（这里建议安装psutil包，因为它可以大大改善memory_profiler的性能）。

就像line_profiler，memory_profiler也需要在感兴趣的函数上面装饰@profile装饰器：

1@profile

2def primes(n):

3    ...

4    ...

想要观察你的函数使用了多少内存，像下面这样执行：

1$ python -m memory_profiler primes.py

一旦程序退出，你将会看到看起来像这样的输出：

01Filename: primes.py

02 

03Line #    Mem usage  Increment   Line Contents

04==============================================

05     2                          @profile

06     3   7.9219 MB  0.0000MB   def primes(n):

07     4   7.9219 MB  0.0000MB       if n==2:

08     5                                  return [2]

09     6   7.9219 MB  0.0000MB       elif n<2:

10     7                                  return []

11     8   7.9219 MB  0.0000MB       s=range(3,n+1,2)

12     9   7.9258 MB  0.0039MB       mroot = n ** 0.5

13    10   7.9258 MB  0.0000MB       half=(n+1)/2-1

14    11   7.9258 MB  0.0000MB       i=0

15    12   7.9258 MB  0.0000MB       m=3

16    13   7.9297 MB  0.0039MB       while m <= mroot:

17    14   7.9297 MB  0.0000MB           if s[i]:

18    15   7.9297 MB  0.0000MB               j=(m*m-3)/2

19    16   7.9258 MB -0.0039MB               s[j]=0

20    17   7.9297 MB  0.0039MB               while j<half:

21    18   7.9297 MB  0.0000MB                   s[j]=0

22    19   7.9297 MB  0.0000MB                   j+=m

23    20   7.9297 MB  0.0000MB           i=i+1

24    21   7.9297 MB  0.0000MB           m=2*i+3

25    22   7.9297 MB  0.0000MB       return [2]+[xfor x ins if x]

 line_profiler和memory_profiler的IPython快捷方式

memory_profiler和line_profiler有一个鲜为人知的小窍门，两者都有在IPython中的快捷命令。你需要做的就是在IPython会话中输入以下内容：

1%load_ext memory_profiler

2%load_ext line_profiler

在这样做的时候你需要访问魔法命令%lprun和%mprun，它们的行为类似于他们的命令行形式。主要区别是你不需要使用@profiledecorator来修饰你要分析的函数。只需要在IPython会话中像先前一样直接运行分析：

1In [1]: from primesimport primes

2In [2]: %mprun -f primes primes(1000)

3In [3]: %lprun -f primes primes(1000)

这样可以节省你很多时间和精力，因为你的源代码不需要为使用这些分析命令而进行修改。 

 内存泄漏在哪里？

cPython解释器使用引用计数做为记录内存使用的主要方法。这意味着每个对象包含一个计数器，当某处对该对象的引用被存储时计数器增加，当引用被删除时计数器递减。当计数器到达零时，cPython解释器就知道该对象不再被使用，所以删除对象，释放占用的内存。

如果程序中不再被使用的对象的引用一直被占有，那么就经常发生内存泄漏。

查找这种“内存泄漏”最快的方式是使用Marius Gedminas编写的objgraph，这是一个极好的工具。该工具允许你查看内存中对象的数量，定位含有该对象的引用的所有代码的位置。 

 一开始，首先安装objgraph:

1pip install objgraph

一旦你已经安装了这个工具，在你的代码中插入一行声明调用调试器：

1import pdb; pdb.set_trace()

最普遍的对象是哪些？

在运行的时候，你可以通过执行下述指令查看程序中前20个最普遍的对象：

01(pdb) importobjgraph

02(pdb) objgraph.show_most_common_types()

03 

04MyBigFatObject            20000

05tuple                     16938

06function                  4310

07dict                      2790

08wrapper_descriptor        1181

09builtin_function_or_method934

10weakref                   764

11list                      634

12method_descriptor         507

13getset_descriptor         451

14type                      439

哪些对象已经被添加或删除？

我们也可以查看两个时间点之间那些对象已经被添加或删除：

01(pdb) importobjgraph

02(pdb) objgraph.show_growth()

03.

04.

05.

06(pdb) objgraph.show_growth()  # this only shows objects that has been added or deleted since last show_growth() call

07 

08traceback               4        +2

09KeyboardInterrupt       1        +1

10frame                  24        +1

11list                  667        +1

12tuple               16969        +1

谁引用着泄漏的对象？

继续，你还可以查看哪里包含给定对象的引用。让我们以下述简单的程序做为一个例子：

1x =[1]

2y =[x, [x], {"a":x}]

3import pdb; pdb.set_trace()

想要看看哪里包含变量x的引用，执行objgraph.show_backref()函数：

1(pdb) importobjgraph

2(pdb) objgraph.show_backref([x], filename="/tmp/backrefs.png")

 该命令的输出应该是一副PNG图像，保存在/tmp/backrefs.png，它看起来是像这样：

最下面有红字的盒子是我们感兴趣的对象。我们可以看到，它被符号x引用了一次，被列表y引用了三次。如果是x引起了一个内存泄漏，我们可以使用这个方法，通过跟踪它的所有引用，来检查为什么它没有自动的被释放。

回顾一下，objgraph 使我们可以：

• 显示占据python程序内存的头N个对象
• 显示一段时间以后哪些对象被删除活增加了
• 在我们的脚本中显示某个给定对象的所有引用 

 努力与精度

在本帖中，我给你显示了怎样用几个工具来分析python程序的性能。通过这些工具与技术的武装，你可以获得所有需要的信息，来跟踪一个python程序中大多数的内存泄漏，以及识别出其速度瓶颈。

对许多其他观点来说，运行一次性能分析就意味着在努力目标与事实精度之间做出平衡。如果感到困惑，那么就实现能适应你目前需求的最简单的解决方案。

参考

• stack overflow - time explained（堆栈溢出 - 时间解释）
• line_profiler（线性分析器）
• memory_profiler（内存分析器）
• objgraph（对象图）