起因
上午有小夥伴說某個 java 服務響應特別慢,看了一下監控,很多請求都超時了,服務是活著的,但響應非常慢。
由於服務是多容器負載均衡排程部署的,又花了一點時間定位到具體的宿主機。仔細查下來發現,並不是部署該服務的所有容器都有問題,僅僅是某一個有問題。
具體的問題是某 java 程序的 cpu 佔用率 打滿了,是 100% 。
這裏要跟大家說的是,如果某關鍵服務的所有副本全部出問題了,那麼第一時間並不是揪著問題不放,跟那兒使勁查。而是先嚐試恢復服務,如果系統在架構上的彈性和容錯做的比較好,可能不會造成 “雪崩”,導致全系統異常,無法使用。但是注意,我說的是“關鍵服務”,就算你隔離、熔斷做的再好,關鍵服務不能用了,整個系統還是不能用,對使用者來說就是 “掛了” ,比如你出地鐵想掃個共享單車,掃碼沒問題,但就是開不了鎖(開鎖服務出問題了)。
對於我們今天遇到的問題來說,還好,沒那麼嚴重,觀察下來只是某服務的某副本出了問題。這裏我根據系統的具體情況和觀察到的情況做了個決定:先不回滾服務,一邊觀察一邊收集事故現場資訊,同時讓一位同事準備好,如果事故進一步惡化就立刻回滾。
其實就算 “回滾” 也是有問題的,因為如果要考慮周全的話,仔細一想就會有一些問題,比如:
回滾單個服務,看起來可行,但實際上問題多多,因為一般情況下,一次 “上線”,會涉及很多服務,相關的上下游都可能會有所牽涉,你如果只單單的回滾了出問題的那個服務 ,其他相關服務可還在最新狀態呢,到時候又會引發新的問題。除非你對這個服務瞭如指掌,非常清楚迭代的內容,也能夠判斷出回滾的影響可控,否則只回滾單個服務,在大型分散式系統中是有風險的。
版本回滾,這也是一些公司的常規做法。尤其是出了比較嚴重的問題,那麼一次上線的全部內容都要完整地回滾,而不僅僅是回滾出問題的那個服務。但這也比較麻煩,因為首先 “全部回滾” 的時長可能比較長,時間一長對使用者的影響就比較大。另外,回滾後還要處理從上線到回滾完成這段時間以來產生的 “髒資料”。總之複雜度高了,要考慮的問題也多。
好了,關於回滾,我這裏就點到為指。總而言之,還是要根據你係統的具體情況來決定。謹慎、靈活地處置。
問題解決過程
上文我說問題只要服務的某個副本上出了問題,你可能會覺得不對,程式碼都一樣的,怎麼可能就只有一個副本有問題呢?
所以先解釋下原因,最後事故處理完我們分析程式碼發現,原來是某個特殊的使用者在某個特殊的條件下觸下了某個 bug。那部分程式碼確實只會在這麼特殊的條件下才會執行,而且這個動作的執行頻率相當低。所以就是這麼巧。
我們進入正題,首先在宿主機上看到某 java 程序的 CPU 佔用率是 100% 。由於我們所有的 java 程序全部是 docker 容器啟動的,所以要找到具體是宿主機的哪個 docker 容器,這裏我用了這個命令:
docker ps -q | xargs docker inspect --format '{{.State.Pid}}, {{.Id}}' | grep 2880
假設在宿主機上的這個 java 程序的 pid 為 2880。這行命令就是找出 pid 對應的具體是哪個 docker 容器。詳解說明一下:
docker ps
是用來列出當前執行中的 Docker 容器的命令。 -q 選項告訴 docker ps 僅輸出每個容器的 ID,而不是完整的容器資訊列表。|
(管道運算子):管道運算子用於將前一個命令的輸出作為下一個命令的輸入。這裏,它將docker ps -q
命令輸出的容器 ID 列表傳遞給下一個命令。xargs docker inspect --format '{{.State.Pid}}, {{.Id}}'
:xargs 是一個將輸入資料轉換為其他命令列引數的工具。在這裏,它將docker ps -q
輸出的容器 ID 列表轉換為docker inspect
命令的引數。docker inspect
是用於獲取有關 Docker 容器的詳細資訊的命令。--format '{{.State.Pid}}, {{.Id}}'
是一個格式化選項,它指定了docker inspect
命令的輸出格式。這裏使用了 Go 模板語法來指定只輸出每個容器的程序 ID(PID)和容器 ID。|
(管道運算子):再次使用管道運算子,將docker inspect
命令的輸出傳遞給下一個命令。grep 2880
:grep 是一個文字搜尋工具,用於搜尋包含特定模式的字串。2880 是要搜尋的字串,代表一個程序 ID(PID)。這個命令會從輸入中篩選出包含數字 2880 的行。
將所有部分結合起來,這行命令的作用是:首先,列出所有執行中的 Docker 容器的 ID。 然後,對每個容器 ID 執行 docker inspect,以獲取每個容器的 PID 和 ID,並以特定格式輸出。最後,從這些輸出中篩選出 PID 為 2880 的容器,並顯示其 PID 和 ID
到這裏我們知道了具體是哪個容器,然後進入到該容器中,檢視了一下 cpu 的使用情況,確實很高,接著使用以下命令匯出 java 程序的執行緒堆疊
jstack -l 1 > jstack.log
java 程序的 pid 為 1 ,所以上面命令中 1 就是 java 程序的程序 pid
分析 threadDump
用 jstack 命令匯出 java 程序的執行緒堆疊快照後就可以進行分析了。
這裏我們使用線上的工具網站來分析:fastthread.io/
我個人覺得是最好用的一個。你可能會問有沒有本地的好用的工具。我找了一圈,有是有,但很一般,還不如人家這個線上網站呢。
接著我們反 jstack.log 打個包上傳上去。很快就會得到分析結果,會出一個關於這個 Thread Dump 的全方面分析報告,方便你定位相關問題。
如果有異常會有紅號感嘆號提示。
除了人家提示的明顯異常,我一般重點會看有沒有死鎖,以及哪些執行緒佔用的 CPU 較高:
剩下的就憑藉你對系統的瞭解和經驗作出判斷了。
具體到我們的情況,我們分析了佔 CPU 最高的兩個執行緒,全部跟我們自己寫的程式碼有關。具體來說有一個執行緒的程式碼執行的是一個遞迴操作。出問題的就是這部分程式碼。
找到原因後,很快我們就修復了 bug。
最後
要說簡單也簡單,如果你的思路是對的,整個處理過程不超過 3 分鐘。但如果你的思路有問題,找到問題的時間就可能會無限長。