使用 cProfile 和火焰图调优 Python 程序性能
前幾天調試程序，發現 QPS 總是卡在 20 左右上不去。開始以為是 IO 問題，就多開了些并發，然并卵，這才想到可能是 CPU 的問題。看了看監控，發現程序某一步的延遲在 400ms 左右，而且這一步是 CPU 密集的。當時開了 4 臺雙核的機器：(1s / 400ms) * 2 * 4 = 20 啊。看來需要優化下這一步的代碼了，那么第一步就是找到可以優化的地方。
測量程序的性能之前并沒有實際做過，Google 了一番，感覺標準庫的 cProfile 似乎值得一試。
要測量的代碼邏輯也很簡單，使用 lxml 解析 HTML，然后提取一些字段出來，這些基本都是調用的 C 庫了，解析的算法也不在 Python 中。看起來似乎沒有什么能改進的地方，不管怎樣，還是先跑一下吧。
cProfile 有多種調用方法，可以直接從命令行調用：
python -m cProfile -s tottime your_program.py其中的?-s?的意思是 sort。常用的 sort 類型有兩個：
要獲得對程序性能的全面理解，經常需要兩個指標都看一下。
不過在這里，我們并不能直接使用命令行方式調用，因為我的代碼中還需要一些比較繁重的配置加載，如果把這部分時間算進去了，多少有些干擾，那么我們也可以直接在代碼中調用 cProfile。
使用 cProfile 的代碼如下：
import cProfile, pstats, iopr = cProfile.Profile() pr.enable()extractor.extract(crawl_doc=doc, composition=PageComposition.row, rule=rule)pr.disable() s = io.StringIO() sortby = "cumtime" # 僅適用于 3.6, 3.7 把這里改成常量了 ps = pstats.Stats(pr, stream=s).sort_stats(sortby) ps.print_stats() print(s.getvalue())把需要 profile 的代碼放到 pr.enable 和 pr.disable 中間就好了。注意這里我們使用了 cumtime 排序，也就是累計運行時間。
結果如下：
我們可以看到總的運行時間是 200ms，而其中紅框內的部分就占了 100ms! 如果能夠優化調的話，性能一下子就能提高一倍。紅框內的代碼是做什么的呢？我們知道解析一個 html 文檔，第一步是建立 DOM 樹，通常情況下，我們可能會從其中抽取一些鏈接。在網頁中，鏈接不一定是絕對路徑，也可能是?/images/2018-12-31-xxx.jpg?這樣的相對路徑。lxml 庫幫我們做了一個貼心的默認值，那就是在構造 DOM 樹的時候，根據傳入的 url 來吧頁面中的所有 url 都重寫成絕對路徑。看起來這是個很貼心的功能，但是在這里卻成了性能瓶頸。為什么很耗時呢？大概是因為需要遍歷整個 DOM 樹，重寫所有的鏈接吧。這顯然不是我們需要的，我們只需要把抽取之后的鏈接還原成絕對路徑就好了，而不是事先把所有鏈接都重寫一遍。所以在這里我們直接去掉這個功能就好了。
修改代碼之后，再次運行 profile 腳本，時長變成了 100ms：
這時候我們接著看，程序中下一個比較大頭的時間占用：jsonfinder 和 json decode/encode。
jsonfinder 是一個有意思的庫，它自動從 HTML 中查找 json 字符串并嘗試解析，但是有時候也不太準。經常為了找到特定的值，還是需要使用正則。那么對于這個可有可無的功能，性能有這么差，還是刪掉好了。
通過刪代碼，現在性能已經是原來的四倍了。
這時候發現代碼里面有正則還挺花費時間的，不過還好，暫時先不管了。
剛剛都是只運行了一遍，測量結果難免有隨機性，必定有失偏頗，實際上應該使用多個測試用例，成千上萬次的跑，才能得到一個比較準確地結果。
上面這個小步驟基本沒有什么可以優化的了，下面我們把優化目標擴大一點，并把次數先定為100.
下面這種圖是按照 tottime 來排序的：
注意其中最耗時的步驟是 parseUnicodeDoc，也就是建樹了，這是符合預期的，然而旁邊的 ncalls 一欄卻不太對勁了。我們明明只運行了 100 次，為什么這個函數調用了 300 次呢？顯然代碼中有重復建樹的地方，也就是有隱藏的 bug。這種地方不經過 profile 很難浮現出來，因為程序本身的邏輯是對的，只是比較耗時而已。
優化之后，終于變成了 100. 從 cProfile 的表格現在已經看不出什么結果來了，下一步我們開始使用火焰圖，可視化往往能讓我們更容易注視到性能瓶頸。（為什么不一開始就用火焰圖呢？因為我以為很麻煩。。實際很簡單）
Python 中有一個第三方包(見參考文獻)可以直接從 cProfile 的結果生成火焰圖:
然后打開 SVG 文件就可以了：
其中火焰的寬度代表了運行的時長，我們現在的優化目標就是這些耗時比較長的步驟。
可以看大其中 mysql 的訪問占了絕對的大頭，按理說跑100次的話，不應該每次都花費時間在建立連接上啊，這里一定有問題。經過排查發現在某處鏈接是使用了?close_old_connections?來保證不會拋出數據庫斷開的異常，這還是在頭條帶來的習慣。。close_old_connections 的功能是關閉已經失效的鏈接，看來我的理解還是有誤的。先把這塊刪掉，最終解決應該是這塊放到一個隊列里，統一存入數據庫。
去掉之后：
現在的大頭又變成 lxml 的，又動了優化它的心思，lxml 是 libxml2 的一個 Python binding，查了下應該是最快的 html parser 了，這塊真的沒有什么優化空間。盯了一會兒，眼睛最終看到了一個小角落：
一個正則匹配居然占用了 8% 的運行時間，太不像話了。老早之前就聽說 Python 的標準庫正則性能不行，現在才發現原來是真的挺差勁的。Python 標準庫的 re 模塊采用的是 PCRE 的處理方式，而采用 NFA 的處理方式的正則要快很多，這塊還需要再看一下。不過眼下倒是可以直接換一個庫來解決。regex 模塊是 re 模塊的一個 drop-in replacement.
pip install regex?and?import regex as re，就搞定了
可以看到正則那塊直接消失了。提升還是很大的。時間不早了，當天的優化就到此結束了。上線之后，積壓一下子就下去了：
后記
要想調試的時候方便，在寫代碼的時候就要注意，盡量使自己的代碼 mock-friendly 一點。如果需要引入外部的數據庫、服務、API等等各種資源，最好有一個開關或者選項能夠不加載外部資源，或者至少能夠很方便地 mock 這些外部服務，這樣方便對每一個小單元進行 profile。
總有人吐槽 Python 的性能低下，但是 Python 本來就不是做計算任務的呀，Python 是一門膠水語言，是用來寫業務邏輯的，而不是用來寫CPU密集的算法的。事實上復雜的解析一般都會用 C++ 這種硬核語言來寫了，比如 numpy TensorFlow lxml。大多數程序員一天 90% 的工作除了和產品經理撕逼以外，也就是在寫 CRUD，也就是調用這些包。所以瓶頸一般在 IO 上而不在 CPU 上，而解決 IO 的瓶頸手段就多了，Python 中至少有 多進程、多線程、AsyncIO、Gevent 等多種方法。不過方法多其實也是一個弊端，這幾種方法可以說是基本互不兼容，對各種第三方庫的支持也參差不齊。而 Go 在這方面就做地很好了，語言直接內置了 go 關鍵字，甚至都不支持多線程。所有的庫都是支持一個統一的并發模型，對于使用者來說更簡單。
Zen of Python 中有一句：There should be one way -- preferably only one way -- to do a thing. 這點上 Python 本身沒有做到，反倒是 Go 實踐地非常好。
扯遠了，程序的瓶頸其實不外乎CPU、內存和 IO 三個方面，而 cProfile 和火焰圖是判斷 CPU 瓶頸的一把利器。
后面還發現了一些性能瓶頸，也列在這里：
性能這個問題其實是典型的木桶理論的場景，系統的整體性能是由最差的一塊決定的。所以也是一個不斷迭代的過程。
祝大家新年快樂~
參考文獻
總結
以上是生活随笔為你收集整理的使用 cProfile 和火焰图调优 Python 程序性能的全部內容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： 阿里妈妈搜索广告CTR模型的“瘦身”之路
- 下一篇： websocket python爬虫_p