事情起因

某年某月的某一天，倒了一杯快樂的水。突然各個(gè)客戶群突然暴雷，說我們的接口很多超時(shí)，作為一個(gè)職業(yè)道德滿滿的新世紀(jì)好青年，我立馬查看了日志記錄。

啊這這這....商品校驗(yàn)信息的接口，這直接影響到了下單流程，說不好要被掛在城墻，暴曬三日的，于是開始了緊鑼密鼓的排查。

排查

1、根據(jù)時(shí)間和接口關(guān)鍵詞定位日志

此處使用的是阿里云的SLS日志服務(wù)。

通過日志發(fā)現(xiàn)，http status 為?499，這部分的原因很多可能是客戶端關(guān)閉了連接。于是同各個(gè)客戶的技術(shù)溝通得知，因?yàn)榭蛻羰窃O(shè)置了超時(shí)時(shí)間3s的限制，超過3s直接關(guān)閉請(qǐng)求，由此排除了業(yè)務(wù)上的代碼邏輯問題。

2、 快速解決生產(chǎn)，統(tǒng)計(jì)接口時(shí)間，放開限制

由于這些接口直接影響到了下單流程，因此最先想到的是，能否由客戶那邊對(duì)時(shí)間限制進(jìn)行放開，于是我統(tǒng)計(jì)了阿里云日志相關(guān)接口的最長(zhǎng)時(shí)間，期望客戶能對(duì)接口響應(yīng)給更寬容的時(shí)間。

對(duì)于我們提出的放開限制的要求，客戶最終確認(rèn)6s為他們的安全時(shí)間，因此，這對(duì)于我們多少還是起到了緩沖，讓我們有一定的時(shí)間，來正式定位問題。但是日常200ms返回的接口，現(xiàn)在被沖上了6秒多，這無論如何都是不能夠接受的，因此，進(jìn)入了定位分析問題中

3、跟蹤日志，正式定位原因

3.1、商品服務(wù)接口偶發(fā)性變慢

經(jīng)排查，服務(wù)流量過載，經(jīng)常將商品服務(wù)的服務(wù)器CPU飚到190%，于是增加服務(wù)器，將商品服務(wù)的流量均衡一下。

3.2 java服務(wù)的GC或CPU問題

在商品服務(wù)增開流量之后，發(fā)現(xiàn)超時(shí)的問題并沒有緩解，于是再次去到了調(diào)用鏈中查看。商品的響應(yīng)很快，基本上100ms以內(nèi)就可以返回，于是主觀的判斷了停頓是發(fā)生在對(duì)外交互的服務(wù)當(dāng)中（這一主觀的認(rèn)為，也對(duì)后面的排查造成了極大的誤導(dǎo)）

如圖所示，門戶網(wǎng)關(guān)最后拿到商品服務(wù)的結(jié)果是12:59:32，但是卻在12:59:38才把結(jié)果返回去，但 是通過review代碼，這里面并沒有其他操作，因此猜測(cè)是門戶網(wǎng)關(guān)卡住了，并沒有繼續(xù)，懷疑是 FULL GC的STW，導(dǎo)致恢復(fù)現(xiàn)場(chǎng)花費(fèi)較多時(shí)間。

3.3 查看GC Log

從這里我們看出兩個(gè)問題：

?FullGC的很頻繁 ?核對(duì)了發(fā)生時(shí)間和超時(shí)時(shí)間較為吻合

因此，運(yùn)維把服務(wù)由原先的4核8G升級(jí)為8核16G，觀察發(fā)現(xiàn)還是出現(xiàn)了超時(shí)，并且是 發(fā)生在沒有fullgc的情況下。由此排除了是網(wǎng)關(guān)服務(wù)的GC問題造成的接口卡頓。

4、 接口測(cè)試

使用jmeter對(duì)接口進(jìn)行測(cè)試復(fù)現(xiàn)。

4.1、 域名請(qǐng)求門戶網(wǎng)關(guān)測(cè)試

由于網(wǎng)關(guān)服務(wù)提供了一個(gè)無業(yè)務(wù)邏輯的health接口，用來健康檢測(cè)，本次通過域名來循環(huán)調(diào)用這個(gè)接口來測(cè)試問題

通過調(diào)用接口發(fā)現(xiàn)，接口呈現(xiàn)有規(guī)律的卡頓，非常非常非常規(guī)律的2分鐘超時(shí)一次，這時(shí)候 仿佛發(fā)現(xiàn)了新大陸。此時(shí)的方向有幾個(gè):

1.惡意流量(日志中可以排除)

期間沒有大批的流量涌入

2. 門戶網(wǎng)關(guān)服務(wù)有類似2min的定時(shí)，可以再代碼中排除3. 2min的時(shí)間剛好是之前GC的時(shí)間，但是在新增資源之后排除4. 網(wǎng)絡(luò)問題，但實(shí)際排查下來，網(wǎng)絡(luò)沒有大范圍的波動(dòng)

4.2、調(diào)用其他服務(wù)接口測(cè)試

發(fā)現(xiàn)各個(gè)服務(wù)的接口都呈現(xiàn)類似的規(guī)律，因此猜測(cè)是基礎(chǔ)組件的一些問題，于是采用ip+port的方式來同樣的測(cè)試。

4.3、 ip+port調(diào)用門戶網(wǎng)關(guān)

看到雖然，服務(wù)的請(qǐng)求時(shí)間偶有上升，但整體水平保持在500ms以下，絕大部分200ms以內(nèi)返回了，因此推測(cè)有可能是ng出現(xiàn)了問題。

4.4、ip+port調(diào)用ng

果不其然，出現(xiàn)了相同的規(guī)律。

5、ng的阻塞

從上面大致定位到了是ng的問題，于是開始排查ng的定時(shí)任務(wù)，這里處理請(qǐng)求使用的是阻塞函數(shù)，因此阻塞住了ng的主線程。至此整個(gè)問題定位到了。其實(shí)，在生產(chǎn)中，我們會(huì)遇到各種各樣的問題，有著很多的干擾因素，但是只要我們能夠有著清晰的思路，問題都有跡可循.