十年匠心定制 · 商业建站与技术教学双线并行 咨询热线:400-886-1026 service@lmnt.cn
ARTICLE DETAIL

资讯详情

深耕网站建设与运营推广的一线实战洞察。

你以为的性能瓶颈,未必是真的瓶颈:用 cProfile 找到真凶

你以为的性能瓶颈,未必是真的瓶颈:用 cProfile 找到真凶 「Python 进阶之路」系列 Day24写在前面写代码的人对哪里慢通常都有一种直觉习惯性地怀疑那些看起来循环次数多、计算量大的代码。但今天用一个实测例子说明这种直觉经常是错的真正的瓶颈可能藏在一行毫不起眼的代码里。找瓶颈不该靠猜该靠cProfile。一、是什么确定性性能分析器cProfile是 Python 内置的确定性性能分析器deterministic profiler——它会精确追踪程序运行过程中每一次函数调用统计每个函数被调用了多少次、自身代码耗时多少、连同它调用的其他函数一共耗时多少。最简单的用法importcProfile cProfile.run(main_work())或者命令行直接跑python-mcProfile-scumtime script.py二、为什么不能凭直觉猜瓶颈写代码的人对哪里慢经常有一种直觉——通常会盯着那些看起来计算量大的循环但真实的瓶颈经常藏在意想不到的地方一次不起眼的阻塞调用、一个被反复调用的小函数、一段隐藏的 I/O 等待。凭直觉去优化很可能把力气花在了根本不是瓶颈的地方这正是需要cProfile这类工具的原因——一次运行自动统计整个调用图里每一个函数的真实耗时不需要在代码里到处手动插入time.perf_counter()计时也不会遗漏。三、怎么用1. 实测用cProfile揪出被忽略的真凶importcProfile,timedefslow_string_concat(n):sforiinrange(n):sstr(i)returnsdeflooks_slow_but_isnt(n):total0foriinrange(n):totali*i time.sleep(0.05)# 看起来只是顺手睡一下很容易被忽略returntotaldeffast_join(n):return.join(str(i)foriinrange(n))defmain_work():slow_string_concat(200_000)looks_slow_but_isnt(200_000)fast_join(200_000)cProfile.run(main_work())跑出来的原始结果按函数名排序ncalls tottime percall cumtime percall filename:lineno(function) 1 0.023 0.023 0.023 0.023 slow_string_concat 1 0.006 0.006 0.057 0.057 looks_slow_but_isnt 1 0.051 0.051 0.051 0.051 {built-in method time.sleep} 1 0.008 0.008 0.029 0.029 {method join of str objects}很多人凭直觉会觉得slow_string_concat才是耗时大头看起来是一个 20 万次循环拼字符串但实测发现time.sleep(0.05)这一行单独拿出来的耗时0.051s比整个字符串拼接函数自身的代码耗时0.023s还要多。looks_slow_but_isnt函数自己的循环代码只花了 0.006s但因为它内部调用了time.sleep算上这次调用后总耗时飙到了 0.057s——如果只看函数名字、不用工具实测很容易完全漏掉这个藏在一个看起来只是普通计算函数里的阻塞调用。另一个值得注意的发现这次实测里朴素的字符串拼接0.023s和.join()0.029s含join调用与生成器耗时并没有出现网上常说的拼接是灾难性 O(n²)、必须用join那种悬殊差距——现代 CPython 对变量自身引用计数为 1 时的原地拼接做了专门优化实际表现比很多教程描述的要好得多。这类流传很广但不一定在当前版本成立的说法同样应该靠实测验证而不是直接当作教条。Day25 会更系统地讲字符串拼接这类常见性能陷阱。2. 用pstats排序、过滤输出cProfile.run()默认按函数名排序不方便一眼看出谁最耗时配合pstats模块可以按需要的指标排序、只看前几名importpstats profilercProfile.Profile()profiler.enable()main_work()profiler.disable()statspstats.Stats(profiler)stats.sort_stats(tottime)# 按函数自身耗时排序stats.print_stats(6)# 只看前6名按tottime排序后time.sleep直接排在了第一位——这一步排序把谁的自身代码最耗时这个问题一眼摆在了面前不用再逐行去读一堆没排序的数据。写代码用cProfile跑一遍看tottime cumtime排序定位真正耗时最多的函数针对性优化3. tottime vs cumtime怎么读tottimetotal time这个函数自身代码的执行耗时不包括它调用的其他函数花的时间cumtimecumulative time这个函数从进入到返回的总耗时包括它调用的所有子函数耗时也包括递归调用looks_slow_but_isnt是最典型的例子它自身的tottime只有 0.006s就是那个for循环算平方和的代码但因为它内部调用了time.sleep(0.05)cumtime变成了 0.057s——看cumtime才能知道调用这个函数总共要等多久看tottime才能知道问题到底出在这个函数自己的代码里还是它调用的别的函数里两个指标要配合着看只看一个容易得出错误结论。四、面试追问Q1cProfile 是怎么工作的它是一个确定性性能分析器通过钩子机制精确追踪程序运行过程中每一次函数调用统计每个函数的调用次数、自身耗时tottime、累计耗时cumtime一次运行就能拿到整个调用图的耗时分布不需要手动到处插桩计时。Q2tottime 和 cumtime 的区别是什么tottime是函数自身代码的执行耗时不包含它调用的子函数花的时间cumtime是包含所有子函数调用含递归在内的总耗时。一个函数自身逻辑很简单但调用了一个耗时的子函数时会表现为tottime很小但cumtime很大这种情况说明真正的瓶颈在被调用的那个子函数身上。Q3为什么不能靠直觉判断性能瓶颈直觉容易被看起来计算量大的代码误导——真实的瓶颈经常藏在不起眼的地方比如一次容易被忽略的阻塞调用、一个被反复调用的小函数。实测中一个看似普通的计算函数因为内部藏了time.sleep耗时反而超过了看起来更耗时的循环这就是不实测就下结论会踩的坑。Q4cProfile 和采样型 profiler 有什么区别cProfile是确定性分析精确记录每一次函数调用数据准确但因为要追踪所有调用会带来一定的性能开销采样型 profiler如 py-spy是按固定时间间隔抽样记录当前的调用栈开销更小、更适合在生产环境里使用但得到的是统计估计的结果不是精确值。Q5定位到瓶颈之后常见的优化思路是什么先看瓶颈的性质如果是tottime高说明问题在这个函数自身的代码逻辑里考虑优化算法或数据结构如果是cumtime高但自身tottime低说明问题在它调用的某个子函数身上需要顺着调用链往下找常见的原因是不必要的阻塞调用、可以缓存起来的重复计算或者可以异步化处理的 I/O 操作。下一篇预告Day25 是模块五的收官篇——常见性能陷阱字符串拼接、全局变量查找、列表 vs 生成器把这些容易被误传或者被过度简化的性能结论逐一实测验证清楚。
返回列表