在之前的記一次k8s pod頻繁重啟的優化之旅中分享過對于pod頻繁重啟的一些案例,最近又遇到一例,繼續分享出來希望能給大家帶來些許收獲。
(資料圖片)
報警群里突然顯示某pod頻繁重啟,我隨即上去查看日志,主要分這么幾步:
1.查看pod重啟的原因,kubectl descirbe pod
Last State: Terminated Reason: Error Exit Code: 137
上面的Reason:Error太寬泛了,不能直觀的知道原因,Exit code:137一般表示程序被SIGKILL
中斷信號殺死,異常原因可能為:
https://cloud.tencent.com/document/product/457/42945
首先排除OOMKilled情況,剩余的就是livenessProbe(存活檢查)失敗。
2.查看pod事件,kubectl descirbe pod,重點關注輸出的Events部分
Warning Unhealthy 2m56s (x8 over 7m16s) kubelet Liveness probe failed: Get http://10.244.11.136:8080/jc_actuator_1/health: net/http: request canceled (Client.Timeout exceeded while awaiting headers)Normal Killing 2m56s kubelet Container enterprise-service failed liveness probe, will be restarted
熟悉的健康檢查失敗(超時),是什么導致超時呢,繼續找日志。
3.結合之前的排查經驗,我認為gc的嫌疑最大,所以查看gc日志
貼一部分日志,可以看到Full GC很繁忙,而且每次結束后內存幾乎沒有釋放,應用已經是處于停擺狀態,接下來要做的就是找出Full GC的兇手。
2023-04-22T14:30:58.772+0000: 574.764: [Full GC (Allocation Failure) 2023-04-22T14:30:58.772+0000: 574.764: [Tenured: 2097151K->2097151K(2097152K), 3.6358812 secs] 2569023K->2568977K(2569024K), [Metaspace: 119379K->119379K(1163264K)], 3.6359987 secs] [Times: user=3.64 sys=0.00, real=3.63 secs] 2023-04-22T14:31:02.410+0000: 578.402: [Full GC (Allocation Failure) 2023-04-22T14:31:02.410+0000: 578.402: [Tenured: 2097151K->2097151K(2097152K), 3.5875116 secs] 2569023K->2568980K(2569024K), [Metaspace: 119379K->119379K(1163264K)], 3.5876388 secs] [Times: user=3.59 sys=0.00, real=3.59 secs] 2023-04-22T14:31:05.999+0000: 581.991: [Full GC (Allocation Failure) 2023-04-22T14:31:05.999+0000: 581.991: [Tenured: 2097152K->2097151K(2097152K), 3.5950824 secs] 2569024K->2568987K(2569024K), [Metaspace: 119379K->119379K(1163264K)], 3.5951774 secs] [Times: user=3.59 sys=0.00, real=3.60 secs] 2023-04-22T14:31:09.596+0000: 585.587: [Full GC (Allocation Failure) 2023-04-22T14:31:09.596+0000: 585.587: [Tenured: 2097151K->2097151K(2097152K), 3.5822343 secs] 2569023K->2568849K(2569024K), [Metaspace: 119379K->119379K(1163264K)], 3.5823244 secs] [Times: user=3.58 sys=0.00, real=3.58 secs] 2023-04-22T14:31:13.180+0000: 589.172: [Full GC (Allocation Failure) 2023-04-22T14:31:13.180+0000: 589.172: [Tenured: 2097151K->2097151K(2097152K), 3.6316461 secs] 2569020K->2568910K(2569024K), [Metaspace: 119380K->119380K(1163264K)], 3.6317393 secs] [Times: user=3.63 sys=0.00, real=3.64 secs] 2023-04-22T14:31:16.813+0000: 592.805: [Full GC (Allocation Failure) 2023-04-22T14:31:16.813+0000: 592.805: [Tenured: 2097151K->2097151K(2097152K), 3.6070671 secs] 2569021K->2568907K(2569024K), [Metaspace: 119380K->119380K(1163264K)], 3.6071998 secs] [Times: user=3.60 sys=0.00, real=3.60 secs] 2023-04-22T14:31:20.425+0000: 596.417: [Full GC (Allocation Failure) 2023-04-22T14:31:20.425+0000: 596.417: [Tenured: 2097151K->2097151K(2097152K), 4.7111087 secs] 2569020K->2568899K(2569024K), [Metaspace: 119381K->119381K(1163264K)], 4.7112440 secs] [Times: user=4.71 sys=0.00, real=4.71 secs] 2023-04-22T14:31:25.142+0000: 601.133: [Full GC (Allocation Failure) 2023-04-22T14:31:25.142+0000: 601.133: [Tenured: 2097151K->2097151K(2097152K), 3.8752248 secs] 2569023K->2568899K(2569024K), [Metaspace: 119381K->119381K(1163264K)], 3.8753506 secs] [Times: user=3.88 sys=0.01, real=3.87 secs] 2023-04-22T14:31:29.021+0000: 605.012: [Full GC (Allocation Failure) 2023-04-22T14:31:29.021+0000: 605.012: [Tenured: 2097151K->2097151K(2097152K), 3.5892311 secs] 2569023K->2568910K(2569024K), [Metaspace: 119381K->119381K(1163264K)], 3.5893335 secs] [Times: user=3.59 sys=0.00, real=3.59 secs] 2023-04-22T14:31:32.612+0000: 608.604: [Full GC (Allocation Failure) 2023-04-22T14:31:32.612+0000: 608.604: [Tenured: 2097151K->2097151K(2097152K), 3.5236182 secs] 2569023K->2568915K(2569024K), [Metaspace: 119381K->119381K(1163264K)], 3.5237085 secs] [Times: user=3.52 sys=0.00, real=3.52 secs]背景知識
我們的服務部署在k8s中,k8s可以對容器執行定期的診斷,要執行診斷,kubelet 調用由容器實現的 Handler (處理程序)。有三種類型的處理程序:
ExecAction:在容器內執行指定命令。如果命令退出時返回碼為 0 則認為診斷成功。
TCPSocketAction:對容器的 IP 地址上的指定端口執行 TCP 檢查。如果端口打開,則診斷被認為是成功的。
HTTPGetAction:對容器的 IP 地址上指定端口和路徑執行 HTTP Get 請求。如果響應的狀態碼大于等于 200 且小于 400,則診斷被認為是成功的。
每次探測都將獲得以下三種結果之一:
Success(成功):容器通過了診斷。
Failure(失敗):容器未通過診斷。
Unknown(未知):診斷失敗,因此不會采取任何行動。
針對運行中的容器,kubelet 可以選擇是否執行以下三種探針,以及如何針對探測結果作出反應:
livenessProbe:指示容器是否正在運行。如果存活態探測失敗,則 kubelet 會殺死容器, 并且容器將根據其重啟策略決定未來。如果容器不提供存活探針, 則默認狀態為 Success。
readinessProbe:指示容器是否準備好為請求提供服務。如果就緒態探測失敗, 端點控制器將從與 Pod 匹配的所有服務的端點列表中刪除該 Pod 的 IP 地址。初始延遲之前的就緒態的狀態值默認為 Failure。如果容器不提供就緒態探針,則默認狀態為 Success。
startupProbe: 指示容器中的應用是否已經啟動。如果提供了啟動探針,則所有其他探針都會被 禁用,直到此探針成功為止。如果啟動探測失敗,kubelet 將殺死容器,而容器依其重啟策略進行重啟。如果容器沒有提供啟動探測,則默認狀態為 Success。
以上探針介紹內容來源于https://kubernetes.io/zh/docs/concepts/workloads/pods/pod-lifecycle/#container-probes
尋找原因前面提到是由于Full GC STW導致jvm無法提供服務,那我們就看看是什么導致Full GC,具體的手段就是獲取heap dump文件,然后分析,什么時機去獲取呢?
這里采用的辦法是守株待兔,開兩個窗口,一個盯著gc日志,當看到有大量Full GC產生時在另一個窗口生成heap dump文件。
接下來通過Eclipse MAT工具分析dump文件
原因一目了然,是導出excel導致,涉及的數據接近10w條,且列比較多。
分析代碼大概看了一下導出的代碼,問題集中在以下四點:
1.查詢數據沒有使用分頁;
2.使用的Apache poi工具本身性能不好,內存占用過高;
3.導出沒有限流,對于極度消耗資源的操作必須要控制并發,保護系統;
4.同步導出,用戶等待時間過長時會選擇重試,對系統來講是雪上加霜。
改進措施1.查詢分頁,保證往excel寫數據時內存中只會有一頁數據;
2.使用性能更好的工具,如easyexcel;
3.異步導出,控制同時導出的并發數;
經過這三步改造以后,導出導致的Full GC問題得以改善,上線一周再沒有發現由于大數據量的導出導致的pod重啟問題。
推薦閱讀1.容器服務pod異常排查
https://cloud.tencent.com/document/product/457/42945
2.通過Exit Code定位 Pod 異常退出原因
https://cloud.tencent.com/document/product/457/43125
3.pod異常問題排查
https://help.aliyun.com/document_detail/412618.html#6
4. easyexcel
http://easyexcel.opensource.alibaba.com/
關鍵詞:
凡注有"環球傳媒網"或電頭為"環球傳媒網"的稿件,均為環球傳媒網獨家版權所有,未經許可不得轉載或鏡像;授權轉載必須注明來源為"環球傳媒網",并保留"環球傳媒網"的電頭。