佇列卡住?方向錯了,使出十八般武藝也沒用

語言: CN / TW / HK

一、背景

上篇文章《 發生故障,服務能承受住考驗嗎? 》提到,下午的時候收到兩個服務失敗率告警。

處理完那個故障後,我多看了一眼監控,發現另外一個失敗率還沒恢復。

於是,繼續找快取層核心開發,問服務是否還有其他問題。

二、誰的問題

還是先熟悉架構圖,如下,分為接入層(我負責)與快取層(核心開發人員負責)。

接入層呼叫快取層時,接入層有一個主調監控,快取層有一個被調監控。

主調監控上看,快取層有一個數據分片存在一個失敗率。

從被調監控上看,快取層自己沒有失敗率。

只看這個資料,沒辦法證明是主調接入層的問題還是被調快取層的問題。

正常情況下,主調監控還會上報主調 IP 與被調 IP:PORT 。

由於我們的系統訪問量比較大,監控系統平臺自動把主調監控的被調 IP:PORT 遮蔽掉了。

我看接入層主調監控的主調 IP,可以看到各臺容器的失敗率比較平均,因此可以排除接入層的單機問題。

所以,我懷疑是被調服務,也就是快取層存在單機問題,比如某臺機器在 coredump。

我這裡不能證明是誰的問題,快取層核心開發說聲稱看監控自己的服務沒問題。

於是我聯絡監控系統平臺,要求開啟主調監控的被調IP,不然沒法定位問題。

開啟半個小時後,從監控上看到了被調IP,也收到了接入層主調監控的單機失敗率告警。

果然,快取層的三臺機器異常。

我趕緊讓快取層核心開發把那三個容器從路由發現平臺摘除掉,然後再去分析問題。

快取層核心開發問我怎麼摘除,那麼多機器找不掉這三臺機器。

我說我摘除吧,路由發現平臺支援基於IP來搜尋的。

於是我隨手就把異常的機器都摘除了。

三、尋找原因

現在已經明確,快取層服務有三個容器存在失敗率。

我讓快取層核心開發定位一下。

一段時間之後,快取層核心開發說看異常機器的被調監控、CPU、負載、記憶體等都正常,沒發現問題。

於是我介入一起看問題。

我自言自語分析到:可以看看單機主調監控,極有可能是某個資料快取命中率降低,但這樣不應該是單機問題。

當然,也可能是系統問題,看屬性監控應該可以看出來。

我隨手去屬性監控一看,發現了問題真相:異常容器有一個佇列卡住了。

然後一算失敗率,14 個佇列,卡住一個,失敗率 7%。

與收到的失敗率告警完全一致。

自此,快取層單機失敗的原因找到了,是佇列卡住了。

所以,接下來是分析為啥佇列會卡住。

四、十八般武藝

由於異常機器已經從路由發現平臺遮蔽,所以先去吃了晚飯。

飯後,我拉上了 RPC 框架的人,問佇列這塊的架構是怎麼樣的。

我的想法是先簡單瞭解架構設計,然後再進行分析。

可能是吃飯時間,RPC框架的同學沒有回覆訊息,我便先自己嘗試定位問題。

武藝1:從屬性監控上可以看到,是 HandleModel 佇列 4 卡住了。

我猜測 RPC 框架是有多執行緒實現多佇列的,所以應該是 HandleModel 4 執行緒卡住了。

具體原因需要了解架構才行。

但是 RPC 框架的人不在,只能自己隨便折騰下嘗試一下。

武藝2:檢視服務程序 PID - top

由於是單程序, top 命令即可看到程序 PID。

武藝3:檢視卡住的執行緒 ID - top -H

由於 RPC 框架對各種管理的執行緒程序了命名,所以根據執行緒名就可以找到對應的執行緒 ID。

命令: top -H -p $PID 解釋: -H 是顯示執行緒, -p $PID 是隻顯示指定程序的資訊。

合起來就是隻顯示程序 $PID 的執行緒資訊。

武藝4:top 資訊非互動式輸出。

這個服務的執行緒有幾百個,top 一螢幕顯示不下,所以看不到對應的執行緒 ID。

非互動式輸出的好處是可以使用管道來進一步使用其他命令對輸出處理,或者重定向到檔案裡。

命令: top -H -b -n 1 -p $PID 解釋: -b 是按 Batch-mode 模式執行,含義是批處理模式,即非互動模式,可以使用管道的模式。

-n 1 含義是 top 只允許一次,預設是無限執行,可以用來多次採集程序或執行緒資訊。

這樣,我們就可以在檔案裡搜尋到對應的執行緒 ID 了。

武藝5: gcore 儲存程序 core 映象檔案。

問題是突然發生的,不知道怎麼復現的。

現在遇到了,如果把程序搞掛了,問題現場就不存在了。

所以,一般情況下,需要保留一份現場環境,用於後面持續分析與定位。

命令: gcore $PID

如果看 gcore 的原始碼,會發現是一個 bash 指令碼,備用呼叫的是 GDB 命令。

武藝6: GDB 開啟 core 檔案

命令: gdb ./exe_name core.$PID

武藝7:gdb 檢視執行緒資訊

命令: info threads

可以發現,對於每個執行緒 ID,GDB 中需要另外一個序號 id。

武藝8: gstack 檢視全部執行緒資訊

固然可以把幾百個執行緒ID都輸出來,然後複製到文字中搜索,但是不優雅。

所以,我想起 gstack 這個命令,可以列印所有執行緒的堆疊,包括執行緒 ID 和 那個序號。

PS:由於 gstack 執行的較慢,我最終還是從之前的 GDB 裡把所有執行緒資訊複製出來了。

當然,如果你檢視下 gstack 的原始碼,會發現也是通過 gdb 實現的,而且比 gcore 實現的優雅一些。

所以,另外一種方法是在 GDB 裡執行命令,然後把執行緒資訊輸出到檔案裡。

武藝9:gdb 切換到對應的執行緒上下文

命令: thread 執行緒對應的序號ID

武藝10:gdb 檢視堆疊

命令: bt

武藝11:檢視 RunEpollTask 的原始碼

可以發現,RPC 框架函式 RunEpollTask 呼叫了系統函式 epoll_wait ,之後就卡住了。

武藝12:檢視 EpollGetTimeout 的原始碼

可以發現,程式碼裡判斷了大小,防止減法減出負數來。

但是由於沒有把 thread->GetWakeupTime() 的值儲存下來,併發執行的情況下,可能前一時刻不小於,後一時刻就小於了。

所以這個函式可能是正常的算出很大的值,也可能是相減算出負數,然後變成無窮大值。

武藝13:列印引數

RunEpollTask 呼叫 epoll_wait 時傳了四個引數,很不幸,第四個最重要的時間引數被優化掉了,打印不出來。

武藝14:反彙編,檢視傳參

看到一堆彙編指令,發現與大學以及網上查到的彙編指令不同,但是又長得差不多。

武藝15:複習彙編

大學彙編課程與網上的彙編資料都是 Intel X86 彙編。

多年前,我也在《彙編快速認識》整理過一些簡單的彙編知識。

而 Linux 下的彙編是 GUN GAS 彙編。

兩個語法又不少差異。

差異1:第一運算元時目的運算元,第二個運算元時源運算元(剛好相反)。

差異2:間接定址,通用暫存器加括號即可獲取間接運算元。

差異3:定址萬能公式。

segment:displacement(base register, index register, scale factor)
等價於
segment:[base register + displacement + index register * scale factor]

真實地址:segment × 16 + 偏移地址

至於暫存器 SP、IP 等與命令 MOV、PUSH、POP、CALL、RET、以及一堆 test 指令,差異不是很大,這裡就不展開介紹了。

武藝16:函式調用匯編如何傳參

我們知道,函式呼叫時,有兩種方法傳參。

一種是全部使用暫存器,另一種是壓入棧裡面。

0x0000000000ee9e5e <+30>:    mov    0xc(%rbx),%edx
0x0000000000ee9e61 <+33>:    mov    0x10(%rbx),%rsi
0x0000000000ee9e65 <+37>:    mov    0x8(%rbx),%edi

看上面反彙編的截圖,可以發現是通過暫存器傳參的。

只不過 epoll_wait 有四個引數,這裡只能看到給三個暫存器賦值。

這是因為編譯器進行了優化,最後一個引數 wait_time 是呼叫函式的返回值,那在呼叫函式返回的時候就可以賦值了。

查下暫存器會引數位置的文件,可以發現引數從前到後的暫存器依次是 edi、rsi、edx、ecx

對應到反彙編上,就是下面四條指令。

武藝17:列印暫存器的值

既然反彙編發現引數存入到暫存器中了,那自然需要打印出暫存器的值,核對一下。

暫存器的值打印出來後,可以發現前三個暫存器的值沒問題,與 p 出來的一致。

但是最後一個關鍵引數的值,是個無窮大值。

到這裡,有兩種可能:要麼是傳參就是這個無窮大值,要麼是 epoll_wait 函式使用到了這個暫存器,修改了值。

所以還需要反彙編檢視 epoll_wait 的程式碼。

武藝18:檢視 epoll_wait 原始碼與反彙編

看到 epoll_wait 反彙編與原始碼,我們可以發現暫存器 ecx 的值賦值到了暫存器 r10 ,值是 10 沒問題。

武藝EX:正常流量打斷點

既然認為這裡的暫存器沒問題,那使用正常流量確認下暫存器的值。

b external/trpc_cpp/trpc/common/coroutine/spp_mt/epoll_proxy.cpp:359
r
b epoll_wait
i registers
p wait_time

通過執行上面的命令,發現正常情況下, wait_time 的值果然是 10,此時 wait_time 的值也可以打印出來。

五、最後

此刻我突然意識到我最初的目標是找 RPC 框架的同學,瞭解佇列的設計架構。

現在方向突然偏航了,轉向去研究為啥卡在 epoll_wait 了。

但是堆疊在 epoll_wait 並不代表就是在這裡卡住了。

後面還是找時間看一下 RPC 框架的原始碼,先了解下 RPC 框架是怎麼設計這個佇列的話。

方向錯了,即使使出十八般武藝,也是無效的。

《完》

-EOF-

本文公眾號:天空的程式碼世界

個人微訊號:tiankonguse

QQ演算法群:165531769(不止演算法)

知識星球:不止演算法