Java微服務隨機掉線排查過程簡析

背景

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

流量轉發路徑：nginx -> spring-gateway -> 業務微服務。

使用的版本如下：

spring-boot.version：2.2.5.RELEASE

spring-cloud.version：Hoxton.SR3

spring-cloud-alibaba.version：2.2.1.RELEASE

java.version：1.8

案發

春節放假期間收到反饋，網頁報錯服務未找到（gateway 找不到服務的報錯提示）。查看 nacos 集群列表，發現個別服務丟失 （下線）。

這個問題每幾天出現一次, 出現時間不固定, 每次掉線的服務像是隨機選的幾個。服務手動 kill+restart 后能穩定運行 2-3 天。

排查和解決

懷疑對象一：服務器內存爆了

進阿里云控制臺查看故障機器近期的各項指標，但是發現故障機器的指標有重要的幾項丟失。內存使用率、CPU 使用率、系統負載均不顯示。

控制臺看不了只好進服務器內查看各指標，free -m 查看內存無異常。提交阿里工單。授權阿里工程師幫忙修復控制臺顯示問題，懷疑這個問題對業務有影響。

控制臺修復后掉線問題依然存在。

懷疑對象二：CPU滿載

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

懷疑對象三：磁盤滿了

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

懷疑對象四：網絡有問題

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

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

echo "1" > /proc/sys/net/ipv4/tcp_tw_reuse 修改內核參數，開啟 TIME_WAIT socket 復用能力，提升實例的網絡發送請求性能。

查看 nacos 客戶端（微服務）的日志，在前面案發里提到沒有日志記錄。

懷疑對象五：Nacos 集群服務端故障

查看 nacos 集群部署的那幾臺服務器, 查看服務器基礎指標 (內存、CPU、磁盤等），未發現異常 （畢竟還有幾十個微服務都很正常工作）。

查看 nacos 服務端日志，發現確實有主動下線服務操作。那就奇怪了，這個機器上的有些服務還在正常工作，為什么會隨機下線幾個服務呢？

懷疑對象六：微服務占用資源太多

后來仔細想想，這個懷疑對象是不是有點離譜了？ 因為部署腳本都是同一個，而且負載均衡也是一樣的。 但其他機器的這個服務都好好的。

調大每個微服務的內存占用。

添加堆棧打印。

等待一段時間后，異常依然存在，并且沒有堆棧打??？因為進程好好的并沒退出。

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

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

觀察幾天后，發現問題依舊，只能將探查方向繼續轉回微服務本身。

用 arthas 進行勘測各項指標，發現所有正常的服務各指標均正常。

想到服務掉線大概率是因為心跳包丟失，懷疑是心跳線程因為某些原因被殺死了。

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

當異常再次發生，arthas 監聽卡死，無任何記錄和響應。

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

終于在工作時間捕獲到異常，第一時間進入服務器內查看情況。

確認服務器基礎項沒問題后，使用 arthas 查看服務進程堆棧情況，但是 arthas 無法進入進程。

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

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

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

此時發現監聽程序提示服務上線了？檢查后發現確實掉線的幾個微服務自動恢復了，心想這就難排查了。

嘗試復現 Bug，此時離第一次案發已經過去一周多，必須盡快處理好這個 Bug 否則可能得被迫離職了。

當第二次發生異常的時候，使用同樣的方式 arthas 無法進入 ->...->jstack 輸出堆棧。奇跡發生了，服務又恢復正常了。

思考 / 猜測：因為 JVM 死了（假死），所以導致進程中的一切內容，包括心跳線程、日志等都 hold 住。

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

連忙查看對比使用的幾個機器內核版本號 uname -r。

那個低版本的就是故障機器，確認相關信息后，聯系阿里云提交工單。

升級完內核并重啟機器后，觀察兩天至今這個問題不存在了。誰能想到這個問題居然是因為 Linux 內核的 Bug 引起的？！不得不佩服第一個發現這個 Bug 的大佬。

完結感言

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

審核編輯：劉清