Project Icon

pprofile

Python高精度性能分析工具

pprofile是一款纯Python实现的性能分析工具,支持行级粒度和线程感知分析。它提供确定性和统计性两种分析模式,可输出多种格式报告。pprofile适用于短时间运行的代码分析,帮助开发者快速定位性能瓶颈。

逐行粒度、线程感知的确定性和统计性纯Python分析器

灵感来自Robert Kern的line_profiler_。

使用方法

作为命令:

$ pprofile some_python_executable arg1 ...

some_python_executable返回时,打印执行过程中涉及的每个文件的带注释代码。

作为命令,忽略默认sys.path中的任何文件(即Python模块本身),以获得更简短的输出:

$ pprofile --exclude-syspath some_python_executable arg1 ...

执行模块,类似于:code:python -m。在此模式下不建议使用--exclude-syspath,因为它可能会隐藏您打算分析的内容。此外,明确以--结束pprofile参数将防止意外窃取命令的参数:

$ pprofile -m some_python_module -- arg1 ...

作为模块:

.. code:: python

import pprofile

def someHotSpotCallable(): # 确定性分析器 prof = pprofile.Profile() with prof(): # 要分析的代码 prof.print_stats()

def someOtherHotSpotCallable(): # 统计分析器 prof = pprofile.StatisticalProfile() with prof( period=0.001, # 每1ms采样一次 single=True, # 仅采样当前线程 ): # 要分析的代码 prof.print_stats()

高级用法请参见:code:pprofile --help和:code:pydoc pprofile

分析开销

pprofile的默认模式(确定性分析_)有较大的开销。部分原因是它被编写为尽可能可移植(因此没有C扩展)。这种大开销可能会成为问题,可以通过使用统计分析_来避免,但代价是结果可读性的降低。

经验法则:

+-----------------------------+----------------------------+------------------------+ | 要分析的代码运行时间... | 确定性分析_ | 统计分析_ | +=============================+============================+========================+ | 几秒钟 | 是 | 否 [#]_ | +-----------------------------+----------------------------+------------------------+ | 几分钟 | 可能 | 是 | +-----------------------------+----------------------------+------------------------+ | 更长(例如:守护进程) | 否 | 是 [#]_ | +-----------------------------+----------------------------+------------------------+

一旦您确定了热点并决定需要更细粒度的分析来理解需要修复的内容,您应该尝试缩短要分析的代码运行时间,以便可以合理地使用确定性分析:使用触发相同代码路径的较小数据集,修改代码仅在小段代码上启用分析...

.. [#] 统计分析将没有足够的时间收集 足够的样本来产生可用的输出。

.. [#] 您可能需要考虑从信号处理程序或其他IPC机制 触发pprofile,以分析较短的子集。参见zpprofile.py 了解如何在运行中的(zope)服务内使用它 (在这种情况下,IPC机制只是Zope正常的URL处理)。

输出

支持的输出格式。

Callgrind

pprofile最有用的输出模式是Callgrind Profile Format,允许使用kcachegrind(或Windows上的qcachegrind_)浏览分析结果。

::

$ pprofile --format callgrind --out cachegrind.out.threads demo/threads.py

如果--out的基本名称以cachegrind.out.开头,则隐式启用Callgrind格式,因此上述命令可以简化为:

::

$ pprofile --out cachegrind.out.threads demo/threads.py

如果您在不同的机器上分析callgrind跟踪,可能需要使用--zipfile选项生成包含所有文件的zip文件:

::

$ pprofile --out cachegrind.out.threads --zipfile threads_source.zip demo/threads.py

生成的文件将使用相对路径,因此您可以在与分析结果相同的路径中提取生成的存档,kcachegrind将加载它们 - 而不是您系统范围的文件,这些文件可能有所不同。

带注释的代码

人类可读的输出,但对于大型程序可能难以使用。

::

$ pprofile demo/threads.py

分析模式

确定性分析

在确定性分析模式下,pprofile会收到每个执行行的通知。这种模式生成非常详细的报告,但代价是较大的开销。此外,由于分析钩子是按线程的,要么必须在生成线程之前启用分析(如果您想分析多个线程),要么被分析的应用程序必须提供在之后启用分析的方法 - 这不太方便。

::

$ pprofile --threads 0 demo/threads.py Command line: ['demo/threads.py'] Total duration: 1.00573s File: demo/threads.py File duration: 1.00168s (99.60%) Line #| Hits| Time| Time per hit| %|Source code ------+----------+-------------+-------------+-------+----------- 1| 2| 3.21865e-05| 1.60933e-05| 0.00%|import threading 2| 1| 5.96046e-06| 5.96046e-06| 0.00%|import time 3| 0| 0| 0| 0.00%| 4| 2| 1.5974e-05| 7.98702e-06| 0.00%|def func(): 5| 1| 1.00111| 1.00111| 99.54%| time.sleep(1) 6| 0| 0| 0| 0.00%| 7| 2| 2.00272e-05| 1.00136e-05| 0.00%|def func2(): 8| 1| 1.69277e-05| 1.69277e-05| 0.00%| pass 9| 0| 0| 0| 0.00%| 10| 1| 1.81198e-05| 1.81198e-05| 0.00%|t1 = threading.Thread(target=func) (call)| 1| 0.000610828| 0.000610828| 0.06%|# /usr/lib/python2.7/threading.py:436 init 11| 1| 1.52588e-05| 1.52588e-05| 0.00%|t2 = threading.Thread(target=func) (call)| 1| 0.000438929| 0.000438929| 0.04%|# /usr/lib/python2.7/threading.py:436 init 12| 1| 4.79221e-05| 4.79221e-05| 0.00%|t1.start() (call)| 1| 0.000843048| 0.000843048| 0.08%|# /usr/lib/python2.7/threading.py:485 start 13| 1| 6.48499e-05| 6.48499e-05| 0.01%|t2.start() (call)| 1| 0.00115609| 0.00115609| 0.11%|# /usr/lib/python2.7/threading.py:485 start 14| 1| 0.000205994| 0.000205994| 0.02%|(func(), func2()) (call)| 1| 1.00112| 1.00112| 99.54%|# demo/threads.py:4 func (call)| 1| 3.09944e-05| 3.09944e-05| 0.00%|# demo/threads.py:7 func2 15| 1| 7.62939e-05| 7.62939e-05| 0.01%|t1.join() (call)| 1| 0.000423908| 0.000423908| 0.04%|# /usr/lib/python2.7/threading.py:653 join 16| 1| 5.26905e-05| 5.26905e-05| 0.01%|t2.join() (call)| 1| 0.000320196| 0.000320196| 0.03%|# /usr/lib/python2.7/threading.py:653 join

请注意,time.sleep调用不被计算在内。由于某些原因,Python没有生成c_call/c_return/c_exception事件(当前代码忽略这些事件)。

统计分析

在统计分析模式下,pprofile定期对当前进程的当前调用栈进行快照,以查看正在执行的内容。因此,分析器开销可以大大降低,使得分析实际工作负载成为可能。此外,由于统计分析在整个进程级别上进行,可以独立于被分析的代码进行切换。 统计分析的缺点是输出缺乏时间信息,这使得理解变得更加困难。

::

$ pprofile --statistic .01 demo/threads.py 命令行: ['demo/threads.py'] 总持续时间: 1.0026秒 文件: demo/threads.py 文件持续时间: 0秒 (0.00%) 行号| 命中| 时间| 每次命中时间| %|源代码 ------+----------+-------------+-------------+-------+----------- 1| 0| 0| 0| 0.00%|import threading 2| 0| 0| 0| 0.00%|import time 3| 0| 0| 0| 0.00%| 4| 0| 0| 0| 0.00%|def func(): 5| 288| 0| 0| 0.00%| time.sleep(1) 6| 0| 0| 0| 0.00%| 7| 0| 0| 0| 0.00%|def func2(): 8| 0| 0| 0| 0.00%| pass 9| 0| 0| 0| 0.00%| 10| 0| 0| 0| 0.00%|t1 = threading.Thread(target=func) 11| 0| 0| 0| 0.00%|t2 = threading.Thread(target=func) 12| 0| 0| 0| 0.00%|t1.start() 13| 0| 0| 0| 0.00%|t2.start() 14| 0| 0| 0| 0.00%|(func(), func2()) (调用)| 96| 0| 0| 0.00%|# demo/threads.py:4 func 15| 0| 0| 0| 0.00%|t1.join() 16| 0| 0| 0| 0.00%|t2.join() 文件: /usr/lib/python2.7/threading.py 文件持续时间: 0秒 (0.00%) 行号| 命中| 时间| 每次命中时间| %|源代码 ------+----------+-------------+-------------+-------+----------- [...] 308| 0| 0| 0| 0.00%| def wait(self, timeout=None): [...] 338| 0| 0| 0| 0.00%| if timeout is None: 339| 1| 0| 0| 0.00%| waiter.acquire() 340| 0| 0| 0| 0.00%| if debug: [...] 600| 0| 0| 0| 0.00%| def wait(self, timeout=None): [...] 617| 0| 0| 0| 0.00%| if not self.__flag: 618| 0| 0| 0| 0.00%| self.__cond.wait(timeout) (调用)| 1| 0| 0| 0.00%|# /usr/lib/python2.7/threading.py:308 wait [...] 724| 0| 0| 0| 0.00%| def start(self): [...] 748| 0| 0| 0| 0.00%| self.__started.wait() (调用)| 1| 0| 0| 0.00%|# /usr/lib/python2.7/threading.py:600 wait 749| 0| 0| 0| 0.00%| 750| 0| 0| 0| 0.00%| def run(self): [...] 760| 0| 0| 0| 0.00%| if self.__target: 761| 0| 0| 0| 0.00%| self.__target(*self.__args, **self.__kwargs) (调用)| 192| 0| 0| 0.00%|# demo/threads.py:4 func 762| 0| 0| 0| 0.00%| finally: [...] 767| 0| 0| 0| 0.00%| def __bootstrap(self): [...] 780| 0| 0| 0| 0.00%| try: 781| 0| 0| 0| 0.00%| self.__bootstrap_inner() (调用)| 192| 0| 0| 0.00%|# /usr/lib/python2.7/threading.py:790 __bootstrap_inner [...] 790| 0| 0| 0| 0.00%| def __bootstrap_inner(self): [...] 807| 0| 0| 0| 0.00%| try: 808| 0| 0| 0| 0.00%| self.run() (调用)| 192| 0| 0| 0.00%|# /usr/lib/python2.7/threading.py:750 run

一些细节丢失了(并非所有执行的行都有非零的命中计数),但在这个简单的例子中,热点仍然很容易识别,并且其调用栈仍然可见。

线程感知分析

ThreadProfile类提供与Profile相同的功能,但使用threading.settrace将跟踪传播到在启用分析后启动的threading.Thread线程。

限制

在另一个线程中花费的时间不会从被中断的行中扣除。从长远来看,如果切换在各行之间均匀分布,这应该不是问题,但执行较少行的线程将显示为消耗比实际更多的CPU时间。

这不仅限于同时多线程分析:对多线程应用程序的单个线程进行分析也会受到其他线程所花费时间的污染。

示例(当与另一个线程一起分析时,报告的行执行时间更长 - 尽管另一个线程未被分析):: $ demo/embedded.py 总持续时间:1.00013秒 文件:demo/embedded.py 文件持续时间:1.00003秒(99.99%) 行号| 命中| 时间| 每次命中时间| %|源代码 ------+----------+-------------+-------------+-------+----------- 1| 0| 0| 0| 0.00%|#!/usr/bin/env python 2| 0| 0| 0| 0.00%|import threading 3| 0| 0| 0| 0.00%|import pprofile 4| 0| 0| 0| 0.00%|import time 5| 0| 0| 0| 0.00%|import sys 6| 0| 0| 0| 0.00%| 7| 1| 1.5974e-05| 1.5974e-05| 0.00%|def func(): 8| 0| 0| 0| 0.00%| # 忙循环,使上下文切换发生 9| 1| 1.40667e-05| 1.40667e-05| 0.00%| end = time.time() + 1 10| 146604| 0.511392| 3.48826e-06| 51.13%| while time.time() < end: 11| 146603| 0.48861| 3.33288e-06| 48.85%| pass 12| 0| 0| 0| 0.00%| 13| 0| 0| 0| 0.00%|# 单线程运行 14| 0| 0| 0| 0.00%|prof = pprofile.Profile() 15| 0| 0| 0| 0.00%|with prof: 16| 0| 0| 0| 0.00%| func() (调用)| 1| 1.00003| 1.00003| 99.99%|# ./demo/embedded.py:7 func 17| 0| 0| 0| 0.00%|prof.annotate(sys.stdout, file) 18| 0| 0| 0| 0.00%| 19| 0| 0| 0| 0.00%|# 双线程运行 20| 0| 0| 0| 0.00%|t1 = threading.Thread(target=func) 21| 0| 0| 0| 0.00%|prof = pprofile.Profile() 22| 0| 0| 0| 0.00%|with prof: 23| 0| 0| 0| 0.00%| t1.start() 24| 0| 0| 0| 0.00%| func() 25| 0| 0| 0| 0.00%| t1.join() 26| 0| 0| 0| 0.00%|prof.annotate(sys.stdout, file) 总持续时间:1.00129秒 文件:demo/embedded.py 文件持续时间:1.00004秒(99.88%) 行号| 命中| 时间| 每次命中时间| %|源代码 ------+----------+-------------+-------------+-------+----------- [...] 7| 1| 1.50204e-05| 1.50204e-05| 0.00%|def func(): 8| 0| 0| 0| 0.00%| # 忙循环,使上下文切换发生 9| 1| 2.38419e-05| 2.38419e-05| 0.00%| end = time.time() + 1 10| 64598| 0.538571| 8.33728e-06| 53.79%| while time.time() < end: 11| 64597| 0.461432| 7.14324e-06| 46.08%| pass [...]

这也意味着所有行的百分比之和可能超过100%。它可以达到并发线程数(2个线程在整个分析执行时间内都忙碌时为200%,以此类推)。

3个线程的示例:

$ pprofile demo/threads.py 命令行:['demo/threads.py'] 总持续时间:1.00798秒 文件:demo/threads.py 文件持续时间:3.00604秒(298.22%) 行号| 命中| 时间| 每次命中时间| %|源代码 ------+----------+-------------+-------------+-------+----------- 1| 2| 3.21865e-05| 1.60933e-05| 0.00%|import threading 2| 1| 6.91414e-06| 6.91414e-06| 0.00%|import time 3| 0| 0| 0| 0.00%| 4| 4| 3.91006e-05| 9.77516e-06| 0.00%|def func(): 5| 3| 3.00539| 1.0018|298.16%| time.sleep(1) 6| 0| 0| 0| 0.00%| 7| 2| 2.31266e-05| 1.15633e-05| 0.00%|def func2(): 8| 1| 2.38419e-05| 2.38419e-05| 0.00%| pass 9| 0| 0| 0| 0.00%| 10| 1| 1.81198e-05| 1.81198e-05| 0.00%|t1 = threading.Thread(target=func) (调用)| 1| 0.000612974| 0.000612974| 0.06%|# /usr/lib/python2.7/threading.py:436 init 11| 1| 1.57356e-05| 1.57356e-05| 0.00%|t2 = threading.Thread(target=func) (调用)| 1| 0.000438213| 0.000438213| 0.04%|# /usr/lib/python2.7/threading.py:436 init 12| 1| 6.60419e-05| 6.60419e-05| 0.01%|t1.start() (调用)| 1| 0.000913858| 0.000913858| 0.09%|# /usr/lib/python2.7/threading.py:485 start 13| 1| 6.8903e-05| 6.8903e-05| 0.01%|t2.start() (调用)| 1| 0.00167513| 0.00167513| 0.17%|# /usr/lib/python2.7/threading.py:485 start 14| 1| 0.000200272| 0.000200272| 0.02%|(func(), func2()) (调用)| 1| 1.00274| 1.00274| 99.48%|# demo/threads.py:4 func (调用)| 1| 4.19617e-05| 4.19617e-05| 0.00%|# demo/threads.py:7 func2 15| 1| 9.58443e-05| 9.58443e-05| 0.01%|t1.join() (调用)| 1| 0.000411987| 0.000411987| 0.04%|# /usr/lib/python2.7/threading.py:653 join 16| 1| 5.29289e-05| 5.29289e-05| 0.01%|t2.join() (调用)| 1| 0.000316143| 0.000316143| 0.03%|# /usr/lib/python2.7/threading.py:653 join 请注意,调用时间并未添加到文件总计中:它已经在"func"内部计算过了。

为什么需要另一个分析器?

Python的标准分析工具具有可调用级别的粒度,这意味着只能知道哪个函数是热点,而不能知道该函数中的哪些行。

Robert Kern的line_profiler是一个非常好的替代方案,提供了行级分析粒度,但在我看来它有一些缺点,这些缺点(加上具有吸引力的技术挑战)促使我开始开发pprofile:

  • 它不是纯Python的。这种选择对性能来说是有意义的,但使得在pypy上使用变得困难,并且需要安装(我重视直接从检出运行)。

  • 它需要修改源代码来选择应该被分析的内容。我更喜欢有一个选项来进行深入的、非侵入式的分析。

  • 作为前一点的效果,它没有高于单个可调用对象的概念,只注释函数而不是整个文件 - 阻止了模块导入分析。

  • 分析递归代码会产生意外的结果(递归成本累积在可调用对象的第一行),因为它不跟踪调用栈。这可能是无意的,可能在line_profiler的某个时候会被修复。

项目侧边栏1项目侧边栏2
推荐项目
Project Cover

豆包MarsCode

豆包 MarsCode 是一款革命性的编程助手,通过AI技术提供代码补全、单测生成、代码解释和智能问答等功能,支持100+编程语言,与主流编辑器无缝集成,显著提升开发效率和代码质量。

Project Cover

AI写歌

Suno AI是一个革命性的AI音乐创作平台,能在短短30秒内帮助用户创作出一首完整的歌曲。无论是寻找创作灵感还是需要快速制作音乐,Suno AI都是音乐爱好者和专业人士的理想选择。

Project Cover

白日梦AI

白日梦AI提供专注于AI视频生成的多样化功能,包括文生视频、动态画面和形象生成等,帮助用户快速上手,创造专业级内容。

Project Cover

有言AI

有言平台提供一站式AIGC视频创作解决方案,通过智能技术简化视频制作流程。无论是企业宣传还是个人分享,有言都能帮助用户快速、轻松地制作出专业级别的视频内容。

Project Cover

Kimi

Kimi AI助手提供多语言对话支持,能够阅读和理解用户上传的文件内容,解析网页信息,并结合搜索结果为用户提供详尽的答案。无论是日常咨询还是专业问题,Kimi都能以友好、专业的方式提供帮助。

Project Cover

讯飞绘镜

讯飞绘镜是一个支持从创意到完整视频创作的智能平台,用户可以快速生成视频素材并创作独特的音乐视频和故事。平台提供多样化的主题和精选作品,帮助用户探索创意灵感。

Project Cover

讯飞文书

讯飞文书依托讯飞星火大模型,为文书写作者提供从素材筹备到稿件撰写及审稿的全程支持。通过录音智记和以稿写稿等功能,满足事务性工作的高频需求,帮助撰稿人节省精力,提高效率,优化工作与生活。

Project Cover

阿里绘蛙

绘蛙是阿里巴巴集团推出的革命性AI电商营销平台。利用尖端人工智能技术,为商家提供一键生成商品图和营销文案的服务,显著提升内容创作效率和营销效果。适用于淘宝、天猫等电商平台,让商品第一时间被种草。

Project Cover

AIWritePaper论文写作

AIWritePaper论文写作是一站式AI论文写作辅助工具,简化了选题、文献检索至论文撰写的整个过程。通过简单设定,平台可快速生成高质量论文大纲和全文,配合图表、参考文献等一应俱全,同时提供开题报告和答辩PPT等增值服务,保障数据安全,有效提升写作效率和论文质量。

投诉举报邮箱: service@vectorlightyear.com
@2024 懂AI·鲁ICP备2024100362号-6·鲁公网安备37021002001498号