日常Bug排查-消息不消費

2021 年 6 月 4 日
筆記
JAVA, MySQL, TCP

日常Bug排查-消息不消費

前言

日常Bug排查系列都是一些簡單Bug排查，筆者將在這裡介紹一些排查Bug的簡單技巧，同時順便積累素材^_。

Bug現場

某天下午，在筆者研究某個問題正high的時候。開發突然找到筆者，線上某個系統突然消費不了queue了。Queue不消費也算是日常問題了。淡定的先把流量切到另一個機房，讓問題先恢復再說。

消息累積

然後就是看不消費的queue到哪去了，打開mq(消息中間件)控制台，全部累積到mq上了。

同時開發對筆者反映，只有這個queueu積累了，其它queue還是能正常消費的。

出問題時間點

這時筆者還得到了一個關鍵資訊，此問題是DBA對其關聯的資料庫進行操作後才發生的。當時由於操作灌入的資料庫過大，導致資料庫主從切換，漂了VIP。從時間點判斷，這個應該是問題的誘因。

jstack

既然卡住了，那麼老辦法，jstack一下，看看我們的mq消費執行緒在幹嘛:

ActiveMQ Session Task-1234
	at java.net.SocketInputStream.socketRead0
	......
	at com.mysql.jdbc.MysqlIO.readFully
	......
	at org.apache.activemq.ActiveMQMessageConsumer.dispatch
	......

很明顯的，都卡在MysqlIO.readFully也就是資料庫讀取上，再也不往下走了。

沒配超時

這就肯定是沒配超時了，排查了下他們的配置，確實沒配。之前系統梳理過好多次，但沒想到還是有這種漏網之魚。這個問題分析本身是很簡單的。不過在這裡筆者想多聊一下，為什麼數據主從切換會形成這樣的現象。

mha切換

如圖所示，mha切換邏輯是將vip從DB舊主上摘掉，然後將vip掛到DB新主上面。為了觀察這種行為，筆者寫了個python程式進行測試。觀察得知，在vip被摘掉的那一刻，雙方的通訊已經不正常了。但是tcp連接狀態依舊是ESTABLISHED。

為什麼tcp狀態依舊ESTABLISHED

因為ip摘掉並不會讓已經存在的socket立馬感知，那麼socket什麼時候能夠感知到我們這個連接已經gg了呢。在當前這個場景下，應用沒設置socket超時，會有這幾種可能:

如果這時候App正在發請求給此五元組

如果DB正在寫回請求給此五元組

由上面兩種情況，我們可以知道哪方作出發送動作，哪方就能夠通過reset或者嘗試次數過多來感知到這個連接已經gg了。
很明顯的，由於我們的應用正卡在socket read,表明我們的App應用並沒有發送數據，而是在等待MySQL的返回，那麼在不設置超時的情況下，App怎麼感知到連接實際上已經不好了呢。

tcp保活定時器

由於應用不做發送動作，那這時就輪到我們的tcp保活定時器tcp_keepalive出馬了。linux下默認的內核參數為:

/proc/sys/net/ipv4/tcp_keepalive_time 7200 兩小時
/proc/sys/net/ipv4/tcp_keepalive_probes 9 探測9次
/proc/sys/net/ipv4/tcp_keepalive_intvl 75s 每次探測間隔75s

tcp保活定時器默認在7200s也就是兩小時後開啟，探測9次，每次間隔75s，如果有明確失敗或者9次都沒返回則判定連接gg。

在我們的這個場景中，應用會在兩個小時後開始保活，在第一次探測的時候對端發送reset從而應用感知到連接gg。這時候，應用才返回。也就是說，不設置超時時間，遇到這種情況，應用的執行緒要卡2小時！

如果是DB進程宕or重啟

如果不是mha切換，而是DB進程重啟或者宕的話，由於Linux內核沒宕還存在著。內核會自動將DB進程所屬的socket進行close也就是發FIN報文回去。那麼應用就可以立馬從socket read系統調用中返回了。

物理機宕機

物理機宕機而不漂VIP,應用在不設置超時的時候。如果是發送數據階段，則tcp_reties2次重試後從socket read系統調用返回。如果不發送數據，和上面的描述基本一樣，2個小時後開啟保活定時器。唯一不同的是，這次是需要探活9次，所以需要會多花11分鐘左右的時間感知。

線下演練為什麼不出問題

VIP漂移這種操作，我們在線下演練過，當時應用很快就切換完了。為什麼到了線上就會卡住呢？這是因為，線下沒有加上IO hang住導致SQL處理時間過長這一條件。SQL很快就返回了，所以我們線下的執行緒只有很小的概率卡在socket read上面。況且有幾十個執行緒在消費，卡一兩個無關大局。

而在我們這次上面，由於SQL處理時間超長，所以基本所有的執行緒都在VIP漂移的那一刻執行socket read即等待資料庫返回階段，就導致所有執行緒全部hang住等。這時候只能等待tcp_keepalive或者重啟了。

總結

要保證高可用，任何遠程調用都需要設置超時。否則就會導致應用長時間無法響應這樣的現象。

Tags: JAVA MySQL TCP