Skip to main content

27.4. Python分析器

源代码: Lib/profile.pyLib/pstats.py


27.4.1. 概述器简介

cProfileprofile 提供了Python程序的 deterministic profilingprofile 是一组统计数据,描述程序的各个部分执行的频率和时间。这些统计数据可以通过 pstats 模块格式化为报告。

Python标准库提供了同一个profiling接口的两个不同的实现:

  1. 建议大多数用户使用 cProfile;它是一个C扩展,具有合理的开销,使其适合于分析长期运行的程序。基于 lsprof,由Brett Rosen和Ted Czotter贡献。

  2. profile,一个纯Python模块,其接口由 cProfile 模仿,但它增加了大量的开销,分析程序。如果你试图以某种方式扩展分析器,这个模块的任务可能会更容易。最初由吉姆·罗斯金德设计和写作。

注解

分析器模块设计用于为给定程序提供执行配置文件,而不是用于基准测试目的(为了获得相当准确的结果,有 timeit)。这特别适用于针对C代码的基准化Python代码:分析器引入Python代码的开销,但不是C级函数,因此C代码似乎比任何Python代码快。

27.4.2. 即时用户手册

本节针对“不想阅读手册”的用户提供。它提供了一个非常简短的概述,并允许用户在现有应用程序上快速执行概要分析。

要配置一个接受单个参数的函数,您可以这样做:

import cProfile
import re
cProfile.run('re.compile("foo|bar")')

(如果后者在您的系统上不可用,请使用 profile 而不是 cProfile。)

上述操作将运行 re.compile() 并打印配置文件结果,如下所示:

      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 <string>:1(<module>)
     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个是 primitive,意味着调用不是通过递归诱导的。下一行:Ordered by: standard name,表示最右侧列中的文本字符串用于对输出进行排序。列标题包括:

ncalls

对于呼叫数,

tt

在给定函数中花费的总时间(并且不包括调用子函数的时间)

percall

tottime 除以 ncalls 的商

cumtime

是在此和所有子函数(从调用到退出)中花费的累积时间。这个数字是递归函数的精确 even

percall

cumtime 除以原始调用的商

filename:lineno(function)

提供每个功能的相应数据

当第一列中有两个数字(例如 3/1)时,表示函数递归。第二个值是原始调用的数量,前者是调用的总数。注意,当函数不递归时,这两个值是相同的,并且只打印单个图形。

不要在配置文件运行结束时打印输出,您可以通过指定 run() 函数的文件名将结果保存到文件中:

import cProfile
import re
cProfile.run('re.compile("foo|bar")', 'restats')

pstats.Stats 类从文件读取配置文件结果并以各种方式格式化它们。

文件 cProfile 也可以作为脚本调用以配置其他脚本。例如:

python -m cProfile [-o output_file] [-s sort_order] myscript.py

-o 将配置文件结果写入文件,而不是stdout

-s 指定一个 sort_stats() 排序值以对输出进行排序。这仅适用于未提供 -o 的情况。

pstats 模块的 Stats 类具有各种用于操作和打印保存在配置文件结果文件中的数据的方法:

import pstats
p = pstats.Stats('restats')
p.strip_dirs().sort_stats(-1).print_stats()

strip_dirs() 方法从所有模块名称中删除了无关的路径。 sort_stats() 方法根据打印的标准模块/行/名称字符串对所有条目进行排序。 print_stats() 方法打印出所有统计数据。您可以尝试以下排序调用:

p.sort_stats('name')
p.print_stats()

第一个调用实际上会按照函数名对列表进行排序,第二个调用将打印出统计信息。以下是一些有趣的试验呼吁:

p.sort_stats('cumulative').print_stats(10)

这会按照函数中的累积时间对配置文件进行排序,然后只打印十个最重要的行。如果你想了解什么算法需要时间,上面的行是你会使用。

如果你想看看什么功能循环很多,并花了很多时间,你会做:

p.sort_stats('time').print_stats(10)

根据每个函数中花费的时间排序,然后打印前十个函数的统计信息。

你也可以试试:

p.sort_stats('file').print_stats('__init__')

这将按文件名对所有统计信息进行排序,然后仅打印类init方法的统计信息(因为它们在其中使用 __init__ 拼写)。作为最后一个例子,你可以尝试:

p.sort_stats('time', 'cumulative').print_stats(.5, 'init')

此行使用时间的主键和累积时间的辅助键排序统计信息,然后打印出一些统计信息。具体来说,首先将列表剔除到其原始大小的50%(re:.5),然后只保留包含 init 的行,并打印该子子列表。

如果你想知道什么函数调用了上面的函数,你现在可以(p 仍然根据最后的条件排序)做:

p.print_callers(.5, 'init')

并且您将获得每个列出的函数的调用者列表。

如果你想要更多的功能,你必须阅读手册,或猜测下面的功能做什么:

p.print_callees()
p.add('restats')

作为脚本调用,pstats 模块是用于读取和检查概要文件转储的统计浏览器。它有一个简单的面向行的界面(使用 cmd 实现)和交互式帮助。

27.4.3. profilecProfile 模块参考

profilecProfile 模块都提供以下功能:

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

此函数接受一个可传递给 exec() 函数的参数,以及一个可选的文件名。在所有情况下,该例程执行:

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

并从执行中收集分析统计信息。如果没有文件名,则此函数自动创建一个 Stats 实例并打印一个简单的性能分析报告。如果指定排序值,它将传递到此 Stats 实例,以控制结果的排序方式。

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

此函数类似于 run(),添加了参数以提供 command 字符串的全局和本地化字典。此例程执行:

exec(command, globals, locals)

并收集上述 run() 函数中的分析统计数据。

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

这个类通常仅在需要比 cProfile.run() 函数提供的更精确的分析控制时才使用。

可以提供自定义计时器,用于测量通过 timer 参数运行的代码需要多长时间。这必须是返回表示当前时间的单个数字的函数。如果数字是整数,timeunit 指定一个乘数,指定每个时间单位的持续时间。例如,如果定时器返回以千秒为单位测量的时间,则时间单位将为 .001

直接使用 Profile 类允许格式化配置文件结果,而不将配置文件数据写入文件:

import cProfile, pstats, io
pr = cProfile.Profile()
pr.enable()
# ... do something ...
pr.disable()
s = io.StringIO()
sortby = 'cumulative'
ps = pstats.Stats(pr, stream=s).sort_stats(sortby)
ps.print_stats()
print(s.getvalue())
enable()

开始收集分析数据。

disable()

停止收集分析数据。

create_stats()

停止收集分析数据并将结果作为当前配置文件在内部记录。

print_stats(sort=-1)

基于当前配置文件创建 Stats 对象并将结果打印到stdout。

dump_stats(filename)

将当前配置文件的结果写入 filename

run(cmd)

通过 exec() 配置cmd。

runctx(cmd, globals, locals)

通过 exec() 与指定的全局和本地环境配置cmd。

runcall(func, *args, **kwargs)

简介 func(*args, **kwargs)

27.4.4. Stats

分析器数据的分析使用 Stats 类完成。

class pstats.Stats(*filenames or profile, stream=sys.stdout)

此类构造函数从 filename (或文件名列表)或从 Profile 实例创建“统计对象”的实例。输出将打印到 stream 指定的流。

由上述构造函数选择的文件必须由相应版本的 profilecProfile 创建。具体来说,在此分析器的未来版本中保证了 no 文件兼容性,并且与其他分析器生成的文件没有兼容性。如果提供了几个文件,则将合并相同功能的所有统计信息,以便在单个报告中考虑多个进程的总体视图。如果附加文件需要与现有 Stats 对象中的数据组合,则可以使用 add() 方法。

代替从文件读取配置文件数据,可以使用 cProfile.Profileprofile.Profile 对象作为配置文件数据源。

Stats 对象有以下方法:

strip_dirs()

此方法用于 Stats 类从文件名中删除所有前导路径信息。它在减小打印输出的大小以适合(接近)80列非常有用。此方法修改对象,并且剥离的信息丢失。在执行剥离操作之后,对象被认为具有“随机”顺序的条目,因为它恰好在对象初始化和加载之后。如果 strip_dirs() 导致两个函数名不可区分(它们在同一文件名的同一行上,并具有相同的函数名),则这两个条目的统计信息将累积到单个条目中。

add(*filenames)

Stats 类的此方法将附加概要分析信息累积到当前概要分析对象中。它的参数应该引用由相应版本的 profile.run()cProfile.run() 创建的文件名。相同命名(re:file,line,name)函数的统计信息将自动累积到单个函数统计中。

dump_stats(filename)

将加载到 Stats 对象中的数据保存到名为 filename 的文件。如果文件不存在,则创建该文件,如果文件已经存在,则会被覆盖。这等同于 profile.ProfilecProfile.Profile 类上同名的方法。

sort_stats(*keys)

此方法通过根据提供的条件对 Stats 对象进行排序来修改 Stats 对象。参数通常是标识排序基础的字符串(示例:'time''name')。

当提供多个键时,当在它们之前选择的所有键中存在相等性时,附加键被用作次要标准。例如,sort_stats('name', 'file') 将根据其功能名称对所有条目进行排序,并通过按文件名排序来解析所有连接(相同的函数名称)。

缩写可用于任何键名称,只要缩写是无歧义的。以下是当前定义的键:

有效Arg

含义

'calls'

呼叫计数

'cumulative'

累积时间

'cumtime'

累积时间

'file'

文件名

'filename'

文件名

'module'

文件名

'ncalls'

呼叫计数

'pcalls'

原始调用计数

'line'

电话号码

'name'

函数名

'nfl'

名称/文件/行

'stdname'

标准名称

'time'

内部时间

'tottime'

内部时间

请注意,统计信息中的所有排序都按降序排列(首先放置最耗时的项目),其中名称,文件和行号搜索按升序排列(按字母顺序排列)。 'nfl''stdname' 之间的细微区别是,标准名称是一种打印的名称,这意味着嵌入行号以奇怪的方式进行比较。例如,第3,20和40行(如果文件名相同)以字符串顺序20,3和40出现。相反,'nfl' 执行行号的数字比较。事实上,sort_stats('nfl')sort_stats('name', 'file', 'line') 相同。

出于向后兼容的原因,允许数值参数 -1012。它们分别被解释为 'stdname''calls''time''cumulative'。如果使用此旧样式格式(数字),将只使用一个排序键(数字键),并且将默认忽略其他参数。

reverse_order()

此方法用于 Stats 类反转对象内的基本列表的排序。请注意,默认情况下,根据所选的排序键正确选择升序或降序。

print_stats(*restrictions)

此方法用于 Stats 类打印出如 profile.run() 定义中所述的报告。

打印的顺序基于对对象执行的最后一次 sort_stats() 操作(在 add()strip_dirs() 中需要注意)。

提供的参数(如果有)可用于将列表限制为重要条目。最初,列表被认为是完整的概要函数集。每个限制都是一个整数(用于选择行数)或0.0和1.0之间的小数部分(用于选择行的百分比)或正则表达式(与打印的标准名称匹配)提供限制,然后按顺序应用它们:

print_stats(.1, 'foo:')

将首先将打印限制为列表的前10%,然后仅打印作为文件名 .*foo: 的一部分的打印函数。相反,命令:

print_stats('foo:', .1)

将该列表限制为具有文件名 .*foo: 的所有函数,然后继续仅打印它们的前10%。

print_callers(*restrictions)

此方法用于 Stats 类打印所有调用概要数据库中的每个函数的函数的列表。该顺序与 print_stats() 提供的顺序相同,并且限制参数的定义也是相同的。每个呼叫者在其自己的线路上报告。根据生成统计信息的剖析器,格式略有不同:

  • 使用 profile,每个呼叫者后面的括号中会显示一个数字,以显示此特定呼叫的发送次数。为了方便,第二个非括号数重复在右边的函数中花费的累积时间。

  • 使用 cProfile,每个调用者前面都有三个数字:特定调用的次数,以及当前函数在此特定调用者调用时所花费的总时间和累积时间。

print_callees(*restrictions)

此方法用于 Stats 类打印由指定函数调用的所有函数的列表。除了这种调用方向的反转(re:called vs被调用)之外,参数和顺序与 print_callers() 方法相同。

27.4.5. 什么是确定性分析?

Deterministic profiling 旨在反映所有 函数调用函数返回exception 事件都被监视,并且为这些事件之间的间隔(在用户的代码正在执行期间)进行精确定时的事实。相反,statistical profiling (这不是由该模块完成)随机采样有效指令指针,并推断在何时花费。后一种技术传统上涉及更少的开销(因为代码不需要被插桩),而是仅提供在何处花费时间的相对指示。

在Python中,由于在执行期间有一个解释器处于活动状态,因此不需要使用检测代码来执行确定性概要分析。 Python为每个事件自动提供一个 hook (可选回调)。此外,Python的解释性质往往会对执行增加如此多的开销,确定性分析往往只会在典型应用程序中增加小的处理开销。结果是确定性分析不是那么昂贵,但提供了关于Python程序执行的大量运行时间统计。

调用计数统计可用于识别代码中的错误(令人惊讶的计数),并识别可能的内联扩展点(高调用计数)。内部时间统计可用于识别应该仔细优化的“热环路”。累积时间统计应用于识别算法选择中的高级错误。注意,在此分析器中对累积时间的异常处理允许将算法的递归实现的统计直接与迭代实现相比较。

27.4.6. 限制

一个限制与定时信息的精度有关。确定性剖析器涉及精度存在一个根本问题。最明显的限制是,底层的“时钟”只是以约.001秒的速率(通常)打勾。因此,没有测量将比基础时钟更精确。如果进行了足够的测量,则“误差”将趋于平均。不幸的是,删除第一个错误会导致第二个错误来源。

第二个问题是,从分派事件直到分析器调用获取时间实际 gets 时钟的状态“花费一段时间”。类似地,从获得时钟的值的时间(然后squirreled)离开分析器事件处理程序时,存在一定的滞后,直到用户的代码再次执行。因此,被多次调用或调用许多函数的函数通常会累积此错误。以这种方式累积的误差通常小于时钟的精度(小于一个时钟节拍),但是它 can 累积并变得非常重要。

使用 profile 的问题比使用低开销的 cProfile 更为重要。因此,profile 提供了一种针对给定平台校准自身的方法,以便可以概率(平均)移除该误差。在分析器被校准之后,它将更准确(在最小二乘法的意义上),但是它有时会产生负数(当呼叫计数异常低时,概率神对你工作: - )。 ) not 由轮廓中的负数报警。如果您已经校准了分析器,他们应该会出现 only,并且结果实际上比没有校准更好。

27.4.7. 校准

profile 模块的分析器从每个事件处理时间中减去一个常数,以补偿调用时间函数的开销,并剔除结果。默认情况下,常数为0.以下过程可用于为给定平台获得更好的常数(请参阅 限制)。

import profile
pr = profile.Profile()
for i in range(5):
    print(pr.calibrate(10000))

该方法直接在分析器下执行由参数给定的Python调用数,并测量两者的时间。然后,它计算每个分析器事件的隐藏开销,并将其作为float返回。例如,在运行Mac OS X的1.8Ghz Intel Core i5上,使用Python的time.clock()作为定时器,神奇数字约为4.04e-6。

这个练习的目的是获得一个相当一致的结果。如果您的计算机是 very 快速,或您的计时器功能具有差的分辨率,您可能需要通过100000,甚至1000000,以获得一致的结果。

当你有一个一致的答案,有三种方式可以使用它:

import profile

# 1. Apply computed bias to all Profile instances created hereafter.
profile.Profile.bias = your_computed_bias

# 2. Apply computed bias to a specific Profile instance.
pr = profile.Profile()
pr.bias = your_computed_bias

# 3. Specify computed bias in instance constructor.
pr = profile.Profile(bias=your_computed_bias)

如果你有一个选择,你最好选择一个较小的常数,然后你的结果将“少见”显示为负的个人资料统计。

27.4.8. 使用自定义计时器

如果要更改当前时间的确定方式(例如,强制使用挂钟时间或已用进程时间),请将所需的计时函数传递给 Profile 类构造函数:

pr = profile.Profile(your_time_func)

生成的分析器将调用 your_time_func。根据您使用 profile.Profile 还是 cProfile.Profileyour_time_func 的返回值将有不同的解释:

profile.Profile

your_time_func 应该返回单个数字,或者一个数字列表,其和为当前时间(如 os.times() 返回的值)。如果函数返回单个时间数字,或者返回数字的列表长度为2,那么你将得到一个特别快的版本的dispatch例程。

警告您应该为选择的定时器功能校准profiler类(请参阅 校准)。对于大多数机器,返回单个整数值的定时器将在分析期间的低开销方面提供最佳结果。 (os.times()pretty 坏,因为它返回一个浮点值的元组)。如果你想以最干净的方式替换一个更好的定时器,派生一个类,并且硬连线一个替代调度方法,最好处理你的定时器调用,以及适当的校准常数。

cProfile.Profile

your_time_func 应返回单个数字。如果它返回整数,您还可以使用第二个参数调用类构造函数,指定一个时间单位的实际持续时间。例如,如果 your_integer_time_func 返回以千秒为单位的时间,那么您将构造如下的 Profile 实例:

pr = cProfile.Profile(your_integer_time_func, 0.001)

由于 cProfile.Profile 类不能校准,自定义定时器功能应该小心使用,并应尽可能快。为了使用自定义计时器获得最佳结果,可能需要在内部 _lsprof 模块的C源代码中对其进行硬编码。

Python 3.3在 time 中添加了几个新功能,可用于精确测量进程或挂钟时间。例如,见 time.perf_counter()