某测试模拟器性能优化-用vprof对Python程序性能调优

项目背景:

组里的几个同学最近在开发一个系统模拟器,当模拟20w节点在线的时候,发现有一个组件log_generator占用CPU特别严重,经常出现占用的CPU超过120%的情况。该组件使用的是多线程模型,所以虽然机器CPU是4核的,也无法利用其它CPU分担负载。

考虑到我们下阶段的目标是模拟100w节点同时在线,现在的模拟器性能肯定无法满足要求,所以必须对该模拟器进行性能调优。

熟悉代码:

为了解决这个问题,我首先把log_generator这个组件的代码看了一遍。该组件同时订阅10个不同的redis channel,将读到的数据,写成特定格式的日志文件,供ELK读取,然后再将这些数据写入到不同kafka的topic中去。为了提高效率,该组件为每个redis channel启动一个单独的线程用于监听,写本地文件和写kafka。

看完代码后,初步怀疑两个地方可能引起性能瓶颈,一个是监听redis的channel写日志,一个是将读取的内容写到kafka中去。为了验证自己的想法,开始着手对程序进行profiling.

vprof和火焰图:

这里,我选择一个开源的性能分析工具vprof,原因是它可以很方便地生成火焰图。火焰图是类似下面的图形,具体了解火焰图,可以访问《如何读懂火焰图》这篇文章。

安装vprof很简单

pip install vprof

由于是多线程后台运行,如果要采集一段时间的性能统计数据,必须要让子线程在一段时间内跟随主线程退出,这个时候可以使用线程的t.setDaemon(True)方法,这样,当主线程退出后,子线程也会自动停止运行。

收集性能数据可以使用

vprof -c cmh log_generator.py

这样的命令,其中-c代表配置

配置里面的c,表示cpu火焰图,m表示内存图,h表示代码热图

当主程序退出后,vprof会自动收集这些数据,并且启动一个http服务器,自动打开浏览器将指定的图表打开展示出来。

如果你是在远程机器上收集数据,那么可以通过下面的方法,先将数据收集为json文件,将其复制到本地,然后再在本地通过vprof展示结果。

vprof -c cmh log_generator.py --output-file profile.json
vprof --input-file profile.json

分析结果:

通过vprof,我们采集到了log_generator组件的性能数据,发现有两个函数的采样特别多,一个是kafka相关的操作(包含requests操作),一个是根本就不可能用到的ORM模块。

ORM这个问题特别不可思议,仔细看火焰图上的调用关系,原来是谁不小心在公用的变量文件里面定义了一个ORM操作的函数,当log_generator用from import *这样的语句导入该文件的变量时,该ORM函数自动就被执行了~ 发现一个bug!

那么requests操作为何有这么多呢?原来是每次写kafka的topic前,代码都先通过http请求获得该topic的schema格式,然后再进行编码写入。由于schema是不变的,所以完全没有必要每次写kafka都获取一遍schema,此处也有bug,将其抽取到循环外面即可解决。

再次复测:

将修改后的代码再次上机运行,发现log_generator组件还是有严重占用CPU的情况,调优工作并未取得明显的效果。

这才是真正的人生嘛,怎么可能那么简单就解决问题的?

那,到底是什么原因导致了log_generator组件的CPU占用居高不下呢,且听下回分解。

总结:

通过本文,您已基本了解如何使用vprof工具进行Python代码性能调优了。