Python: cProfile 使用

[TOC]

References:
FutureWarning: Passing (type, 1) or '1type' as a synonym of type is deprecated; in a future version of numpy, it will be understood as
FutureWarning: Deprecated numpy API calls in tf.python.framework.dtypes
tensorflow + numpy compatibility?
cprofiler, python 使用
使用cProfile分析Python程序性能
python性能分析工具:cProfile使用
服务器 终端连接反应慢
ssh连接服务器时特别慢的问题的解决方法
Mobile Shell: https://mosh.org/
点赞收藏:PyTorch常用代码段整理合集

cProfile + pstats

在进行python开发时需要对python脚本的性能分析,以便对python脚本进行优化,下面使用cProfile和 pstats对python脚本性能分析。

cProfile思路

  1. 使用cProfile模块生成脚本执行的统计信息文件
  2. 使用pstats格式化统计信息,并根据需要做排序分析处理

1.使用cProfile模块生成脚本执行的统计信息文件
python -m cProfile -o file-name script.py -params i.e.,

python -m cProfile -o /jtitsm/01_shipper/cProfile_read_xml.txt read_xml.py /jtitsm/TEST/wbmh_1/20171017 /soft/omc_bak/xml/test_1/20171017 /jtitsm/01_shipper_test/logs/file2tcp_xml.log.20171017

参数说明:

  • 使用模块当做脚本运行:-m cProfile
  • 输出参数:-o /jtitsm/01_shipper/cProfile_read_xml.txt
  • 测试的python脚本:read_xml.py
  • 其余为python脚本的输入参数
  1. python命令行查看统计信息。
    执行python:
import pstats
p=pstats.Stats('/jtitsm/01_shipper/cProfile_read_xml.txt')
p.print_stats()
#根据调用次数排序
p.sort_stats('calls').print_stats()
#根据调用总时间排序
p.sort_stats('cumulative').print_stats()

*Stats类(pstats.Stats)说明

  • strip_dirs() 用以除去文件名前的路径信息。
  • add(filename,[…]) 把profile的输出文件加入Stats实例中统计
  • dump_stats(filename) 把Stats的统计结果保存到文件
  • sort_stats(key,[…]) 最重要的一个函数,用以排序profile的输出
  • reverse_order() 把Stats实例里的数据反序重排
  • print_stats([restriction,…]) 把Stats报表输出到stdout
  • print_callers([restriction,…]) 输出调用了指定的函数的函数的相关信息
  • print_callees([restriction,…]) 输出指定的函数调用过的函数的相关信息

sort_stats支持以下参数:

参数 含义
‘calls’ call count
‘cumulative’ cumulative time
‘file’ file name
‘filename’ file name
‘module’ module name
‘ncalls’ call count
‘pcalls’ primitive call count
‘line’ line number
‘name’ function name
‘nfl’ name/file/line
‘stdname’ standard name
‘time’ internal time
‘tottime’ internal time

*一个比较典型的输出结果:

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 :1()
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次,原始调用说明不包含递归调用。
以standard name进行排序。3/1表示发生了递归调用,1为原始调用次数,3为递归调用次数
ncalls 函数的被调用次数
tottime 函数总计运行时间,除去函数中调用的函数运行时间
percall 函数运行一次的平均时间,等于tottime/ncalls
cumtime 函数总计运行时间,含调用的函数运行时间
percall 函数运行一次的平均时间,等于cumtime/ncalls
filename:lineno(function) 函数所在的文件名,函数的行号,函数名

profile

监视模块

cProfile:基于lsprof的用C语言实现的扩展应用,运行开销比较合理,适合分析运行时间较长的程序,推荐使用这个模块;
profile:纯Python实现的性能分析模块,接口和cProfile一致。但在分析程序时增加了很大的运行开销。不过,如果你想扩展profiler的功能,可以通过继承这个模块实现;
使用cProfile进行性能分析,你可以在Python脚本中实现,也可以使用命令行执行:

if __name__ == "__main__":
    import cProfile

    # 直接把分析结果打印到控制台
    cProfile.run("test()")
    # 把分析结果保存到文件中
    cProfile.run("test()", filename="result.out")
    # 增加排序方式
    cProfile.run("test()", filename="result.out", sort="cumulative")

使用命令行运行的方法基本一致,Bash代码如下:

# 直接把分析结果打印到控制台
python -m cProfile test.py
# 把分析结果保存到文件中
python -m cProfile -o result.out test.py
# 增加排序方式
python -m cProfile -o result.out -s cumulative test.py

分析工具

使用cProfile分析的结果可以输出到指定的文件中,但是文件内容是以二进制的方式保存的,用文本编辑器打开时乱码。所以,Python提供了一个pstats模块,用来分析cProfile输出的文件内容。

import pstats

# 创建Stats对象
p = pstats.Stats("result.out")

# strip_dirs(): 去掉无关的路径信息
# sort_stats(): 排序,支持的方式和上述的一致
# print_stats(): 打印分析结果,可以指定打印前几行

# 和直接运行cProfile.run("test()")的结果是一样的
p.strip_dirs().sort_stats(-1).print_stats()

# 按照函数名排序,只打印前3行函数的信息, 参数还可为小数,表示前百分之几的函数信息 
p.strip_dirs().sort_stats("name").print_stats(3)

# 按照运行时间和函数名进行排序
p.strip_dirs().sort_stats("cumulative", "name").print_stats(0.5)

# 如果想知道有哪些函数调用了sum_num
p.print_callers(0.5, "sum_num")

# 查看test()函数中调用了哪些函数
p.print_callees("test")

结果类似:

8 function calls in 0.042 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.042    0.042 test.py:5(<module>)
        1    0.002    0.002    0.042    0.042 test.py:12(test)
        2    0.035    0.018    0.039    0.020 test.py:5(sum_num)
        3    0.004    0.001    0.004    0.001 {range}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

其中,输出每列的具体解释如下:

    ncalls:表示函数调用的次数;
    tottime:表示指定函数的总的运行时间,除掉函数中调用子函数的运行时间;
    percall:(第一个percall)等于 tottime/ncalls;
    cumtime:表示该函数及其所有子函数的调用运行的时间,即函数开始调用到返回的时间;
    percall:(第二个percall)即函数运行一次的平均时间,等于 cumtime/ncalls;
    filename:lineno(function):每个函数调用的具体信息;

另外,上面分析的时候,排序方式使用的是函数调用时间(cumulative),除了这个还有一些其他允许的排序方式:calls, cumulative, file, line, module, name, nfl, pcalls, stdname, time等。

图形化工具

对于一些比较大的应用程序,如果能够将性能分析的结果以图形的方式呈现,将会非常实用和直观,常见的可视化工具有Gprof2Dot,visualpytune,KCacheGrind等,这里介绍一下Gprof2Dot的用法。
使用之前,你需要安装graphviz:

sudo apt-get install graphviz

然后下载Gprof2Dot:gprof2dot.py之后运行:

python gprof2dot.py -f pstats result.out | dot -Tpng -o result.png

结果如下:

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 204,530评论 6 478
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 86,403评论 2 381
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 151,120评论 0 337
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,770评论 1 277
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,758评论 5 367
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,649评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 38,021评论 3 398
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,675评论 0 258
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,931评论 1 299
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,659评论 2 321
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,751评论 1 330
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,410评论 4 321
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 39,004评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,969评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,203评论 1 260
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 45,042评论 2 350
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,493评论 2 343

推荐阅读更多精彩内容