面試題必問: 遇到過線上問題沒,你是怎么排查的?
不知道你們經(jīng)歷過這種問題沒有,比如問你遇到過線上性能問題沒有,GC頻繁,CPU飆高,任務(wù)隊(duì)列積壓,線程池任務(wù)拒絕等等,對(duì)于看重項(xiàng)目經(jīng)驗(yàn)的面試官,這種問題基本是標(biāo)配,問線上問題處理的經(jīng)過,問題定位,排查的思路,怎么做的業(yè)務(wù)快速止血。一方面考察候選人項(xiàng)目的真實(shí)性,一般遇到線上問題大部分時(shí)候是系統(tǒng)主要負(fù)責(zé)人著手處理的,所以如果你處理過線上問題,也從側(cè)面反映你的重要性。另外還能知道面試者是不是真的從原理上掌握了問題的根本原因,對(duì)技術(shù)的熱忱等。另外建議大家處理完線上問題,排查了原因之后不要停,把排查過程和問題原因記錄下來,一方面以后遇到類似問題可以基于已有的經(jīng)驗(yàn)快速反應(yīng),另外就是一定讓自己的知識(shí)體系化,怎么體系化呢? 就需要把日常的技術(shù)問題做歸類總結(jié)。
這篇文章主要是給大家一個(gè)參考,講講安琪拉在上家公司遇到的線上問題以及排查思路,你們可能會(huì)好奇為什么不講在阿里遇到的線上問題,這個(gè)我也會(huì)講,但是因?yàn)楹芏鄶?shù)據(jù)要脫敏(馬賽克),所以暫時(shí)先講之前的,這篇是很早之前寫的了,發(fā)布在博客園上。
鋪墊太長(zhǎng)了,下面進(jìn)入正題。
問題
一個(gè)在普通不過的周末,安琪拉在家里玩安琪拉,蹲在草叢正準(zhǔn)備給妲己一頓暴擊,手機(jī)突然收到線上告警短信,嚇得我一激靈,二技能放空,被妲己一套帶走,趁著復(fù)活間隙,趕緊從床上爬起來打開電腦。
起因: 消息隊(duì)列積壓了十幾萬(wàn)消息,第一反應(yīng),什么情況。。

趕緊穿衣服,對(duì)待線上問題要嚴(yán)肅。
如下圖,“待處…” 那一列就是指隊(duì)列中“待處理的”消息。
消息積壓,指的是消息的消費(fèi)速度跟不上生產(chǎn)的速度,消息在消息隊(duì)列中。

可以看到有好幾個(gè)分區(qū)已經(jīng)積壓了上萬(wàn)條消息;
問題排查
立即開始問題排查,遇到線上問題,一定是保證最快速度止血,降低對(duì)業(yè)務(wù)的影響,然后再是排查原因,當(dāng)然有的問題也需要快速找到原因。
第一反應(yīng)是不是入口流量太大,處理消息的線程池核心線程數(shù)滿了,任務(wù)都在排隊(duì),但是看了入口流量并沒有尖刺。
看監(jiān)控的消息消費(fèi)任務(wù)耗時(shí),如下圖:

可以看到耗時(shí)在不斷增加。那就需要看處理耗時(shí)增加原因了,為什么處理任務(wù)的耗時(shí)上漲了。
查看消息消費(fèi)日志,如下:

發(fā)現(xiàn)有很多網(wǎng)絡(luò)接口超時(shí)的。

大致得出結(jié)論:消息處理任務(wù)依賴下游系統(tǒng)接口,連接下游接口超時(shí),連接下游接口設(shè)置的超時(shí)時(shí)間不算短,為什么下游接口如此多SocketTimeOut呢?

下游系統(tǒng)也是我負(fù)責(zé)的系統(tǒng),那重點(diǎn)開始看下游的系統(tǒng)監(jiān)控,發(fā)現(xiàn)相關(guān)的接口調(diào)用的單機(jī)耗時(shí)時(shí)間極不規(guī)律,如下圖所示:

對(duì)比一下日常這個(gè)接口的耗時(shí)時(shí)間,如下圖,日常都沒有超過100ms的:

查看下游系統(tǒng)的監(jiān)控大盤,發(fā)現(xiàn)了問題:

老年代GC次數(shù)暴漲,而且gc耗時(shí)都到了秒級(jí)別,1分鐘5~10秒,太恐怖了。
分析GC問題
找一臺(tái)機(jī)器,把GC回收dump下來分析,使用mat查看,如下圖所示:

一共七百多M空間,一個(gè)對(duì)象就占了640M空間,找到原因了,有內(nèi)鬼(大對(duì)象)。

繼續(xù)往下,看這個(gè)對(duì)象為什么會(huì)這么大,從GC Roots最短路徑如下,MAT的使用,以及JVM相關(guān)分析,感興趣可以微信公眾號(hào)【安琪拉的博客】回復(fù)JVM,拉你進(jìn)JVM交流群。

解釋下,上面主要有三列,第一列是內(nèi)存對(duì)象的類,重點(diǎn)在2,3列,Shallow Heap指的是對(duì)象本身占據(jù)的內(nèi)存大小, Retained Heap = 本身本身占據(jù)內(nèi)存大小 + 當(dāng)前對(duì)象可直接或間接引用到的對(duì)象的大小總和,換句話說,就是當(dāng)前對(duì)象如果被回收,能夠回收的內(nèi)存大小。
繼續(xù)看,第一步,查看誰(shuí)引用了這個(gè)對(duì)象,找到自己代碼中的類,

第二步,查看這個(gè)對(duì)象TaggedMetricRegistry都引用了誰(shuí),為什么會(huì)占用這么大的內(nèi)存空間,如下圖所示,

找到罪魁禍?zhǔn)琢?,metrics這個(gè) ConcurrentHashMap 占了671M內(nèi)存,現(xiàn)在開始可以看下代碼,找到 TaggedMetricRegistry繼承自MetricRegistry,metrics 是MetricRegistry的成員變量,如下圖:


那為什么這個(gè) ConcurrentHashMap 占了這么大的內(nèi)存空間,并且GC也回收不掉呢?
我們繼續(xù)看MAT,分析 ConcurrentHashMap 占有的詳細(xì)內(nèi)存分布:

發(fā)現(xiàn)ConcurrentHashMap有幾個(gè)Node節(jié)點(diǎn)尤其大,
追下去,繼續(xù)

看到這個(gè)key,對(duì)應(yīng)在代碼中的位置,

你們可能好奇這段代碼是干嘛的呢?
這個(gè)代碼的作用是統(tǒng)計(jì)接口每次的執(zhí)行時(shí)間,它內(nèi)部update的源碼如下:

這個(gè)方法是統(tǒng)計(jì)接口的耗時(shí)、調(diào)用次數(shù)的,它內(nèi)部有一個(gè)measurements 的跳躍表,存放時(shí)間戳和統(tǒng)計(jì)指標(biāo)(耗時(shí)、調(diào)用次數(shù))的鍵值對(duì),設(shè)置的時(shí)間窗口是1分鐘,也就是它會(huì)存放1分鐘的統(tǒng)計(jì)數(shù)據(jù)在內(nèi)存中,當(dāng)然這里面有個(gè)采樣比,不是1分鐘的全量數(shù)據(jù),可以看到采樣比是COLLISION_BUFFER決定的,然后1分鐘上報(bào)一次內(nèi)存數(shù)據(jù)到遠(yuǎn)端。問題就出現(xiàn)在這,因?yàn)檫@個(gè)耗時(shí)統(tǒng)計(jì)的函數(shù)的QPS非常高,1分鐘有數(shù)據(jù)頻繁產(chǎn)生的時(shí)候,會(huì)導(dǎo)致在一個(gè)時(shí)間窗口(1分鐘)measurements極速增長(zhǎng),導(dǎo)致內(nèi)存占用快速增長(zhǎng),但是因?yàn)橛袕?qiáng)引用,GC的時(shí)候也不會(huì)把這個(gè)回收掉,所有才出現(xiàn)了上面的那個(gè)情況。
2. 談?wù)務(wù)齽t表達(dá)式的性能優(yōu)化問題
最近面試BAT,整理一份面試資料《Java面試BATJ通關(guān)手冊(cè)》,覆蓋了Java核心技術(shù)、JVM、Java并發(fā)、SSM、微服務(wù)、數(shù)據(jù)庫(kù)、數(shù)據(jù)結(jié)構(gòu)等等。
獲取方式:點(diǎn)“在看”,關(guān)注公眾號(hào)并回復(fù) Java 領(lǐng)取,更多內(nèi)容陸續(xù)奉上。
文章有幫助的話,在看,轉(zhuǎn)發(fā)吧。
謝謝支持喲 (*^__^*)

