27.4. The Python Profilers

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

27.4.1. Introduction to the profilers

cProfileprofile提供确定性分析的Python程序。配置文件是一组统计信息,描述程序的各个部分执行的频率和时间。这些统计信息可通过pstats模块格式化为报告。

Python标准库提供了同一个性能分析界面的两种不同的实现:

  1. cProfile建议大多数用户;它是一个C扩展,具有合理的开销,使其适合于分析长期运行的程序。基于由Brett Rosen和Ted Czotter贡献的lsprof
  2. profile,这是一个纯Python模块,其接口由cProfile模拟,但会对分析的程序增加显着的开销。如果你试图以某种方式扩展profiler,这个模块的任务可能会更容易。最初由吉姆·罗斯金德设计和写作。

注意

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

27.4.2. Instant User’s Manual

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

要对包含单个参数的函数进行概要分析,您可以执行以下操作:

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个原语,意味着调用不是通过递归诱发的。下一行:已订购 标准 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将配置文件结果写入文件,而不是标准输出

-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仍然根据最后的标准排序)do:

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(),添加了参数以提供命令字符串的全局和本地化字典。该例程执行:

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. The Stats Class

使用Stats类对分析器数据进行分析。

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

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

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

This method modifies the Stats object by sorting it according to the supplied criteria. 参数通常是标识排序基础的字符串(例如:'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. What Is Deterministic Profiling?

确定性分析意在反映所有函数调用函数返回异常并且对这些事件之间的间隔(在其期间用户的代码正在执行)进行精确的定时。相比之下,统计分析(这不是由该模块完成)随机采样有效指令指针,并推断在哪里花费时间。后一种技术传统上涉及较少的开销(因为代码不需要被插桩),而是仅提供在何处花费时间的相对指示。

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

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

27.4.6. Limitations

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

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

使用profile比使用较低开销的cProfile更为重要。出于这个原因,profile提供了为给定平台校准自身的方法,以便可以概率(平均)移除该错误。在分析器被校准之后,它将更准确(在最小二乘法意义上),但是它有时会产生负数(当呼叫计数异常低时,概率神对你工作: - )。 )不要由配置文件中的负数报警。如果您已经校准了分析器,它们应该只出现,结果实际上比没有校准更好。

27.4.7. Calibration

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

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。

这个练习的目的是获得一个相当一致的结果。如果您的计算机很快,或者您的计时器功能的分辨率较差,您可能需要通过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. Using a custom timer

如果要更改当前时间的确定方式(例如,强制使用挂钟时间或已用进程时间),请将所需的计时函数传递到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类(请参见Calibration)。对于大多数机器,返回单个整数值的定时器将在分析期间的低开销方面提供最佳结果。os.times()漂亮坏,因为它返回一个浮点值的元组)。如果你想以最干净的方式替换一个更好的定时器,派生一个类,并且硬连线一个替代调度方法,最好处理你的定时器调用,以及适当的校准常数。

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()