Python性能分析器 -- cProfile

摘要: 《Python性能分析与优化》笔记 part2，cProfile

【对算法，数学，计算机感兴趣的同学，欢迎关注我哈，阅读更多原创文章】
我的网站：潮汐朝夕的生活实验室
我的公众号：算法题刷刷
我的知乎：潮汐朝夕
我的github：FennelDumplings
我的leetcode：FennelDumplings

---

在文章Python性能分析基础中，我们学习了性能分析的基础知识方法论，如果把性能分析方法整合到开发过程中，就可以帮助我们提高产品的开发质量。

本文我们学习 Python 性能分析器 cProfile。

---

cProfile

cProfile 是一种确定性的性能分析器，提供了一组 API 帮助开发者收集 Python 程序运行的信息，更确切地说，是统计每个函数消耗的 CPU 时间。同时它还提供了其他细节，比如函数被调用的次数。

cProfile 只测量 CPU 时间，并不关心内存消耗和其他与内存相关的信息统计。

确定性的性能分析器其实就是基于事件的性能分析器的另一种说法。也就是说，这个性能分析器会关注代码运行过程中的函数调用、返回语句等事件，甚至可以测量程序运行期间发生的每一个事件。

cProfile 是标准库的组件，无需安装。

例子

import cProfile

def fib(n):
    if n == 0:
        return 0
    elif n == 1:
        return 1
    else:
        return fib(n - 1) + fib(n - 2)

def fib_seq(n):
    seq = []
    if n > 0:
        seq.extend(fib_seq(n - 1))
    seq.append(fib(n))
    return seq

cProfile.run("fib_seq(30)")

输出结果如下:

         7049218 function calls (96 primitive calls) in 1.408 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    1.407    1.407 <string>:1(<module>)
     31/1    0.000    0.000    1.407    1.407 re_compile.py:11(fib_seq)
7049123/31    1.407    0.000    1.407    0.045 re_compile.py:3(fib)
        1    0.000    0.000    1.408    1.408 {built-in method builtins.exec}
       31    0.000    0.000    0.000    0.000 {method 'append' of 'list' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
       30    0.000    0.000    0.000    0.000 {method 'extend' of 'list' objects}

我们可以从这个结果中收集到以下信息

(1) 第一行

一共 7049218 个函数调用被监控，其中 96 个原生调用，即这 195 个调用不涉及递归

(2) ncalls

ncalls 表示函数调用的次数。如果在这一列中有两个数值,就表示有递归调用。第二个数值是原生调用的次数,第一个数值是总调用次数。

这个数值可以帮助识别潜在的bug(当数值大得异乎寻常时可能就是bug),或者可能需要进行内联函数扩展(inlineexpansion)的位置。

(3) tottime

tottime是函数内部消耗的总时间(不包括调用其他函数的时间)。

这列信息可以帮助我们找到可以进行优化的、运行时间较长的循环。

(4) tottime 之后的 percall

percall是tottime除以ncalls,表示一个函数每次调用的平均消耗时间。

(5) cumtime

cumtime 是之前所有子函数消耗时间的累计和(也包含递归调用时间)。

这个数值可以帮助开发者从整体视角识别性能问题,比如算法选择错误。

(6) cumtime 之后的 percall

另一个percall是用cumtime除以原生调用的数量,表示到该函数调用时,每个原生调用的平均消耗时间。

(7) filename:lineno(function)

被分析函数所在的文件名、行号、函数名。

cProfile 工具的局限

存在透明的性能分析器。也就是说，即使像cProfile这样消耗极小的性能分析器，仍然会对代码实际的性能造成影响。

当一个事件被触发时，事件实际发生的时间相比性能分析器查询到的系统内部时钟的时间，还是会有一些延迟。

当程序计数器离开性能分析器代码，回到用户代码中继续执行时，程序也会出现滞后。

计算机内部的任何一段代码，内部时钟都有一个精度范围，任何小于这个精度的测量值都会被忽略。

cProfile 支持的 API

(1) run

run(command, filename=None, sort=-1)

run 调用时，会执行下面的函数

exec(command, __main__.__dict, __main__.__dict__)

若没有 filename，会创建一个新的 stats 类的实例。

如果我们提供 filename 和 sort 如下

cProfile.run("fib_seq(30)", "stats", "cumtime")

stats 为二进制文件。后面我们可以读取它并通过它创建我们自己的报告。

(2) runctx

runctx(command, globals, locals, filename=None)

与 run 唯一不同的是支持 globals 和 locals，runctx 被调用时，会执行以下函数

exec(command, globals, locals)

下面看看 run 和 runctx 的区别

import cProfile

def my_func():
    import fib
    cProfile.run("fib.fib_seq(30)")

my_func()

以上代码运行会报错，fib 模块没有被 run 方法发现，因为 run 调用的时候，exec 的参数是 __main__.__dict__

import cProfile

def my_func():
    import fib
    cProfile.runctx("fib.fib_seq(30)", None, locals())

my_func()

输出

         7049218 function calls (96 primitive calls) in 1.424 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    1.424    1.424 <string>:1(<module>)
     31/1    0.000    0.000    1.424    1.424 fib.py:10(fib_seq)
7049123/31    1.424    0.000    1.424    0.046 fib.py:2(fib)
        1    0.000    0.000    1.424    1.424 {built-in method builtins.exec}
       31    0.000    0.000    0.000    0.000 {method 'append' of 'list' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
       30    0.000    0.000    0.000    0.000 {method 'extend' of 'list' objects}

(3) Profile 类

Profile(timer=None, timeunit=0.0, subcalls=True, builtins=True)

Profile 类可以比 run/runctx 提供更多的控制。

timer 是自定义函数，必须是一个可以返回当前时间数值的函数。

如果timer的返回值是一个整数,那么timeunit参数就表示单位时间换算成秒的系数。例如,如果返回值单位时间是毫秒,那么timeunit应该就是.001。

Profile 类的方法

enable():表示开始收集性能分析数据。
disable():表示停止收集性能分析数据。
create_stats():表示停止收集数据,并为已收集的数据创建stats对象。
print_stats(sort=-1):创建一个stats对象,打印分析结果。
dump_stats(filename):把当前性能分析的内容写进一个文件。
run(cmd):和之前介绍过的run函数相同。
runctx(cmd, globals, locals):和之前介绍过的runctx函数相同。
runcall(func, *args, **kwargs):收集被调用函数func的性能分析信息。

例子

通过这种方式对已经写好的代码或者已经通过测试的代码进行性能分析时,可以直接增加或删除性能分析代码,不需要调整源代码。

import cProfile

def my_func():
    import fib
    cProfile.runctx("fib.fib_seq(30)", None, locals())

prof = cProfile.Profile()
prof.enable()

my_func()
prof.create_stats()
prof.print_stats()

(4) cProfile 命令行参数

python -m cProfile fib_run.py -o fib_run.profile

这样做会分析全部代码的性能。当需要分析部分代码的性能时，此方法不可用。

Stats 类

pstats 模块的 Stats 类可以读取和操作 stats 文件。

import pstats

p = pstats.Stats("my_stats")
p.strip_dirs().sort_stats(-1).print_stats()

Stats 类可以接收 cProfile.Profile 类的参数，不用文件名称作为数据源。

Stats 类的方法

• strip_dirs(): 删除报告中所有函数文件名的路径信息。这个方法会改变stats实例内部的顺序,任何运行该方法的实例都将随机排列项目(每一行信息)的顺序。如果两个项目被认为是相同的(函数名相同,文件名相同,行数相同),那么这两个项目就可以合并。
• add(*filenames): 这个方法将文件名对应的文件的信息加载到当前的stats对象中。需要注意的是,和前面单独一个文件的处理方式相同,引用同一函数的stats项目(filename:lineno(function),即文件名、行数和函数名)将被合并。
• dump_stats(filename): 就像cProfile.Profile类,这个方法把加载到Stats类的数据保存为一个文件。
• sort_stats(*keys): 它是通过一系列条件依次对所有项目进行排序,从而调整stats对象的。当条件不止一个时,只有经过前一个条件排序后是相同的项目,才使用后一个条件进行排序。
  例如,如果sort_stats ('name','file')条件被使用,那么首先会把所有项目按照函数名排序,然后对名称相同的项目再按照文件名排序。

准则	含义	升序/降序排列
calls	调用总次数	降序
cumulative	累计时间	降序
cumtime	累计时间	降序
file 文件名 升序filename	文件名	升序
module	模块名	升序
ncalls	调用总次数	降序
pcalls	原始调用数	降序
line	行号	升序
name	函数名	升序
nfl	函数名/文件名/行号组合	降序
stdname	标准名称	升序
time	函数内部运行时间	降序
tottime	函数内部运行时间	降序

• reverse_order():这个方法会逆反原来参数的排序方法
• print_stats(*restrictions):这个方法是把信息打印到STDOUT。里面的可选参数用于体现打印结果的形式,可以是整数、小数和字符串。
  • 整数:限制打印的行数。
  • 0.0到1.0(包含)之间的小数:表示按总行数的百分比打印。
  • 字符串:正则表达式,用于匹配stdname。

性能分析器的结果可能会非常长。但是,如果排序合理,就可以用参数汇总输出结果,获取需要的数据。

• print_callers(*restrictions) 方法的输入参数和使用规则与前面的函数相同,但是输出结果有一点儿不同。它会显示程序执行过程中调用的每个函数的调用次数、总时间和累计时间,以及文件名、行号和函数名的组合。
• print_callees(*restrictions)方法打印一列调用其他函数的函数。其数据显示格式和限制参数与上一个函数相同。

---