草庐IT

Python 从 cProfile 获得有意义的结果

coder 2023-05-23 原文

我在一个文件中有一个 Python 脚本,它需要 30 多秒才能运行。我正在尝试对其进行分析,因为我想大大减少这个时间。

我正在尝试使用 cProfile 分析脚本,但基本上它似乎告诉我的是,是的,主脚本需要很长时间才能运行,但没有给出那种我期待的崩溃。在终端,我输入如下内容:

cat my_script_input.txt | python -m cProfile -s time my_script.py

我得到的结果是:

<my_script_output>
             683121 function calls (682169 primitive calls) in 32.133 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1   31.980   31.980   32.133   32.133 my_script.py:18(<module>)
   121089    0.050    0.000    0.050    0.000 {method 'split' of 'str' objects}
   121090    0.038    0.000    0.049    0.000 fileinput.py:243(next)
        2    0.027    0.014    0.036    0.018 {method 'sort' of 'list' objects}
   121089    0.009    0.000    0.009    0.000 {method 'strip' of 'str' objects}
   201534    0.009    0.000    0.009    0.000 {method 'append' of 'list' objects}
   100858    0.009    0.000    0.009    0.000 my_script.py:51(<lambda>)
      952    0.008    0.000    0.008    0.000 {method 'readlines' of 'file' objects}
 1904/952    0.003    0.000    0.011    0.000 fileinput.py:292(readline)
    14412    0.001    0.000    0.001    0.000 {method 'add' of 'set' objects}
      182    0.000    0.000    0.000    0.000 {method 'join' of 'str' objects}
        1    0.000    0.000    0.000    0.000 fileinput.py:80(<module>)
        1    0.000    0.000    0.000    0.000 fileinput.py:197(__init__)
        1    0.000    0.000    0.000    0.000 fileinput.py:266(nextfile)
        1    0.000    0.000    0.000    0.000 {isinstance}
        1    0.000    0.000    0.000    0.000 fileinput.py:91(input)
        1    0.000    0.000    0.000    0.000 fileinput.py:184(FileInput)
        1    0.000    0.000    0.000    0.000 fileinput.py:240(__iter__)
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

这似乎没有告诉我任何有用的信息。绝大多数时间都被简单地列为:

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1   31.980   31.980   32.133   32.133 my_script.py:18(<module>)

my_script.py 中,第 18 行只不过是文件头 block 注释的结束 """工作集中在第 18 行。整个脚本主要由基于行的处理组成,其中大部分是一些字符串拆分、排序和设置工作,所以我希望能找到大部分时间用于这些事件中的一个或多个。就目前而言,将所有时间分组在 cProfile 的结果中视为发生在注释行上没有任何意义,或者至少不能说明实际上一直在消耗什么。

编辑:我构建了一个与上述案例类似的最小工作示例来演示相同的行为:

mwe.py

import fileinput

for line in fileinput.input():
    for i in range(10):
        y = int(line.strip()) + int(line.strip())

然后调用它:

perl -e 'for(1..1000000){print "$_\n"}' | python -m cProfile -s time mwe.py

要得到结果:

         22002536 function calls (22001694 primitive calls) in 9.433 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    8.004    8.004    9.433    9.433 mwe.py:1(<module>)
 20000000    1.021    0.000    1.021    0.000 {method 'strip' of 'str' objects}
  1000001    0.270    0.000    0.301    0.000 fileinput.py:243(next)
  1000000    0.107    0.000    0.107    0.000 {range}
      842    0.024    0.000    0.024    0.000 {method 'readlines' of 'file' objects}
 1684/842    0.007    0.000    0.032    0.000 fileinput.py:292(readline)
        1    0.000    0.000    0.000    0.000 fileinput.py:80(<module>)
        1    0.000    0.000    0.000    0.000 fileinput.py:91(input)
        1    0.000    0.000    0.000    0.000 fileinput.py:197(__init__)
        1    0.000    0.000    0.000    0.000 fileinput.py:184(FileInput)
        1    0.000    0.000    0.000    0.000 fileinput.py:266(nextfile)
        1    0.000    0.000    0.000    0.000 {isinstance}
        1    0.000    0.000    0.000    0.000 fileinput.py:240(__iter__)
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

我是否以某种方式错误地使用了 cProfile?

最佳答案

正如我在评论中提到的,当您无法让 cProfile 在外部工作时,您通常可以在内部使用它。没那么难。

例如,当我在我的 Python 2.7 中使用 -m cProfile 运行时,我实际上得到了与您相同的结果。但是当我手动检测您的示例程序时:

import fileinput
import cProfile

pr = cProfile.Profile()
pr.enable()
for line in fileinput.input():
    for i in range(10):
        y = int(line.strip()) + int(line.strip())
pr.disable()
pr.print_stats(sort='time')

...这是我得到的:

         22002533 function calls (22001691 primitive calls) in 3.352 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
 20000000    2.326    0.000    2.326    0.000 {method 'strip' of 'str' objects}
  1000001    0.646    0.000    0.700    0.000 fileinput.py:243(next)
  1000000    0.325    0.000    0.325    0.000 {range}
      842    0.042    0.000    0.042    0.000 {method 'readlines' of 'file' objects}
 1684/842    0.013    0.000    0.055    0.000 fileinput.py:292(readline)
        1    0.000    0.000    0.000    0.000 fileinput.py:197(__init__)
        1    0.000    0.000    0.000    0.000 fileinput.py:91(input)
        1    0.000    0.000    0.000    0.000 {isinstance}
        1    0.000    0.000    0.000    0.000 fileinput.py:266(nextfile)
        1    0.000    0.000    0.000    0.000 fileinput.py:240(__iter__)
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

这更有用:它告诉您可能已经预料到的情况,即您一半以上的时间都花在了调用 str.strip() 上。


另外,请注意,如果您无法编辑包含要分析的代码的文件 (mwe.py),您可以随时这样做:

import cProfile
pr = cProfile.Profile()
pr.enable()
import mwe
pr.disable()
pr.print_stats(sort='time')

即使这并不总是有效。例如,如果您的程序调用 exit(),则必须使用 try:/finally: 包装器和/或 atexit。它调用 os._exit() 或 segfaults,你可能完全被淹没了。但这并不常见。


但是,我后来发现:如果将所有代码移出全局范围,-m cProfile 似乎可以工作,至少在这种情况下是这样。例如:

import fileinput

def f():
    for line in fileinput.input():
        for i in range(10):
            y = int(line.strip()) + int(line.strip())
f()

现在 -m cProfile 的输出包括:

  2000000    4.819    0.000    4.819    0.000 :0(strip)
   100001    0.288    0.000    0.295    0.000 fileinput.py:243(next)

我不知道为什么这也让它慢了一倍……或者这只是缓存效应;距离我上次运行它已经有几分钟了,我在这之间做了很多网页浏览。但这并不重要,重要的是大部分时间都在合理的地方收费。

但是如果我改变它以将外部循环移动到全局级别,并且只有它的主体变成一个函数,大部分时间都会再次消失。


另一种选择,除非作为最后的手段,否则我不会建议......

我注意到,如果我使用 profile 而不是 cProfile,它在内部和外部都可以工作,从而为正确的调用计费。但是,这些调用也慢了大约 5 倍。并且似乎还有额外的 10 秒的持续开销(如果在内部使用,则从 import profile 收取费用,如果在外部使用,则在第 1 行收取费用)。因此,要发现 split 占用了我 70% 的时间,而不是等待 4 秒并执行 2.326/3.352,我必须等待 27 秒,然后执行 10.93/(26.34 - 10.01)。没什么好玩的……


最后一件事:我使用 CPython 3.4 开发版本得到了相同的结果——在内部使用时结果正确,在外部使用时所有费用都计入第一行代码。但是 PyPy 2.2/2.7.3 和 PyPy3 2.1b1/3.2.3 似乎都用 -m cProfile 给了我正确的结果。这可能只是意味着 PyPy 的 cProfile 是在 profile 之上伪造的,因为纯 Python 代码足够快。


无论如何,如果有人能弄清楚/解释为什么 -m cProfile 不起作用,那就太好了……但否则,这通常是一个非常好的解决方法。

关于Python 从 cProfile 获得有意义的结果,我们在Stack Overflow上找到一个类似的问题: https://stackoverflow.com/questions/21274898/

有关Python 从 cProfile 获得有意义的结果的更多相关文章

  1. python - 如何使用 Ruby 或 Python 创建一系列高音调和低音调的蜂鸣声? - 2

    关闭。这个问题是opinion-based.它目前不接受答案。想要改进这个问题?更新问题,以便editingthispost可以用事实和引用来回答它.关闭4年前。Improvethisquestion我想在固定时间创建一系列低音和高音调的哔哔声。例如:在150毫秒时发出高音调的蜂鸣声在151毫秒时发出低音调的蜂鸣声200毫秒时发出低音调的蜂鸣声250毫秒的高音调蜂鸣声有没有办法在Ruby或Python中做到这一点?我真的不在乎输出编码是什么(.wav、.mp3、.ogg等等),但我确实想创建一个输出文件。

  2. ruby - 无法在 60 秒内获得稳定的 Firefox 连接 (127.0.0.1 :7055) - 2

    我使用的是Firefox版本36.0.1和Selenium-Webdrivergem版本2.45.0。我能够创建Firefox实例,但无法使用脚本继续进行进一步的操作无法在60秒内获得稳定的Firefox连接(127.0.0.1:7055)错误。有人能帮帮我吗? 最佳答案 我遇到了同样的问题。降级到firefoxv33后一切正常。您可以找到旧版本here 关于ruby-无法在60秒内获得稳定的Firefox连接(127.0.0.1:7055),我们在StackOverflow上找到一个类

  3. Python 相当于 Perl/Ruby ||= - 2

    这个问题在这里已经有了答案:关闭10年前。PossibleDuplicate:Pythonconditionalassignmentoperator对于这样一个简单的问题表示歉意,但是谷歌搜索||=并不是很有帮助;)Python中是否有与Ruby和Perl中的||=语句等效的语句?例如:foo="hey"foo||="what"#assignfooifit'sundefined#fooisstill"hey"bar||="yeah"#baris"yeah"另外,类似这样的东西的通用术语是什么?条件分配是我的第一个猜测,但Wikipediapage跟我想的不太一样。

  4. java - 什么相当于 ruby​​ 的 rack 或 python 的 Java wsgi? - 2

    什么是ruby​​的rack或python的Java的wsgi?还有一个路由库。 最佳答案 来自Python标准PEP333:Bycontrast,althoughJavahasjustasmanywebapplicationframeworksavailable,Java's"servlet"APImakesitpossibleforapplicationswrittenwithanyJavawebapplicationframeworktoruninanywebserverthatsupportstheservletAPI.ht

  5. 报告回顾丨模型进化狂飙,DetectGPT能否识别最新模型生成结果? - 2

    导读语言模型给我们的生产生活带来了极大便利,但同时不少人也利用他们从事作弊工作。如何规避这些难辨真伪的文字所产生的负面影响也成为一大难题。在3月9日智源Live第33期活动「DetectGPT:判断文本是否为机器生成的工具」中,主讲人Eric为我们讲解了DetectGPT工作背后的思路——一种基于概率曲率检测的用于检测模型生成文本的工具,它可以帮助我们更好地分辨文章的来源和可信度,对保护信息真实、防止欺诈等方面具有重要意义。本次报告主要围绕其功能,实现和效果等展开。(文末点击“阅读原文”,查看活动回放。)Ericmitchell斯坦福大学计算机系四年级博士生,由ChelseaFinn和Chri

  6. 华为OD机试用Python实现 -【明明的随机数】 2023Q1A - 2

    华为OD机试题本篇题目:明明的随机数题目输入描述输出描述:示例1输入输出说明代码编写思路最近更新的博客华为od2023|什么是华为od,od薪资待遇,od机试题清单华为OD机试真题大全,用Python解华为机试题|机试宝典【华为OD机试】全流程解析+经验分享,题型分享,防作弊指南华为o

  7. python - 如何读取 MIDI 文件、更改其乐器并将其写回? - 2

    我想解析一个已经存在的.mid文件,改变它的乐器,例如从“acousticgrandpiano”到“violin”,然后将它保存回去或作为另一个.mid文件。根据我在文档中看到的内容,该乐器通过program_change或patch_change指令进行了更改,但我找不到任何在已经存在的MIDI文件中执行此操作的库.他们似乎都只支持从头开始创建的MIDI文件。 最佳答案 MIDIpackage会为您完成此操作,但具体方法取决于midi文件的原始内容。一个MIDI文件由一个或多个音轨组成,每个音轨是十六个channel中任何一个上的

  8. 「Python|Selenium|场景案例」如何定位iframe中的元素? - 2

    本文主要介绍在使用Selenium进行自动化测试或者任务时,对于使用了iframe的页面,如何定位iframe中的元素文章目录场景描述解决方案具体代码场景描述当我们在使用Selenium进行自动化测试的时候,可能会遇到一些界面或者窗体是使用HTML的iframe标签进行承载的。对于iframe中的标签,如果直接查找是无法找到的,会抛出没有找到元素的异常。比如近在咫尺的例子就是,CSDN的登录窗体就是使用的iframe,大家可以尝试通过F12开发者模式查看到的tag_name,class_name,id或者xpath来定位中的页面元素,会抛出NoSuchElementException异常。解决

  9. python ffmpeg 使用 pyav 转换 一组图像 到 视频 - 2

    2022/8/4更新支持加入水印水印必须包含透明图像,并且水印图像大小要等于原图像的大小pythonconvert_image_to_video.py-f30-mwatermark.pngim_dirout.mkv2022/6/21更新让命令行参数更加易用新的命令行使用方法pythonconvert_image_to_video.py-f30im_dirout.mkvFFMPEG命令行转换一组JPG图像到视频时,是将这组图像视为MJPG流。我需要转换一组PNG图像到视频,FFMPEG就不认了。pyav内置了ffmpeg库,不需要系统带有ffmpeg工具因此我使用ffmpeg的python包装p

  10. Python 刷Leetcode题库,顺带学英语单词(31) - 2

    ValidPalindromeGivenastring,determineifitisapalindrome,consideringonlyalphanumericcharactersandignoringcases. [#125]Example:"Aman,aplan,acanal:Panama"isapalindrome."raceacar"isnotapalindrome.Haveyouconsiderthatthestringmightbeempty?Thisisagoodquestiontoaskduringaninterview.Forthepurposeofthisproblem

随机推荐