背景介紹

某日下午大約四點多，接到合作方消息，線上環(huán)境，我這邊維護的某http服務(wù)突然大量超時（對方超時時間設(shè)置為300ms），我迅速到鷹眼平臺開啟采樣，發(fā)現(xiàn)該服務(wù)平均QPS到了120左右，平均RT在2秒多到3秒，部分毛刺高達5到6秒（正常時候在60ms左右）。

qps情況：

rt情況

問題解決

該服務(wù)是一個對內(nèi)的運營平臺服務(wù)（只部署了兩臺docker）預(yù)期qps個位數(shù)，近期沒做過任何的線上發(fā)布，核心操作是整合查詢數(shù)據(jù)庫，一次請求最多涉及40次左右的DB查詢，最終查詢結(jié)果為一個多層樹形結(jié)構(gòu)，一個響應(yīng)體大約50K。之前口頭跟調(diào)用方約定要做緩存，現(xiàn)在看到QPS在120左右，（QPS證明沒有做緩存），遂要求對方做緩存，降低QPS。后QPS降到80以內(nèi)，rt恢復(fù)正常（平均60ms），最終QPS一直降到40（后續(xù)需要推動調(diào)用方上緩存，保證QPS在個位數(shù)）。

問題定位

由于該服務(wù)核心操作是查詢數(shù)據(jù)庫，且一次請求有40次DB query，遂首先排查是否慢sql導(dǎo)致，查看db性能監(jiān)控，發(fā)現(xiàn)db 平均rt在0.3ms以內(nèi)，可以算出來DB整體耗時在12ms左右，排除慢sql導(dǎo)致RT變高。

開始懷疑，是否DB連接池在高并發(fā)下出現(xiàn)排隊，tddl默認的連接池大小是10.一查監(jiān)控，整個占用的連接數(shù)從來沒有超過7個，排除連接池不足的問題。

至此，造成RT高的原因，在數(shù)據(jù)庫層面被排除。

接著開始查采樣到的服務(wù)調(diào)用鏈上的每一個執(zhí)行點，看看到底是調(diào)用鏈上的那部分耗時最多。發(fā)現(xiàn)里面很多執(zhí)行點都有一個特點，就是本地調(diào)用耗時特別長（幾百毫秒），但是真正的服務(wù)調(diào)用（比如db查詢動作）時間卻很短，(0ms代表執(zhí)行時間小于1ms，也間接印證之前db的平均RT在0.3ms以內(nèi))

本地調(diào)用耗時: 267ms

客戶端發(fā)送請求: 0ms

服務(wù)端處理請求: 0ms

客戶端收到響應(yīng): 1ms

總耗時: 1ms

這時候問題逐漸清晰，問題出現(xiàn)在本地方法執(zhí)行的耗時過長，可是再次檢查該服務(wù)所有代碼，并沒有需要長耗時的本地執(zhí)行邏輯，那么繼續(xù)看CPU的load情況。

load長時間在4左右徘徊，我們的docker部署在4c8G的宿主機上，但是我們不能獨占這個4C的，持續(xù)這么高的load已經(jīng)不正常了。

繼續(xù)追查cpu load飆高的原因，接著去看GC日志，發(fā)現(xiàn)大量的Allocation Failure，然后ParNew次數(shù)在每分鐘100次以上，明顯異常，見下GC日志例子

2020-03-25T16:16:18.390+0800:1294233.934: [GC (Allocation Failure)2020-03-25T16:16:18.391+0800:1294233.935: [ParNew:1770060K->25950K(1922432K),0.0317141secs]2105763K->361653K(4019584K),0.0323010secs] [Times: user=0.12sys=0.00, real=0.04secs]

每次占用cpu的時間在0.04s左右，但是由于ParNew GC太過頻繁，每分鐘最高100次以上，整體占用cpu時間還是很可觀。

看了下jvm內(nèi)存參數(shù)

年輕代分配了2G內(nèi)存，其中eden區(qū)約1.7G

使用jmap查看年輕代對象占用空間情況,排名靠前的有多個org.apache.tomcat.util.buf包下的對象，比如ByteChunk、CharChunk、MessageBytes等，以及響應(yīng)涉及的一些臨時對象列表。其中ByteChunk等即tomcat響應(yīng)輸出相關(guān)類

至此問題明確，超大響應(yīng)包（50K）在發(fā)送到網(wǎng)卡的過程中，需要經(jīng)過從用戶態(tài)user space拷貝到內(nèi)核態(tài) kernel space，然后在拷貝到網(wǎng)卡進行發(fā)送（像netty等的零拷貝針對的就是這種拷貝），加上響應(yīng)體查詢過程中，涉及的大量臨時對象list，在高并發(fā)場景下，就導(dǎo)致年輕代內(nèi)存占滿，然后頻繁gc（后續(xù)在合適的時間會壓測該接口），這里還有一個點，很多人以為ParNewGC不會stop the world，其實是會的。頻繁ParNewGC造成用戶線程進入阻塞狀態(tài)，讓出CPU時間片，最終導(dǎo)致連接處理等待，接口的RT變高。整個排查過程，鷹眼，idb性能監(jiān)控等可視化監(jiān)控平臺幫助真的很大，否則到處去查日志得查的暈頭轉(zhuǎn)向了。

經(jīng)驗總結(jié)
接口設(shè)計，需要避免超大響應(yīng)體出現(xiàn)，分而治之，將一個大接口拆分為多個小接口。

緩存設(shè)計，像這個服務(wù)一樣，一個請求帶來將近40次DB查詢的，需要考慮在服務(wù)端進行緩存（當時偷懶了，要求調(diào)用方去做緩存）。

性能設(shè)計，要對自己負責(zé)系統(tǒng)的性能了如指掌，可以通過壓測等手段得到自己系統(tǒng)的天花板，否則，某一個接口hang住，會導(dǎo)致整個應(yīng)用的可用性出現(xiàn)問題。

流量隔離，內(nèi)部應(yīng)用和外部流量之間，需要進行流量隔離，即使通過緩存，也有緩存擊穿的問題。

口頭說的東西都不靠譜，要落在文檔上，還需要檢查執(zhí)行情況。文章來源地址http://www.zghlxwxcb.cn/news/detail-647834.html

到了這里，關(guān)于年輕代頻繁GC ParNew導(dǎo)致http變慢的文章就介紹完了。如果您還想了解更多內(nèi)容，請在右上角搜索TOY模板網(wǎng)以前的文章或繼續(xù)瀏覽下面的相關(guān)文章，希望大家以后多多支持TOY模板網(wǎng)！