項目背景：

組里的幾個同學最近在開發(fā)一個系統(tǒng)模擬器，當模擬20w節(jié)點在線的時候，發(fā)現(xiàn)有一個組件log_generator占用CPU特別嚴重，經(jīng)常出現(xiàn)占用的CPU超過120%的情況。該組件使用的是多線程模型，所以雖然機器CPU是4核的，也無法利用其它CPU分擔負載。

考慮到我們下階段的目標是模擬100w節(jié)點同時在線，現(xiàn)在的模擬器性能肯定無法滿足要求，所以必須對該模擬器進行性能調(diào)優(yōu)。

熟悉代碼：

為了解決這個問題，我首先把log_generator這個組件的代碼看了一遍。該組件同時訂閱10個不同的redis channel，將讀到的數(shù)據(jù)，寫成特定格式的日志文件，供ELK讀取，然后再將這些數(shù)據(jù)寫入到不同kafka的topic中去。為了提高效率，該組件為每個redis channel啟動一個單獨的線程用于監(jiān)聽，寫本地文件和寫kafka。

看完代碼后，初步懷疑兩個地方可能引起性能瓶頸，一個是監(jiān)聽redis的channel寫日志，一個是將讀取的內(nèi)容寫到kafka中去。為了驗證自己的想法，開始著手對程序進行profiling.

vprof和火焰圖：

這里，我選擇一個開源的性能分析工具vprof，原因是它可以很方便地生成火焰圖?；鹧鎴D是類似下面的圖形，具體了解火焰圖，可以訪問《如何讀懂火焰圖》這篇文章。

image

安裝vprof很簡單

pip install vprof

由于是多線程后臺運行，如果要采集一段時間的性能統(tǒng)計數(shù)據(jù)，必須要讓子線程在一段時間內(nèi)跟隨主線程退出，這個時候可以使用線程的t.setDaemon(True)方法，這樣，當主線程退出后，子線程也會自動停止運行。

收集性能數(shù)據(jù)可以使用

vprof -c cmh log_generator.py

這樣的命令，其中-c代表配置

配置里面的c，表示cpu火焰圖，m表示內(nèi)存圖，h表示代碼熱圖

當主程序退出后，vprof會自動收集這些數(shù)據(jù)，并且啟動一個http服務器，自動打開瀏覽器將指定的圖表打開展示出來。

如果你是在遠程機器上收集數(shù)據(jù)，那么可以通過下面的方法，先將數(shù)據(jù)收集為json文件，將其復制到本地，然后再在本地通過vprof展示結果。

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

分析結果：

通過vprof，我們采集到了log_generator組件的性能數(shù)據(jù)，發(fā)現(xiàn)有兩個函數(shù)的采樣特別多，一個是kafka相關的操作（包含requests操作），一個是根本就不可能用到的ORM模塊。

ORM這個問題特別不可思議，仔細看火焰圖上的調(diào)用關系，原來是誰不小心在公用的變量文件里面定義了一個ORM操作的函數(shù)，當log_generator用from import *這樣的語句導入該文件的變量時，該ORM函數(shù)自動就被執(zhí)行了~ 發(fā)現(xiàn)一個bug！

那么requests操作為何有這么多呢？原來是每次寫kafka的topic前，代碼都先通過http請求獲得該topic的schema格式，然后再進行編碼寫入。由于schema是不變的，所以完全沒有必要每次寫kafka都獲取一遍schema，此處也有bug，將其抽取到循環(huán)外面即可解決。

image

再次復測：

將修改后的代碼再次上機運行，發(fā)現(xiàn)log_generator組件還是有嚴重占用CPU的情況，調(diào)優(yōu)工作并未取得明顯的效果。

這才是真正的人生嘛，怎么可能那么簡單就解決問題的？

那，到底是什么原因?qū)е铝薼og_generator組件的CPU占用居高不下呢，且聽下回分解。

總結：

通過本文，您已基本了解如何使用vprof工具進行Python代碼性能調(diào)優(yōu)了。