背景

我們的業(yè)務(wù)共使用 11 臺（阿里云）服務(wù)器，使用 SpringcloudAlibaba 構(gòu)建微服務(wù)集群, 共計 60 個微服務(wù), 全部注冊在同一個 Nacos 集群。

流量轉(zhuǎn)發(fā)路徑：nginx -> spring-gateway -> 業(yè)務(wù)微服務(wù)。

使用的版本如下：

spring-boot.version：2.2.5.RELEASE

spring-cloud.version：Hoxton.SR3

spring-cloud-alibaba.version：2.2.1.RELEASE

java.version：1.8

案發(fā)

春節(jié)放假期間收到反饋，網(wǎng)頁報錯服務(wù)未找到（gateway 找不到服務(wù)的報錯提示）。查看 nacos 集群列表，發(fā)現(xiàn)個別服務(wù)丟失 （下線）。

這個問題每幾天出現(xiàn)一次, 出現(xiàn)時間不固定, 每次掉線的服務(wù)像是隨機(jī)選的幾個。服務(wù)手動 kill+restart 后能穩(wěn)定運(yùn)行 2-3 天。

排查和解決

懷疑對象一：服務(wù)器內(nèi)存爆了

進(jìn)阿里云控制臺查看故障機(jī)器近期的各項(xiàng)指標(biāo)，但是發(fā)現(xiàn)故障機(jī)器的指標(biāo)有重要的幾項(xiàng)丟失。內(nèi)存使用率、CPU 使用率、系統(tǒng)負(fù)載均不顯示。

控制臺看不了只好進(jìn)服務(wù)器內(nèi)查看各指標(biāo)，free -m 查看內(nèi)存無異常。提交阿里工單。授權(quán)阿里工程師幫忙修復(fù)控制臺顯示問題，懷疑這個問題對業(yè)務(wù)有影響。

控制臺修復(fù)后掉線問題依然存在。

懷疑對象二：CPU滿載

能感覺到執(zhí)行命令很流暢，所以感覺不是這個原因。top 查看后很正常。

懷疑對象三：磁盤滿了

雖然概率很小，但是 du -sh * 看一下，發(fā)現(xiàn)磁盤容量還能用到公司倒閉。

懷疑對象四：網(wǎng)絡(luò)有問題

服務(wù)器那三個基本故障暫時排除后，最大懷疑對象就是網(wǎng)絡(luò)。畢竟服務(wù)掉線肯定是服務(wù)端一段時間內(nèi)接收不到客戶端心跳包，所以把客戶端踢下線了。

通過 telnet,mtr -n...,netstat -nat |grep "TIME_WAIT" | wc -l 這些命令也只能看個大概。

echo "1" > /proc/sys/net/ipv4/tcp_tw_reuse 修改內(nèi)核參數(shù)，開啟 TIME_WAIT socket 復(fù)用能力，提升實(shí)例的網(wǎng)絡(luò)發(fā)送請求性能。

查看 nacos 客戶端（微服務(wù)）的日志，在前面案發(fā)里提到?jīng)]有日志記錄。

懷疑對象五：Nacos 集群服務(wù)端故障

查看 nacos 集群部署的那幾臺服務(wù)器, 查看服務(wù)器基礎(chǔ)指標(biāo) (內(nèi)存、CPU、磁盤等），未發(fā)現(xiàn)異常 （畢竟還有幾十個微服務(wù)都很正常工作）。

查看 nacos 服務(wù)端日志，發(fā)現(xiàn)確實(shí)有主動下線服務(wù)操作。那就奇怪了，這個機(jī)器上的有些服務(wù)還在正常工作，為什么會隨機(jī)下線幾個服務(wù)呢？

懷疑對象六：微服務(wù)占用資源太多

后來仔細(xì)想想，這個懷疑對象是不是有點(diǎn)離譜了？ 因?yàn)椴渴鹉_本都是同一個，而且負(fù)載均衡也是一樣的。 但其他機(jī)器的這個服務(wù)都好好的。

調(diào)大每個微服務(wù)的內(nèi)存占用。

添加堆棧打印。

等待一段時間后，異常依然存在，并且沒有堆棧打印？因?yàn)檫M(jìn)程好好的并沒退出。

google 搜索 nacos 服務(wù)掉線，找到一篇看起來極其靠譜的文章。

上文提到我使用的 springcloud 版本，恰好這個版本的 nacos-client 版本就是 1.4.1， 于是立馬測試升級。

觀察幾天后，發(fā)現(xiàn)問題依舊，只能將探查方向繼續(xù)轉(zhuǎn)回微服務(wù)本身。

用 arthas 進(jìn)行勘測各項(xiàng)指標(biāo)，發(fā)現(xiàn)所有正常的服務(wù)各指標(biāo)均正常。

想到服務(wù)掉線大概率是因?yàn)樾奶鼇G失，懷疑是心跳線程因?yàn)槟承┰虮粴⑺懒恕?/p>

翻看 nacos-client 源碼，找到心跳函數(shù)（nacos2.x 不是這個），使用 arthas 監(jiān)聽心跳包，嘗試能找到心跳丟失的證據(jù)，貼上當(dāng)時的記錄。

當(dāng)異常再次發(fā)生，arthas 監(jiān)聽卡死，無任何記錄和響應(yīng)。

無奈更換思路，寫一個監(jiān)聽服務(wù)掉線的程序，期望可以在工作時間內(nèi)及時獲取到異常。

終于在工作時間捕獲到異常，第一時間進(jìn)入服務(wù)器內(nèi)查看情況。

確認(rèn)服務(wù)器基礎(chǔ)項(xiàng)沒問題后，使用 arthas 查看服務(wù)進(jìn)程堆棧情況，但是 arthas 無法進(jìn)入進(jìn)程。

用 jstat 查看 GC 情況，顯示很正常。

用 jmap/jstack 輸出堆棧 jstack -l 25944 >heap.txt，但是提示無法進(jìn)入進(jìn)程。無奈使用添加 - F（這個參數(shù)的堆棧少了很多信息），jstack -F -l 25944 >heap.txt

查看堆棧文件上萬行記錄，眼都看花了但是沒有死鎖也沒有發(fā)現(xiàn)異常。

此時發(fā)現(xiàn)監(jiān)聽程序提示服務(wù)上線了？檢查后發(fā)現(xiàn)確實(shí)掉線的幾個微服務(wù)自動恢復(fù)了，心想這就難排查了。

嘗試復(fù)現(xiàn) Bug，此時離第一次案發(fā)已經(jīng)過去一周多，必須盡快處理好這個 Bug 否則可能得被迫離職了。

當(dāng)?shù)诙伟l(fā)生異常的時候，使用同樣的方式 arthas 無法進(jìn)入 ->...->jstack 輸出堆棧。奇跡發(fā)生了，服務(wù)又恢復(fù)正常了。

思考 / 猜測：因?yàn)?JVM 死了（假死），所以導(dǎo)致進(jìn)程中的一切內(nèi)容，包括心跳線程、日志等都 hold 住。

Google 搜索關(guān)鍵詞 JVM 停止（假死）排查，終于找到一個極其靠譜的回答。

連忙查看對比使用的幾個機(jī)器內(nèi)核版本號 uname -r。

那個低版本的就是故障機(jī)器，確認(rèn)相關(guān)信息后，聯(lián)系阿里云提交工單。

升級完內(nèi)核并重啟機(jī)器后，觀察兩天至今這個問題不存在了。誰能想到這個問題居然是因?yàn)?Linux 內(nèi)核的 Bug 引起的？！不得不佩服第一個發(fā)現(xiàn)這個 Bug 的大佬。

完結(jié)感言

這個問題折磨了一周多，每日如鯁在喉！調(diào)試過程也是苦樂參半，樂的是突然有了調(diào)試思路，苦的是思路是一條死胡同，還好最終結(jié)果是滿意的。

審核編輯：劉清