填坑總結：python記憶體洩漏排查小技巧

華為雲開發者社群發表於2021-11-23
Python記憶體
摘要：最近服務遇到了記憶體洩漏問題，運維同學緊急呼叫解決，於是在解決問題之餘也系統記錄了下記憶體洩漏問題的常見解決思路。

本文分享自華為雲社群《python記憶體洩漏排查小技巧》，作者：lutianfei。

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

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

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

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

填坑總結：python記憶體洩漏排查小技巧

思路一：研究新舊原始碼及二方庫依賴差異

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

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

從上述兩個角度出發：

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

填坑總結：python記憶體洩漏排查小技巧

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

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

目前python常用的記憶體檢測工具有pympler、objgraph、tracemalloc 等。

首先，通過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個小時，一切穩如老狗，各型別的數量沒有一絲波瀾。

填坑總結：python記憶體洩漏排查小技巧

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

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

平靜資料就此被打破了，如下圖紅框所示：dict、function、method、tuple、traceback等重要型別的數量開始不斷攀升。

填坑總結：python記憶體洩漏排查小技巧

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

填坑總結：python記憶體洩漏排查小技巧

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

填坑總結：python記憶體洩漏排查小技巧

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

填坑總結：python記憶體洩漏排查小技巧

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

異常宣告如下：

填坑總結：python記憶體洩漏排查小技巧

拋異常程式碼如下：

填坑總結：python記憶體洩漏排查小技巧

問題所在

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

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

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

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

帶著以上兩個疑問，我們做了兩個驗證：

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

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

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

進階思路

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

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

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

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

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

填坑總結：python記憶體洩漏排查小技巧

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

填坑總結：python記憶體洩漏排查小技巧

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

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]
    )

通過graphviz的dot工具,對上面生產的graph格式資料轉換成如下圖片：

dot -Tpng xxx.dot -o xxx.png

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

記憶體新增的ImageReqWrapper的呼叫鏈

填坑總結：python記憶體洩漏排查小技巧

記憶體新增的traceback的呼叫鏈：

填坑總結：python記憶體洩漏排查小技巧

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

另，關於 python3中 快取Exception導致的記憶體洩漏問題，知乎有一篇講的相對更清楚一點：https://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()

填坑總結：python記憶體洩漏排查小技巧

參考文章

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

 

點選關注，第一時間瞭解華為雲新鮮技術~

相關文章