[[403694]]

前言

日常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或者重啟了。

本文轉載自微信公眾號「解Bug之路」，可以通過以下二維碼關注。轉載本文請聯系解Bug之路公眾號。