如何解读Python cProfile输出内容 解答Snakeviz可视化结果分析疑问

基础字段含义 #

你给出的cProfile结果默认按tottime（内部执行时间）排序，各列定义如下：

• ncalls：函数总调用次数，格式为A/B时说明存在递归调用，A是总调用次数，B是去重后的非递归调用次数
• tottime：函数自身逻辑消耗的总时间，不包含其调用的子函数耗时，当前排序依据就是这个值，数值高要么是函数本身逻辑重，要么是被调用频率极高
• 第一个percall：tottime / ncalls，即单次调用该函数自身逻辑的平均耗时
• cumtime：函数执行的累计总耗时，包含其调用的所有子函数的耗时，对于你自己编写的上层函数，这个值更能反映对应业务环节的总消耗
• 第二个percall：cumtime / 非递归调用次数，即单次触发该函数完整执行流程的平均耗时
• 最后一列：对应代码位置，格式为文件名:行号(函数名)，被大括号{}包裹的是Python内置方法或系统底层调用，不属于用户态Python代码

你提到的疑问点具体解释 #

1. 耗时最高的pulp内部__init__方法不是你写的 #

你在自己的代码中调用Pulp创建变量、添加约束的逻辑，都会触发Pulp底层的初始化操作。24.2万次调用说明你的建模规模较大，这部分耗时是你调用Pulp的逻辑间接产生的，优化方向要从你自己的建模代码入手。

2. mps_lp.py中的<listcomp>不是你写的列表推导式 #

这是Pulp的MPS格式导出模块内部的列表推导式，对应结果中第10行的writeMPS函数（累计耗时0.57s），你代码中调用了Pulp导出MPS模型的方法，才会触发这部分逻辑的执行。

3. {method 'do_handshake' of '_ssl._SSLSocket' objects}等底层调用的含义 #

这类条目都是网络请求相关的底层耗时：

• do_handshake是HTTPS请求的SSL握手耗时
• _ssl._SSLSocket的read方法是加密网络数据读取耗时
• _winapi.WaitForSingleObject是Windows系统等待网络请求返回的阻塞耗时
  说明你的脚本存在HTTPS网络请求的逻辑，这部分耗时和Pulp无关，属于网络交互开销。

定位你自己代码优化点的方法 #

优先关注你自己编写的函数的cumtime值，顺着调用链向上溯源，找到是你写的哪个函数调用了这些高耗时的底层逻辑，就是优化的入口。
从你当前的输出可以直接得到几个优化方向：

• 415万次__hash__调用、24万次__init__调用说明建模冗余度高，可以检查是否存在重复创建变量、重复添加约束的逻辑，简化建模规则
• writeMPS累计耗时0.57s，若不需要导出MPS文件可以直接关闭该步骤，需要导出的话可以检查是否有不必要的导出内容
• 网络相关总耗时接近0.7s，可以检查是否可以复用SSL连接、减少请求次数、批量请求接口来降低这部分开销
• 你自己编写的betfairFinalArray函数自身耗时0.171s，占累计耗时的90%以上，说明函数内部逻辑耗时长，可以单独优化这部分的代码逻辑

内容的提问来源于stack exchange，提问作者beginner_python