项目背景：

组里的几个同学最近在开发一个系统模拟器，当模拟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，原因是它可以很方便地生成火焰图。火焰图是类似下面的图形，具体了解火焰图，可以访问《如何读懂火焰图》这篇文章。

image

安装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，将其抽取到循环外面即可解决。

image

再次复测：

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

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

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

总结：

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