背景

我們?cè)诠ぷ髦惺褂?DDAgent Ver. 5 作為采集工具進(jìn)行被管服務(wù)器的性能指標(biāo)采集與上報(bào)，并且對(duì) DDAgent 做了一定程度的定制。在幾次特性迭代后，發(fā)現(xiàn)線上一批運(yùn)行許久的被管服務(wù)器出現(xiàn)內(nèi)存占用過高。分析問題機(jī)器上進(jìn)程樹各節(jié)點(diǎn)占用情況，看到 DDAgent 采集進(jìn)程的內(nèi)存占用居高不下。

作為保障業(yè)務(wù)系統(tǒng)穩(wěn)定作業(yè)的監(jiān)控組件發(fā)生了內(nèi)存泄漏，自然是非常嚴(yán)重的，所以開始我們的“排查之旅”。

分析

有許多工具提供了對(duì) Python 程序內(nèi)存狀態(tài)的分析與導(dǎo)出，這里我們使用 pyrasite，它可以 attach 到一個(gè)運(yùn)行中的 Python 程序，生成一份內(nèi)存快照，并查看當(dāng)前有哪些對(duì)象類型分別占用了多少內(nèi)存，從大到小排序。

使用命令非常簡(jiǎn)單：pyrasite-memory-viewer <PID>，同時(shí)會(huì)生成一份快照文件： /tmp/pyrasite-<PID>-objects.json 。

由于無法提供真實(shí)生產(chǎn)中的數(shù)據(jù)，下文提及的所有數(shù)據(jù)均來自于問題版本在測(cè)試環(huán)境中運(yùn)行 12 小時(shí)之后的采樣。

在 pyrasite 提供的 CUI 視圖中，我們可以清晰地看到字典類型的對(duì)象實(shí)例占用內(nèi)存最多，達(dá)到了 3.4MB，有 6621 個(gè)實(shí)例：

可惜 pyrasite 的 CUI 界面沒有提供進(jìn)一步數(shù)據(jù)透視的能力，以查看這么多字典對(duì)象到底是哪些，有什么特征。

但我們也看到，內(nèi)存快照文件是 JSON 格式的可讀文本，打開后為如下結(jié)構(gòu)的內(nèi)容：

{'address': 139671453162096, 'type': 'instance', 'size': 72, 'refs': [139671565716816, 139671453172632]}
{'address': 139671453172632, 'type': 'dict', 'size': 1048, 'len': 4, 'refs': [139671677239136, 29053312, 139671565997664, 139671451015864, 139671677145776, 29056072, 139671677239040, 139671674819024]}
{'address': 139671674819024, 'type': 'bool', 'size': 24, 'value': 'True', 'refs': []}
{'address': 139671677239040, 'type': 'str', 'size': 43, 'len': 6, 'value': 'closed', 'refs': []}
{'address': 29056072, 'type': 'int', 'size': 24, 'value': 134, 'refs': []}
...

很容易猜出，每一行表示當(dāng)前內(nèi)存中的一個(gè) Python 對(duì)象，address 為該對(duì)象的內(nèi)存地址，type 為該對(duì)象的類型名，size 是該對(duì)象自身占據(jù)的內(nèi)存大?。ú怀鲆馔庠撝岛?sys.getsizeof 計(jì)算所得一致），如果對(duì)象類型為 int、str、bool 這種 Primitive Type，則通過 value 表示其值，如果對(duì)象類型為 str、tuple、list、dict 等容器類型（按 Python 定義嚴(yán)謹(jǐn)?shù)刂v是實(shí)現(xiàn)了 __len__ 方法的類型），那么通過 len 表示其元素?cái)?shù)量，最后一個(gè) refs 則表示這個(gè)對(duì)象上所引用其他對(duì)象的地址。

在對(duì)該快照文件中的字典對(duì)象做簡(jiǎn)單分析后，得到了一個(gè)很重要的情報(bào)：6621 個(gè)字典對(duì)象中有 4884 個(gè)都是空字典 ，占比 73.8%。

不論什么業(yè)務(wù)場(chǎng)景，在一個(gè)正常的 Python 程序?qū)崿F(xiàn)中，不可能有如此多的空字典。

想搞清為什么，就得找出在哪里創(chuàng)建了這些空字典對(duì)象。

但是到目前為止 pyrasite 提供的信息都已探索完，要進(jìn)一步排查，就得“另辟蹊徑”。

定位

我們針對(duì)發(fā)生泄漏的場(chǎng)景重新縷下思路，有如下事實(shí)和猜測(cè)：

• 一個(gè)或多個(gè)地方在持續(xù)創(chuàng)建空字典對(duì)象，并且無法回收它們，導(dǎo)致內(nèi)存泄漏
• 內(nèi)存泄漏量隨著時(shí)間變化而增長(zhǎng)，在指標(biāo)采集業(yè)務(wù)中，很可能是在每次采集過程中造成的泄漏，在間隔周期后又重復(fù)觸發(fā)
• 并未看到當(dāng)前依賴的 DDAgent 版本有未關(guān)閉的相關(guān) Issue，很可能是我們定制過程中引入的 Bug

但是，哪怕一次最簡(jiǎn)單的系統(tǒng)基礎(chǔ)指標(biāo)采集，程序所跑過的代碼行數(shù)（DDAgent 框架代碼、采集 Check 插件代碼）都在千級(jí)規(guī)模，想靠人力去分析定位“泄漏點(diǎn)”，如同大海撈針。

同時(shí)我們還面臨一個(gè)挑戰(zhàn)：由于泄漏過程較慢，很難在本地測(cè)試環(huán)境進(jìn)行快速?gòu)?fù)現(xiàn)和分析。

如何克服上述困難？結(jié)合造成泄漏對(duì)象很重要的畫像——無法回收的空字典，我們或許可以借助 Python 解釋器的運(yùn)行時(shí)修改與自省特性來排查。

即，我們寫一段追蹤代碼，捕捉符合以下特征的對(duì)象：

• 特征 1：字典（dict）類型
• 特征 2：字典對(duì)象長(zhǎng)度為 0
• 特征 3：該對(duì)象的引用計(jì)數(shù)始終大于 0

對(duì)應(yīng)的解決方案是：

• 響應(yīng)特征 1：構(gòu)造一個(gè)字典類型，其：

  • 在初始化函數(shù) __init__ 中記錄自己被實(shí)例化時(shí)的堆棧信息，通過 traceback 模塊完成，這是實(shí)現(xiàn)追蹤的關(guān)鍵
  • 并通過 __builtin__ 模塊進(jìn)行運(yùn)行時(shí)替換，將內(nèi)置的 dict 換成該自定義類型，實(shí)現(xiàn)全局追蹤

    • 我們使用的解釋器版本為 CPython 2.7.13，所以是 __builtin__ 而不是 3.x 的 builtins
    • 該方案存在一些問題，但在我們這個(gè)場(chǎng)景中恰好夠用了，后面復(fù)盤時(shí)再提
• 響應(yīng)特征 2：這個(gè)最簡(jiǎn)單，需要時(shí) len(dict_obj) == 0 搞定
• 響應(yīng)特征 3：使用 weakref.WeakSet 實(shí)現(xiàn)追蹤表收集字典對(duì)象，通過“弱引用”特性避免追蹤代碼影響正常對(duì)象的回收

接著，只要定時(shí)將追蹤表中符合特征的內(nèi)容進(jìn)行輸出，就可以達(dá)到定位創(chuàng)建未回收空字典對(duì)象位置的目標(biāo)：

這里需要額外提及一下，由于 dict 字典對(duì)象沒有實(shí)現(xiàn) __hash__ 方法，因此它無法作為 Key 被插入到 dict、set、WeakSet 對(duì)象中，一句話測(cè)試下便知：

> python -c '{}[{}]=0'
Traceback (most recent call last):
  File '<string>', line 1, in <module>
TypeError: unhashable type: 'dict'

為了使其能被順利插入到 WeakSet 中，這里使用自增 Id 方案做最簡(jiǎn)單的 Hash 實(shí)現(xiàn)。

接著我們?cè)?DDAgent 的采集模塊 collect.py 入口處啟用這段追蹤代碼：

將采集進(jìn)程運(yùn)行一段時(shí)間后，我們得到了 traceinfo 文件：

[
  [
    ['.../embedded/lib/python2.7/threading.py',774,'__bootstrap','self.__bootstrap_inner()'],
    ['.../embedded/lib/python2.7/threading.py',801,'__bootstrap_inner','self.run()'],
    ['.../modules/monitor/bot/schedule.py',51,'run','task.run()'],
    ['.../modules/monitor/bot/task.py',50,'run','super(RepeatTask, self).run()'],
    ['.../modules/monitor/bot/task.py',18,'run','self.check()'],
    ['.../modules/monitor/checks/collector.py',223,'wrapper','_check.run()'],
    ['.../modules/monitor/checks/__init__.py',630,'run','self._roll_up_instance_metadata()'],
    ['.../modules/monitor/checks/__init__.py',498,'_roll_up_instance_metadata','dict((k, v) for (k, v) in self._instance_metadata))'],
    ['.../modules/monitor/tracer.py',33,'__init__','self.trace_info = traceback.extract_stack()']
  ],
  [
    ['.../embedded/lib/python2.7/threading.py',774,'__bootstrap','self.__bootstrap_inner()'],
    ['.../embedded/lib/python2.7/threading.py',801,'__bootstrap_inner','self.run()'],
    ['.../modules/monitor/bot/schedule.py',51,'run','task.run()'],
    ['.../modules/monitor/bot/task.py',50,'run','super(RepeatTask, self).run()'],
    ['.../modules/monitor/bot/task.py',18,'run','self.check()'],
    ['.../modules/monitor/checks/collector.py',223,'wrapper','_check.run()'],
    ['.../modules/monitor/checks/__init__.py',630,'run','self._roll_up_instance_metadata()'],
    ['.../modules/monitor/checks/__init__.py',498,'_roll_up_instance_metadata','dict((k, v) for (k, v) in self._instance_metadata))'],
    ['.../modules/monitor/tracer.py',33,'__init__','self.trace_info = traceback.extract_stack()']
  ],
  [
    ['.../embedded/lib/python2.7/threading.py',774,'__bootstrap','self.__bootstrap_inner()'],
    ['.../embedded/lib/python2.7/threading.py',801,'__bootstrap_inner','self.run()'],
    ['.../modules/monitor/bot/schedule.py',51,'run','task.run()'],
    ['.../modules/monitor/bot/task.py',50,'run','super(RepeatTask, self).run()'],
    ['.../modules/monitor/bot/task.py',18,'run','self.check()'],
    ['.../modules/monitor/checks/collector.py',223,'wrapper','_check.run()'],
    ['.../modules/monitor/checks/__init__.py',630,'run','self._roll_up_instance_metadata()'],
    ['.../modules/monitor/checks/__init__.py',498,'_roll_up_instance_metadata','dict((k, v) for (k, v) in self._instance_metadata))'],
    ['.../modules/monitor/tracer.py',33,'__init__','self.trace_info = traceback.extract_stack()']
  ],
...

不用花太多精力，就可以識(shí)別到幾乎所有的空字典對(duì)象都創(chuàng)建自 .../modules/monitor/checks/__init__.py 文件的第 498 行，在一個(gè)名為 _roll_up_instance_metadata 的方法中：

該方法在每個(gè)采集過程中都會(huì)被調(diào)用一次，每次調(diào)用將某些元數(shù)據(jù)插入到 svc_metadata 這個(gè)對(duì)象成員列表中。

既然有生產(chǎn)肯定有消費(fèi)，我們緊接著該方法就找到重置 svc_metadata 列表的代碼：

class AgentCheck(object):
    # ...
    def _roll_up_instance_metadata(self):
        # ...
    def get_service_metadata(self):
        if self._instance_metadata:
            self._roll_up_instance_metadata()  # 注意：這里并不是唯一調(diào)用 _roll_up_instance_metadata 的位置
        service_metadata = self.svc_metadata
        self.svc_metadata = []  # 重置
        return service_metadata

如果 get_service_metadata 方法能在每次采集過程末被成功調(diào)用，那至少 svc_metadata 不會(huì)產(chǎn)生數(shù)據(jù)堆積。

但是在檢查當(dāng)前版本的整體實(shí)現(xiàn)后，我們并沒找到任何一處觸發(fā) get_service_metadata 的地方。

隨后，通過對(duì)比 DDAgent 官方實(shí)現(xiàn)，并審查 Git 提交歷史，終于一切真相大白。

DDAgent 在 checks/collector.py 的第 416 行 調(diào)用了 get_service_metadata，對(duì)元數(shù)據(jù)進(jìn)行了消費(fèi)：

然而我們?cè)谀炒翁匦缘?，為了?run 方法看上去更整潔，將一些與需求實(shí)現(xiàn)無關(guān)的代碼全部移除了，包括對(duì) get_service_metadata 的調(diào)用！

移除消費(fèi)代碼，但生產(chǎn)代碼繼續(xù)在工作，這就是導(dǎo)致內(nèi)存泄漏的原因！

復(fù)盤

這里就不提諸如“做好設(shè)計(jì)評(píng)審與 Code Review”、“加強(qiáng)測(cè)試階段質(zhì)量檢測(cè)工作”等“套話”，當(dāng)然這些也值得我們反思。

內(nèi)存泄漏問題幾乎不可能徹底預(yù)防與治理，像 Rust 這樣的安全編程語言也 無法作出承諾保證程序不會(huì)發(fā)生內(nèi)存泄漏。

許多觸發(fā)內(nèi)存不安全的行為：數(shù)組訪問越界、訪問釋放后的內(nèi)存等，都可以通過制定更嚴(yán)格的編程模型（如 Rust 提出的所有權(quán)+生命周期規(guī)則）來規(guī)避——甚至可以規(guī)避數(shù)據(jù)競(jìng)爭(zhēng)（data-race）的問題。

然而觸發(fā)內(nèi)存泄漏的行為，和競(jìng)態(tài)條件（race-condition）一樣，則需要開發(fā)人員自己結(jié)合開發(fā)組件和業(yè)務(wù)規(guī)則進(jìn)行約束。試想一個(gè)需要手動(dòng)觸發(fā) flush 的數(shù)據(jù)隊(duì)列，結(jié)果我們?cè)诓煌Ｍ扑蛿?shù)據(jù)的同時(shí)卻忘了調(diào)用它，這種引發(fā)的內(nèi)存泄漏是無法靠任何通用檢查規(guī)則來甄別的。

敬畏編碼。

最后聊下我們的“排查之旅”其實(shí)非常幸運(yùn)，因?yàn)橛|發(fā)泄漏的關(guān)鍵代碼：

class AgentCheck(object):
    # ...
    def _roll_up_instance_metadata(self):
        self.svc_metadata.append(
            dict((k, v) for (k, v) in self._instance_metadata))
        self._instance_metadata = []

恰好使用 dict 類型構(gòu)造函數(shù)實(shí)例化了一個(gè)空字典！

如果直接使用字面量方式創(chuàng)建，如：self.svc_metadata.append({})，則是無法被追蹤到的 —— __builtin__ 模塊只能替換內(nèi)置類型構(gòu)造函數(shù)的入口，無法控制字面量。

假想通過字面量構(gòu)建空字典的內(nèi)存泄漏場(chǎng)景，我們又該如何排查？這里提供兩個(gè)思路，僅作記錄：

• 修改 CPython 源碼中 dict 內(nèi)置類型的實(shí)現(xiàn)，根據(jù)前面的追蹤方案給每個(gè) dict 對(duì)象加上實(shí)例化時(shí)的堆棧信息
• 后面了解到，CPython 3.4 新增了一個(gè) tracemalloc 模塊，雖然還未實(shí)踐過，但從其官方介紹來看也適用我們這次的場(chǎng)景

  • 該模塊能提供一個(gè)對(duì)象被創(chuàng)建時(shí)的堆棧信息

    • Traceback where an object was allocated
  • 逐文件、逐行統(tǒng)計(jì)已分配的內(nèi)存塊信息：總大小、數(shù)量、平均大小

    • Statistics on allocated memory blocks per filename and per line number: total size, number and average size of allocated memory blocks
  • 可以計(jì)算兩次內(nèi)存快照間的差異，甄別內(nèi)存泄漏

    • Compute the differences between two snapshots to detect memory leaks