填坑總結:python記憶體泄漏排查小技巧

摘要:最近服務遇到了記憶體泄漏問題,運維同學緊急呼叫解決,於是在解決問題之餘也系統記錄了下記憶體泄漏問題的常見解決思路。

本文分享自華為雲社區《python記憶體泄漏排查小技巧》,作者:lutianfei。

最近服務遇到了記憶體泄漏問題,運維同學緊急呼叫解決,於是在解決問題之餘也系統記錄了下記憶體泄漏問題的常見解決思路。

首先搞清楚了本次問題的現象:

1. 服務在13號上線過一次,而從23號開始,出現記憶體不斷攀升問題,達到預警值重啟實例後,攀升速度反而更快。

2. 服務分別部署在了A、B 2種晶片上,但除模型推理外,幾乎所有的預處理、後處理共享一套程式碼。而B晶片出現記憶體泄漏警告,A晶片未出現任何異常。

思路一:研究新舊源碼及二方庫依賴差異

根據以上兩個條件,首先想到的是13號的更新引入的問題,而更新可能來自兩個方面:

  1. 自研程式碼
  2. 二方依賴程式碼

從上述兩個角度出發:

  • 一方面,分別用Git歷史資訊和BeyondCompare工具對比了兩個版本的源碼,並重點走讀了下A、B兩款晶片程式碼單獨處理的部分,均未發現任何異常。
  • 另一方面,通過pip list命令對比兩個鏡像包中的二方包,發現僅有pytz時區工具依賴的版本有變化。
    經過研究分析,認為此包導致的記憶體泄漏的可能性不大,因此暫且放下。

至此,通過研究新舊版本源碼變化找出記憶體泄漏問題這條路,似乎有點走不下去了。

思路二:監測新舊版本記憶體變化差異

目前python常用的記憶體檢測工具有pymplerobjgraphtracemalloc 等。

首先,通過objgraph工具,對新舊服務中的TOP50變數類型進行了觀察統計

objraph常用命令如下:

# 全局類型數量
objgraph.show_most_common_types(limit=50)

# 增量變化
objgraph.show_growth(limit=30)

這裡為了更好的觀測變化曲線,我簡單做了個封裝,使數據直接輸出到了csv文件以便觀察。

stats = objgraph.most_common_types(limit=50)
stats_path = "./types_stats.csv"
tmp_dict = dict(stats)
req_time = time.strftime("%Y-%m-%d %H:%M:%S", time.localtime())
tmp_dict['req_time'] = req_time
df = pd.DataFrame.from_dict(tmp_dict, orient='index').T

if os.path.exists(stats_path):
    df.to_csv(stats_path, mode='a', header=True, index=False)
else:
    df.to_csv(stats_path, index=False)

如下圖所示,用一批圖片在新舊兩個版本上跑了1個小時,一切穩如老狗,各類型的數量沒有一絲波瀾。

此時,想到自己一般在轉測或上線前都會將一批異常格式的圖片拿來做個邊界驗證。

雖然這些異常,測試同學上線前肯定都已經驗證過了,但死馬當成活馬醫就順手拿來測了一下。

平靜數據就此被打破了,如下圖紅框所示:dictfunctionmethodtupletraceback等重要類型的數量開始不斷攀升。

而此時鏡像記憶體亦不斷增加且毫無收斂跡象。

由此,雖無法確認是否為線上問題,但至少定位出了一個bug。而此時回頭檢查日誌,發現了一個奇怪的現象:
正常情況下特殊圖片導致的異常,日誌應該輸出如下資訊,即check_image_type方法在異常棧中只會列印一次。

但現狀是check_image_type方法循環重複列印了多次,且重複次數隨著測試次數在一起變多。

重新研究了這塊兒的異常處理程式碼。

異常聲明如下:

拋異常程式碼如下:

問題所在

思考後大概想清楚了問題根源:

這裡每個異常實例相當於被定義成了一個全局變數,而在拋異常的時候,拋出的也正是這個全局變數。當此全局變數被壓入異常棧處理完成之後,也並不會被回收。

因此隨著錯誤格式圖片調用的不斷增多,異常棧中的資訊也會不斷增多。而且由於異常中還包含著請求圖片資訊,因此記憶體會呈MB級別的增加。

但這部分程式碼上線已久,線上如果真的也是這裡導致的問題,為何之前沒有任何問題,而且為何在A晶片上也沒有出現任何問題?

帶著以上兩個疑問,我們做了兩個驗證:

首先,確認了之前的版本以及A晶片上同樣會出現此問題。

其次,我們查看了線上的調用記錄,發現最近剛好新接入了一個客戶,而且出現了大量使用類似問題的圖片調用某局點(該局點大部分為B晶片)服務的現象。我們找了些線上實例,從日誌中也觀測到了同樣的現象。

由此,以上疑問基本得到了解釋,修復此bug後,記憶體溢出問題不再出現。

進階思路

講道理,問題解決到這個地步似乎可以收工了。但我問了自己一個問題,如果當初沒有列印這一行日誌,或者開發人員偷懶沒有把異常棧全部打出來,那應該如何去定位?

帶著這樣的問題我繼續研究了下objgraphpympler 工具。

前文已經定位到了在異常圖片情況下會出現記憶體泄漏,因此重點來看下此時有哪些異樣情況:

通過如下命令,我們可以看到每次異常出現時,記憶體中都增加了哪些變數以及增加的記憶體情況。

  1. 使用objgraph工具
    objgraph.show_growth(limit=20)

  1. 使用pympler工具
from pympler import tracker
tr = tracker.SummaryTracker()
tr.print_diff()

通過如下程式碼,可以列印出這些新增變數來自哪些引用,以便進一步分析。

gth = objgraph.growth(limit=20)
for gt in gth:
    logger.info("growth type:%s, count:%s, growth:%s" % (gt[0], gt[1], gt[2]))
    if gt[2] > 100 or gt[1] > 300:
        continue
    objgraph.show_backrefs(objgraph.by_type(gt[0])[0], max_depth=10, too_many=5,
                           filename="./dots/%s_backrefs.dot" % gt[0])
    objgraph.show_refs(objgraph.by_type(gt[0])[0], max_depth=10, too_many=5,
                       filename="./dots/%s_refs.dot" % gt[0])
    objgraph.show_chain(
        objgraph.find_backref_chain(objgraph.by_type(gt[0])[0], objgraph.is_proper_module),
        filename="./dots/%s_chain.dot" % gt[0]
    )

通過graphvizdot工具,對上面生產的graph格式數據轉換成如下圖片:

dot -Tpng xxx.dot -o xxx.png

這裡,由於dict、list、frame、tuple、method等基本類型數量太多,觀測較難,因此這裡先做了過濾。

記憶體新增的ImageReqWrapper的調用鏈

記憶體新增的traceback的調用鏈:

雖然帶著前面的先驗知識,使我們很自然的就關注到了traceback和其對應的IMAGE_FORMAT_EXCEPTION異常。
但通過思考為何上面這些本應在服務調用結束後就被回收的變數卻沒有被回收,尤其是所有的traceback變數在被IMAGE_FORMAT_EXCEPTION異常調用後就無法回收等這些現象;同時再做一些小實驗,相信很快就能定位到問題根源。

另,關於 python3中 快取Exception導致的記憶體泄漏問題,知乎有一篇講的相對更清楚一點://zhuanlan.zhihu.com/p/38600861

至此,我們可以得出結論如下:

由於拋出的異常無法回收,導致對應的異常棧、請求體等變數都無法被回收,而請求體中由於包含圖片資訊因此每次這類請求都會導致MB級別的記憶體泄漏。

另外,研究過程中還發現python3自帶了一個記憶體分析工具tracemalloc,通過如下程式碼就可以觀察程式碼行與記憶體之間的關係,雖然可能未必精確,但也能大概提供一些線索。

import tracemalloc

tracemalloc.start(25)
snapshot = tracemalloc.take_snapshot()
global snapshot
gc.collect()
snapshot1 = tracemalloc.take_snapshot()
top_stats = snapshot1.compare_to(snapshot, 'lineno')
logger.warning("[ Top 20 differences ]")
for stat in top_stats[:20]:
    if stat.size_diff < 0:
        continue
    logger.warning(stat)
snapshot = tracemalloc.take_snapshot()

參考文章

//testerhome.com/articles/19870?order_by=created_at&
//blog.51cto.com/u_3423936/3019476
//segmentfault.com/a/1190000038277797
//www.cnblogs.com/zzbj/p/13532156.html
//drmingdrmer.github.io/tech/programming/2017/05/06/python-mem.html
//zhuanlan.zhihu.com/p/38600861

 

點擊關注,第一時間了解華為雲新鮮技術~