問(wèn)題背景

服務(wù)介紹

首先簡(jiǎn)單介紹下異常服務(wù)的背景逼纸。服務(wù)的背景可以概括為是一個(gè)消息隊(duì)列的消費(fèi)端服務(wù)刷袍，訂閱上游消息隊(duì)列的信息后，在本服務(wù)中對(duì)信息進(jìn)行加工最后入庫(kù)樊展，如下圖虛線中的部分呻纹。

服務(wù)背景

服務(wù)整體是 分布式 部署的堆生，有若干個(gè)分布式部署的實(shí)例，如圖共三個(gè)雷酪。每個(gè)實(shí)例負(fù)責(zé)承包消費(fèi)一部分 partition淑仆，對(duì)于每個(gè)partition都啟動(dòng)一個(gè)receive線程 + 3個(gè)process線程用來(lái)對(duì)消息隊(duì)列中的數(shù)據(jù)進(jìn)行 接收 + 轉(zhuǎn)換，最終以業(yè)務(wù)上需要的格式入庫(kù)哥力。服務(wù)中每個(gè)partition消費(fèi)的細(xì)節(jié)如下：

1. receive線程接收kafka訂閱到的消息蔗怠，并且將其存入本地消息隊(duì)列msgQueue（一個(gè)LinkedBlockingQueue），receive線程的偽代碼如下吩跋。

while(running):
    Msg msg = kakfa.receive()
    msgQueue.offer(msg)

2. 每個(gè)msgQueue啟動(dòng)3個(gè)process線程處理消費(fèi)寞射，然后將結(jié)果存入另一個(gè)bizQueue（也是一個(gè)JDK內(nèi)部的LinkedBlockingQueue），processor的流程也很簡(jiǎn)單锌钮，如下桥温。

while(running):
    Msg rawMsg = msgQueue.poll();
    ProcessedMsg processed = process(rawMsg); # 經(jīng)過(guò)各種轉(zhuǎn)化與加工，處理成業(yè)務(wù)需要的格式
    bizQueue.offer(processed);

3. 定時(shí)任務(wù)30ms執(zhí)行一次梁丘，負(fù)責(zé)將bizQueue中的消息取出并且入庫(kù)侵浸。

問(wèn)題

關(guān)于服務(wù)的背景中，讀者可能會(huì)有以下幾個(gè)問(wèn)題氛谜。

1. 為什么要用kakfa這樣的消息隊(duì)列掏觉？
   是基于業(yè)務(wù)的背景，kafka隊(duì)列中數(shù)據(jù)的消費(fèi)方并不是只有本文中的服務(wù)這一種值漫，還有很多其它的服務(wù)也在用著同樣的消息澳腹，進(jìn)行著其它的消息處理工作。這也正是利用到了消息隊(duì)列的 解耦[^1] 的特性杨何。同時(shí)酱塔，這也是為什么本服務(wù)中要在第2步進(jìn)行消息的 轉(zhuǎn)化與加工，因?yàn)橄⒌南M(fèi)方有多個(gè)晚吞，不同消費(fèi)方關(guān)注的內(nèi)容不同，本服務(wù)中需要對(duì)隊(duì)列中的消息進(jìn)行提取與加工谋国，只提取業(yè)務(wù)上關(guān)系的部分槽地。

2. 為什么服務(wù)內(nèi)部處理的時(shí)候要用內(nèi)存消息隊(duì)列？
   可以看到服務(wù)中共使用了兩個(gè)內(nèi)部的消費(fèi)隊(duì)列（msgQueue與bizQueue）芦瘾，這兩個(gè)消息隊(duì)列存在意義是解決 處理速度不匹配 的問(wèn)題捌蚊，從kafka拉取消息很快，但是消息加工可能會(huì)較慢近弟，因此需要msgQueue來(lái)緩沖消息缅糟；同理，消息的加工可能較慢祷愉，但是入庫(kù)的操作非常慢窗宦，這時(shí)也需要bizQueue來(lái)緩沖消費(fèi)赦颇。

3. 3個(gè)processor處理的時(shí)候，是否會(huì)有消息順序性的問(wèn)題赴涵？
   分布式隊(duì)列中一個(gè)很重要的問(wèn)題就是 消息順序消費(fèi)問(wèn)題[^1]（例如轉(zhuǎn)賬通知短信一定要在轉(zhuǎn)賬完成后再發(fā)送）媒怯，而其中解決局部消息有序的方式就是確保一個(gè)partition中的消息都是被順序消費(fèi)處理的。但是本文中在處理消息時(shí)使用了3個(gè)processor并行處理髓窜，操作系統(tǒng)四大特性中的 異步性[^2] 顯然無(wú)法保證消費(fèi)的順序執(zhí)行扇苞，但是本文中的業(yè)務(wù)對(duì)消息的順序性并不敏感，因此可以這樣使用寄纵。對(duì)于消息順序性敏感的場(chǎng)景需要注意鳖敷。

問(wèn)題現(xiàn)象 & 排查步驟

問(wèn)題現(xiàn)象

書(shū)歸正文腿短，本次OOM問(wèn)題的現(xiàn)象為渊抽，在服務(wù)重啟運(yùn)行一段時(shí)間后會(huì)因?yàn)?code>OutOfMemoryError導(dǎo)致服務(wù)斷流（即停止消費(fèi)），即出現(xiàn)了 內(nèi)存溢出 的現(xiàn)象橱夭，疑似存在 內(nèi)存泄漏 的可能哺壶。

內(nèi)存溢出與內(nèi)存泄漏屋吨，內(nèi)存溢出是結(jié)果OutOfMemoryError，內(nèi)存泄漏是可能導(dǎo)致內(nèi)存溢出的原因山宾，可能因?yàn)槟承┍驹摶厥盏膶?duì)象因?yàn)榇a問(wèn)題等某些原因無(wú)法被GC回收至扰，這種不該存留的對(duì)象越來(lái)越多，最終堵滿(mǎn)內(nèi)存（就像浴室下水的頭發(fā)）资锰。
但是并不是所有OOM問(wèn)題都是因?yàn)閮?nèi)存泄漏敢课，有可能就是內(nèi)存不夠，例如本文的問(wèn)題最終定位為性能不足的問(wèn)題绷杜。

排查步驟

dump內(nèi)存

最開(kāi)始的時(shí)候當(dāng)然是優(yōu)先采用八字真言：“多喝熱水直秆，重啟試試”。

多喝熱水鞭盟，重啟試試

多喝熱水圾结，重啟試試

在反復(fù)重啟又反復(fù)出現(xiàn)OOM問(wèn)題后，我們發(fā)現(xiàn)問(wèn)題并不簡(jiǎn)單齿诉，看來(lái)需要認(rèn)真排查一下服務(wù)的問(wèn)題筝野。

眉頭一皺 問(wèn)題并不簡(jiǎn)單

第一步，調(diào)整JVM啟動(dòng)參數(shù)在OOM發(fā)生時(shí)自動(dòng)dump

正常運(yùn)行的服務(wù)的內(nèi)存是無(wú)法看出有任何異常情況的粤剧，而當(dāng)服務(wù)已經(jīng)OOM之后歇竟，如果沒(méi)有try-catch這種情況的話(huà)，一般線程就會(huì)崩潰停止任務(wù)的執(zhí)行抵恋，相當(dāng)于Java直接掀了桌子焕议，這之后的內(nèi)存信息也沒(méi)有了任何參考價(jià)值，只有當(dāng)正在發(fā)生OOM那一刻的內(nèi)存才是最有分析意義的弧关。
于是我們調(diào)整了JVM的啟動(dòng)參數(shù)盅安，增加了-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/server/dump.hprof唤锉，參數(shù)的含義是讓JVM在發(fā)生OOM時(shí)自動(dòng)生成jstack的dump文件到指定目錄下。

第二步宽堆，linux的MAT分析工具

修改好參數(shù)后腌紧，重啟服務(wù)，果然不久問(wèn)題就復(fù)現(xiàn)了畜隶，并且成功產(chǎn)出了一份dump.hprof文件壁肋，接下來(lái)需要進(jìn)行文件分析，需要用到ecplise的MAT工具籽慢，我們平常使用的都是windows版的MAT浸遗，有著完善的操作功能，但是線上服務(wù)的內(nèi)存dump文件有8G箱亿，而線上生產(chǎn)環(huán)境往往使用的linux的操作系統(tǒng)跛锌，因此就需要我們將這份文件傳到windows機(jī)器上，傳輸?shù)倪^(guò)程會(huì)浪費(fèi)太多寶貴的排查時(shí)間届惋。因此筆者選擇直接在linux上執(zhí)行MAT分析內(nèi)存髓帽。

在網(wǎng)上搜索 linux MAT 后，發(fā)現(xiàn)都是互相copy-paste的一份博客脑豹，可以通過(guò)上官網(wǎng)下載linux版的MAT郑藏，然后執(zhí)行./ParseHeapDump.sh生成幾MB的zip打包的內(nèi)存分析結(jié)果html網(wǎng)頁(yè)文件（linux MAT的使用方法網(wǎng)上千篇一律復(fù)制了同一份博客，本文不再贅述）瘩欺，然后下載zip文件必盖，打開(kāi)其中的index.html網(wǎng)頁(yè)后，可以粗略的看到內(nèi)存的占用概況俱饿。

dump_Leak_Suspects

通過(guò)分析其中的Class Histogram歌粥、Top Consumers和dump_Leak_Suspects，已經(jīng)基本可以確定拍埠，就是服務(wù)中這些LinkedBlockingQueue中保存了過(guò)多的數(shù)據(jù)（每個(gè)Queue高達(dá)300M）失驶，從而導(dǎo)致了OOM問(wèn)題的發(fā)生。那么問(wèn)題來(lái)了枣购，通過(guò)上文中背景的描述我們知道嬉探，服務(wù)中分別有兩處使用了LinkedBlockingQueue，到底是哪一個(gè)呢坷虑？通過(guò)linux MAT生成的概覽我無(wú)法獲取到更加詳細(xì)的信息甲馋，網(wǎng)上的搜索結(jié)果也是千篇一律的復(fù)制同一份博客埂奈，根本沒(méi)有提到這個(gè)問(wèn)題迄损。

Class Histogram

Top Consumers

第三步，果然還是需要用windows MAT账磺，將dump文件從linux傳入windows

基于linux dump出的結(jié)果芹敌，我們已經(jīng)將犯罪嫌疑人鎖定在了msgQueue和bizQueue這兩個(gè)隊(duì)列上痊远，但是目前l(fā)inux生成的dump文件無(wú)法支持筆者進(jìn)一步的分析。于是筆者又回到了第二步一開(kāi)始的問(wèn)題氏捞，如何將8G的linux文件傳輸?shù)阶约旱膚indows機(jī)器上碧聪？

經(jīng)過(guò)一系列搜索后，筆者總結(jié)出如下幾種辦法：

1. 用sz功能液茎，但是windows的sz功能有文件大小限制逞姿，如果直接使用sz會(huì)收到這樣的彈窗提示
   

   不支持sz 4G以上的文件
   
   經(jīng)過(guò)筆者的一輪搜索后，發(fā)現(xiàn)解決的辦法只能是通過(guò)cat dump.hprof | split -b 2G - dump.hprof命令將文件切割開(kāi)捆等，挨個(gè)sz過(guò)來(lái)后滞造，在windows上執(zhí)行cmd命令copy /B dump.hprof.a + dump.hprof.b + dump.hprof.c dump.hprof合并到一起

2. 通過(guò)python -m SimpleHTTPServer，前提是linux機(jī)器上有python環(huán)境栋烤，這樣的話(huà)會(huì)啟動(dòng)一個(gè)小型的http服務(wù)器谒养，然后在windows的地址欄輸入linuxhost:8000，下載dump文件

筆者采用了后者明郭。

第四步买窟，MAT內(nèi)存分析過(guò)程與結(jié)論

綜上，我們知道了問(wèn)題出在LinkedBlockingQueue薯定，也下載到了dump文件始绍，通過(guò)windows的MAT工具打開(kāi)分析dump文件后，我們可以進(jìn)一步確認(rèn)到底是哪個(gè)queue堆滿(mǎn)了沉唠。
通過(guò)dominator tree疆虚，我們看到了占用百分比最高的幾個(gè)LinkedBlockingQueue。

dominator tree

通過(guò)查看這些LinkedBlockingQueue的incoming references满葛，我們定位到原來(lái)是msgQueue径簿。

incoming references

通過(guò)對(duì)上面的背景分析可知，如果是bizQueue堆積嘀韧，很有可能是步驟3阻塞篇亭，導(dǎo)致bizQueue產(chǎn)生的消息遲遲沒(méi)有消費(fèi)。現(xiàn)在既然是msgQueue的堆積锄贷，那么最有可能的是三個(gè)processor處理的過(guò)程中阻塞译蒂。這時(shí)候又用到了內(nèi)存dump的thread_overview（線程棧dump）功能，processor線程在啟動(dòng)的時(shí)候有特殊的命名谊却，通過(guò)線程名搜索到并觀察了每個(gè)線程的執(zhí)行狀態(tài)后柔昼，筆者發(fā)現(xiàn)，processor線程并沒(méi)有阻塞的嫌疑炎辨。

thread_overview

那么綜上排查到現(xiàn)在為止捕透，所有的可能性都排除之后，只有一個(gè)可能性，即 不是消費(fèi)的太慢了乙嘀，而是生產(chǎn)的太快了末购，通過(guò)對(duì)代碼歷史注釋的理解和內(nèi)存棧的分析，筆者發(fā)現(xiàn)虎谢，當(dāng)前從kafka中獲取的每個(gè)消息包中共有100個(gè)消息盟榴，而歷史注釋中表示每個(gè)消息包中一般40條消息，也就是說(shuō)kafka上游最近調(diào)大了每個(gè)包的消息數(shù)量婴噩，從而導(dǎo)致同樣輪詢(xún)速度的receiver同時(shí)間寫(xiě)入msgQueue的消息量變大了擎场，下游消費(fèi)不及時(shí)，導(dǎo)致了OOM几莽。

通過(guò)對(duì)服務(wù)的實(shí)例進(jìn)行擴(kuò)容操作（擴(kuò)容100/40=2.5倍）顶籽，再觀察了一段時(shí)間后，OOM問(wèn)題成功得到解決银觅。

MAT的幾個(gè)術(shù)語(yǔ)解釋

1. incoming references 和 outcoming references

public class Foo {
    private LinkedBlockingQueue msgQueue;
}

對(duì)于上面的Foo類(lèi)的對(duì)象來(lái)說(shuō)礼饱，指向關(guān)系是 Foo --> msgQueue，因此對(duì)于Foo的視角來(lái)說(shuō)究驴，out refercences是msgQueue镊绪，對(duì)于msgQueue來(lái)說(shuō)，in references是Foo

2. shallow heap 與 retained heap
   同樣以上面的Foo類(lèi)為例洒忧，對(duì)Foo類(lèi)產(chǎn)生的對(duì)象foo來(lái)說(shuō)蝴韭，其實(shí)foo本身就只是 一個(gè)對(duì)象頭+一大堆相關(guān)參數(shù)+一個(gè)執(zhí)行msgQueue的指針（64bit） 的數(shù)據(jù)而已，這個(gè)就是shallow heap熙侍。但是如果能夠?qū)oo回收掉榄鉴，那么msgQueue也能 級(jí)聯(lián) 回收掉，那么將回收掉Foo+msgQueue的全部?jī)?nèi)存蛉抓，這就是retained heap庆尘。
   舉例子就好像一個(gè)人身上可能只有幾塊錢(qián)，這是shallow錢(qián)巷送，但是他的手機(jī)驶忌、銀行卡、名下的資產(chǎn)等等由他的身份指向的資產(chǎn)可能有幾個(gè)億笑跛，這就是retained錢(qián)付魔。

結(jié)論與反思

雖然最后的結(jié)論很簡(jiǎn)單，對(duì)實(shí)例進(jìn)行了橫向擴(kuò)容就可以解決飞蹂，但是排查的過(guò)程與經(jīng)驗(yàn)是寶貴的几苍。同時(shí)，我們要反思陈哑，為什么會(huì)出現(xiàn)這樣的情況妻坝。通過(guò)代碼可以看到妖胀，msgQueue的capacity容量是固定限制為3000的。

OQL

msgQueue的capacity

但是從內(nèi)存dump文件的分析來(lái)看惠勒，僅僅使用了285個(gè)就導(dǎo)致內(nèi)存OOM了，就算是LinkedBlockingQueue中的包的大小被擴(kuò)充了2.5倍爬坑，之前的方式285*2.5=712.5個(gè)元素的時(shí)候仍然能撐爆內(nèi)存

msgQueue的capacity

本身如果msgQueue的capacity大小限制合理的話(huà)纠屋，會(huì)在達(dá)到容量上限的時(shí)候阻塞receiver的接收操作，等待下游的消費(fèi)盾计，即使消費(fèi)速度變慢售担，但是也還是能夠使得流式系統(tǒng)正常運(yùn)行的。因此署辉，本次case的根本原因在于LinkedBlockingQueue容量capacity設(shè)置的不合理導(dǎo)致族铆。

references

1. ^ 《分布式消息中間件實(shí)踐》
2. ^ 《深入理解計(jì)算機(jī)系統(tǒng)》