1. 告警
最近所負(fù)責(zé)的服務(wù)略頻繁地收到4xx告警
2. 問題定位
1剧蚣、查業(yè)務(wù)日志崇渗，沒發(fā)現(xiàn)相關(guān)錯誤的日志
2、查nginx access log急前，發(fā)現(xiàn)返回的狀態(tài)碼都是499醒陆，從request_uri查了一遍發(fā)現(xiàn)不是集中在某一個請求上，說明應(yīng)該不是某個接口的問題了裆针，有可能進(jìn)程層面問題了刨摩。
通過對upstream_addr 分類，可以看到問題基本都是集中在 某一臺這臺機(jī)器上
3世吨、網(wǎng)上資料了解到澡刹，499 是 nginx 擴(kuò)展的 4xx 錯誤，代表客戶端請求還未返回時耘婚，客戶端主動斷開連接罢浇。原因有幾種，不過大部分原因都說到有可能服務(wù)器upstream處理過慢沐祷，導(dǎo)致用戶提前關(guān)閉連接嚷闭。那就先往這個方向排查，登錄機(jī)器查看實際的access.log
發(fā)現(xiàn)upstream response都是10s以上赖临。這就證明了上游服務(wù)器處理10秒還沒有響應(yīng)胞锰，因此nginx提前關(guān)閉鏈接，返回499
4兢榨、為什么進(jìn)程響應(yīng)如此慢嗅榕，10秒太不正常了〕炒希考慮到那段時間就只有一臺機(jī)器有問題誊册，而且是進(jìn)程層面的問題，首先想到的是GC暖璧，于是再次登錄到機(jī)器上查看gc log案怯。發(fā)現(xiàn)有Full GC，時間點和告警的時間也吻合澎办。 驚呆的是嘲碱，這次FullGC耗時長達(dá)19.07秒，由于我們的服務(wù)使用的是jdk8默認(rèn)的ParallelGC局蚀，F(xiàn)ullGC期間麦锯，整個應(yīng)用Stop The World的。這是非忱派穑恐怖的一件事
由此看來扶欣，4xx告警的初步原因已經(jīng)定位到，就是FullGC導(dǎo)致的。
3. FullGC原因排查
那么究竟為什么會發(fā)生FullGC呢料祠？需要深入分析一下骆捧。
借助服務(wù)治理平臺的JVM監(jiān)控觀察了幾天。期間不同機(jī)器不同時間也發(fā)生了幾次FullGC髓绽。從監(jiān)控發(fā)現(xiàn)敛苇，基本每臺機(jī)器隔兩天就會發(fā)生一次FullGC，每次FullGC后年老代回收的垃圾不算多顺呕，使用比例還是挺高的枫攀。
為什么年老代空間占用這么多？
繼續(xù)分析上面那條full gc log株茶，
1来涨、發(fā)生full gc時，年老代內(nèi)存已經(jīng)占用了99.98%了（1048397/1048576）启盛∩ㄒ梗看起來因為年老代滿了而觸發(fā)的FullGC了。
2驰徊、full gc回收了年老代大約302M的垃圾，回收后年老代占用70.4%（738282/1048576）堕阔。這占用率還是比較高的棍厂。
4. 年老代對象分析
1、首先jmap簡單打印一下所有對象的信息超陆。發(fā)現(xiàn)有ClassPathList和ClassClassPath兩個類的對象數(shù)量高達(dá)1000多萬牺弹，并且這兩個數(shù)量是一樣的。仿佛嗅到了內(nèi)存泄漏的味道时呀。
2张漂、只依靠對象統(tǒng)計信息，不足以定位問題谨娜，需要使用完整HeapDump航攒，通過MAT進(jìn)一步分析
jmap把完整堆heapDump下來
隔一段時間后，繼續(xù)jmap趴梢，這次只取存活對象的dump（實際效果是先執(zhí)行一次FULL GC）
可以看到漠畜，經(jīng)過Full GC后，ClassPathList對象沒有被回收坞靶，數(shù)量反而繼續(xù)增加。到這里，基本可以確定晴裹，ClassPathList是存在泄漏了田盈。
5. 年老代ClassPathList分析
那么，ClassPathList究竟被誰引用著，導(dǎo)致回收不掉呢簇抵？
通過MAT的OQL過濾出老生代的ClassPathList對象庆杜，從對象的關(guān)聯(lián)關(guān)系上繼續(xù)深入分析。
首先需要知道老生代的地址區(qū)間正压，可以使用vjtools
通過vjmap的address命令欣福，快速打印各代地址。
可以得知焦履，oldGen的下界是0x80000000拓劝，上界是0xc0000000（注意OQL中使用時要把數(shù)值前的那串0去掉）。
執(zhí)行OQL只查詢年老代中的ClassPathList對象：執(zhí)行OQL只查詢年老代中的ClassPathList對象：
抽取其中一個對象分析嘉裤，可以發(fā)現(xiàn)這個ClassPathList對象被一連串不同ClassPathList對象的next屬性引用著郑临。看起來是個鏈表的結(jié)構(gòu)
再看看GCRoot屑宠，發(fā)現(xiàn)是被AppClassLoader也就是我們的應(yīng)用類加載器引用著厢洞。除非這個加載器卸載了，否則ClassPathList對象是不會被GC掉了典奉。
6. 項目中哪里使用了ClassPathList躺翻？
分析到這里，似乎離真相越來越近了卫玖。到底這個ClassPathList在項目中哪里使用到了公你？
通過前面的分析知道了ClassPathList的整體引用關(guān)系鏈：
AppClassLoader -> ClassPool類的defaultPool字段 -> ClassPoolTail類的source字段 -> ClassPathList類的pathList
6.1 ClassPathList源碼
可以看到，ClassPathList有兩個屬性假瞬，一個是next陕靠，結(jié)合之前MAT的分析，ClassPathList的確就是一個鏈表的結(jié)構(gòu)脱茉。隨著時間的增長剪芥，ClassPathList不斷新增，鏈表也隨之變得越來越大琴许，最后內(nèi)存占用逐漸上升税肪。
另一個path字段屬于ClassPath類型，ClassPath是個接口榜田，查看它的實現(xiàn)類寸认，發(fā)現(xiàn)一個似曾相識的名稱ClassClassPath，之前分析對象統(tǒng)計信息時串慰，還有一個類的對象數(shù)量是和ClassPathList一樣的偏塞，正是這個ClassClassPath。每新增一個ClassPathList邦鲫，都會伴隨著新增對應(yīng)的ClassPath對象灸叼，這也解釋了為什么兩者數(shù)量是一致的了神汹。
6.2 ClassClassPath源碼
通過注釋知道，這個ClassClassPath的作用大概就是古今，利用一個叫ClassPool的對象屁魏，可以調(diào)用其insertClassPath方法來新增一個ClassClassPath對象，insertClassPath方法內(nèi)部通過頭插法將ClassClassPath添加到ClassPathList鏈表捉腥，從而形成一個search-path氓拼，然后通過這個search-path能夠獲取到某一個Class類的信息。
于是嘗試著搜了一下抵碟，看看項目中有沒有調(diào)用到insertClassPath方法的地方桃漾。意外發(fā)現(xiàn)一個類，
這不就是我們項目用來打印方法入?yún)⒛獯?zhí)行耗時撬统、上報metrics的@AutoLog的實現(xiàn)類嗎。
可以看到getParams方法中調(diào)用了insertClassPath敦迄，注解@AutoLog的printParams默認(rèn)為true恋追，也就是每次調(diào)用都需要打印方法入?yún)ⅲ看未蛴∏岸家{(diào)用getParams先獲取參數(shù)名稱罚屋。因此每次都會insertClassPath苦囱，從而導(dǎo)致ClassPathList鏈表越來越大。
至此脾猛，內(nèi)存泄漏的元兇已經(jīng)找到撕彤。解決方法也就簡單了。
因為目標(biāo)只是想得到方法的參數(shù)名稱尖滚，通過JoinPoint其實能直接獲取到，因此可以改成JoinPoint獲取的方式瞧柔。
7. 壓測
為了進(jìn)行對比漆弄，分別在修改前后各進(jìn)行一次壓測。壓測JVM參數(shù)大致與線上一致造锅，為了盡快看到效果撼唾，只是調(diào)小了heap的大小。-Xms200m -Xmx200m
7.1 修改前
ClassPathList數(shù)量不斷增長
年老代每次能回收的垃圾越來越少哥蔚，每次回收過后的剩余空間也越來越小倒谷。最終整個年老代被撐滿
雖然還沒觸發(fā)OOM，但是CPU負(fù)載飆高糙箍，從基本都在處于頻繁的FULLGC狀態(tài)
7.2 修改后
ClassPathList已經(jīng)被消滅掉了
FullGC也趨于規(guī)律化了渤愁。每次回收的垃圾大致都相同
8. 后記
- 很多時候只依靠簡單的對象統(tǒng)計信息，不足以定位問題深夯，需要使用完整HeapDump抖格，通過MAT進(jìn)一步分析诺苹。如果只需分析年老代對象，可以使用OQL過濾雹拄∈毡迹可用如下方式可獲得老生代地址：
第一種方式是在啟動參數(shù)增加 -XX:+PrintHeapAtGC，每次GC都打印地址
第二種方式是使用vjmap的命令滓玖，在-old, -sur, -address 中坪哄，都會打印出該區(qū)間的地址
第三種方式，使用vjmap的address命令势篡，快速打印各代地址翩肌，不會造成過長時間停頓。
詳情參考：https://github.com/vipshop/vjtools/blob/master/vjmap/README.md
- 親選服務(wù)使用JDK8殊霞， 默認(rèn)的GC收集算法摧阅；-XX:+UseParallelOldGC。使用Parallel Scavenge（年輕代）+Parallel Old（老年代）的組合進(jìn)行GC绷蹲。這是一套注重吞吐量的收集器棒卷。吞吐量=程序運(yùn)行時間/（程序運(yùn)行時間+GC時間）。假設(shè)運(yùn)行時間99秒祝钢、GC時間1秒比规。吞吐量=99%。但是對于有一定并發(fā)量的在線應(yīng)用來說拦英，GC時停頓1秒是挺大影響的蜒什。因此后續(xù)可根據(jù)情況調(diào)整使用CMS
附： 我們服務(wù)的JVM參數(shù)
-Xms2g -Xmx2g -XX:MetaspaceSize=256m -XX:MaxMetaspaceSize=256m -XX:NewRatio=1 -Xss512k -XX:SurvivorRatio=1
-XX:-UseAdaptiveSizePolicy -XX:+PrintPromotionFailure -XX:+PrintGCApplicationStoppedTime -Xloggc:/dev/shm/gc.log -XX:+UseGCLogFileRotation
-XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=1m -XX:+PrintTenuringDistribution
-XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/data/weblog/java/
-XX:ErrorFile=/data/weblog/java/hs_err_%p.log
-XX:-OmitStackTraceInFastThrow
