一次端口告警,發現 java 進程被異常殺掉,而根因竟然是因為在問題機器上 vim 查看了 nginx 日志。下面我將從時間維度詳細回顧這次排查,希望讀者在遇到相似問題時有些許啟發。
時間線
15:19 收到端口異常 odin 告警。
狀態:P1故障
名稱:應用端口8989
指標:data-stream-openapi.port.8989
主機:data-stream-openapi-nmg-sf-a9457-1.docker.nmg01
節點:hbb-v.data-stream-openapi.data-stream.datadream.didi.com
當前值:0.00
說明:happen(data-stream-openapi.port.8989,#12,12) = 0
故障時間:2022-11-15 15:21:10
收到告警之后,登陸機器發現 java 進程消失了,第一反應是先摘流容器,然后再排查問題。
15:23 摘掉容器流量。
15:24 開始重建容器。
15:26 重建容器成功并上線。
請求成功率恢復,端口恢復。
排查路徑
線上告警解除,業務恢復正常后,開始排查問題。首先排除日常發布的因素,先查看容器性能相關的監控,是否存在異常。查看 odin 用戶內存使用率的監控,發現有異常:在 15:19 內存使用率突然飆升,然后極速下跌。看著內存使用率有問題,第一反應是否有 FullGC 的問題?
奇怪的是,在告警發生前后,居然一直沒有 FullGC。
YGC 在問題發生點沒有異常,15:25 YGC 較高,但很快恢復,應該和應用剛啟動有關。
此時順便查看 cpu 使用率有無問題。線上性能問題,往往是內存、cpu、io 這些情況。cpu 使用率沒有明顯的波動,15:25有短暫升高,原因是容器重建,java 代碼即時編譯。
既然性能層面監控沒有頭緒,試著查看應用監控和日志。成功率下跌是基于 nginx 的滅火圖監控,查看應用層面接口的成功率監控,發現在告警發生期間,應用接口成功率并沒有下跌。
根因定位
沒有 FullGC,應用監控和應用日志都沒有明顯異常,為什么 java 進程無緣無故沒有了?難道被 Linux 殺掉了,這時只能抱著試試的心態,看看是不是這個原因。
dmesg -T | grep java。
發現 java 進程1155805在15:17時候被 linux 操作系統殺掉了,原因是發生了out of memory。再看看端口異常的告警配置,在12個周期(12*10s=2min)端口均不通會觸發告警。到此,時間點串起來了。15:17 linux oom killer 殺掉了 java 進程,15:19 觸發了端口異常告警。? ? ? ?
奇怪的是,java 進程并沒有 FullGC,為啥會觸發 linux 系統 OOM 呢?就在排查原因陷入困境時,有同事反饋他剛才在問題機器看過日志,是使用?vim?查看?nginx?日志,打開文件過程中,vim 程序報錯。
有資料反饋 oom killer 有 case 和 vim 操作有關
vim 查看日志為什么會干掉 java 進程呢?看一下日志大小,居然有37G,而我們的容器規格僅有8G。?
至此,問題原因基本定位:使用 vim 命令查看37G的的文件,文件在加載過程中耗盡了內存,觸發了 linux oom killer 的機制,進而殺掉了 java 進程。
問題是,為什么不殺掉 vim 進程,而要殺掉 java 進程呢?
原理解析
這里有兩個問題要驗證:
vim 是不是要將文件全部加載到內存?
linux oom killer的機制是什么?
查閱資料吧,進入知識盲區了。有一篇不錯的 vim 原理介紹 ,有興趣可以閱讀:《Linux 編輯器之神 vim 的 IO 存儲原理》
歸納一下,vim 在加載文件時會調用 readfile 函數(readfile 內部在系統調用read),而 readfile 會讀完文件。看來 vim 加載大文件確實會干爆內存。
劃重點:readfile 會讀完文件。這就是為什么當 vim 打開一個超大文件的時候,會非常慢的原因
那 linux oom killer 的機制又是什么?為什么不殺 vim 進程,殺掉 java 進程呢?核心原理是在內存快被耗盡的時候,linux 會嘗試殺掉一些進程,不讓系統變得更糟糕,具體殺掉哪個進程,有一個打分機制,得分高的進程容易被殺掉。具體原理可閱讀《Linux 內核 OOM killer 機制》、《oom kill 內存源碼》。
文章內容在此不贅述,分享兩個核心:一個是 linux 內核源碼注釋
* If we run out of memory, we have the choice between either* killing a random task (bad), letting the system crash (worse)* OR try to be smart about which process to kill. Note that we* don't have to be perfect here, we just have to be good.
一個是 oom killer 相關結論
你的進程被Linux殺掉幾個可能的原因:
一種是內存泄露;
一種是你的進程所需要的內存資源太大,系統無法滿足,應該在設計時對進程需要的資源有個最大限制,不能讓他無限增長;
當然,也不一定全是你的問題,也有可能是同一主機的其他進程占用資源過多,但是Linux OOM選擇“最壞“進程殺掉的算法是很簡單粗暴的,就選中你的進程殺掉,也是有可能的
linux oom killer 會在系統內存耗盡的時候,觸發殺掉糟糕進程的保護機制,但選擇糟糕進程的機制不是很精準,存在誤殺的可能。
運維規范
查看或者搜索日志有很多很好用的命令,比如 less、grep、tail。
vim?命令嚴禁用在查看日志的場景,如果需要用 vim 編輯文件,一定要先確認文件的大小。