1.故障背景
20230512早上9點(diǎn)半左右，服務(wù)突然中斷造成產(chǎn)品不可用。
2.設(shè)想重啟原因：
1.時(shí)間端內(nèi)有占用大內(nèi)存操作，定時(shí)任務(wù)，造成內(nèi)存溢出或者探針失敗重啟
2.時(shí)間段內(nèi)業(yè)務(wù)高峰，內(nèi)存溢出或探針失敗重啟
3.kafka大量失敗造成應(yīng)用重啟。那么kafka失敗原因排查
3.排查過程
3.1排查應(yīng)用不可用探針失敗造成重啟
首先查看 pod狀態(tài)：
所有pod都有一次重啟記錄。
檢查pod狀態(tài)：因?yàn)閜od已經(jīng)重啟了。查看現(xiàn)在pod詳情還是可以看到探針超時(shí)。
檢查探針設(shè)置：
Pod Events中超時(shí)的是 readiness探針。解釋下探針：
readiness probes：就緒性探針，用于檢測(cè)應(yīng)用實(shí)例當(dāng)前是否可以接收請(qǐng)求，如果不能，k8s不會(huì)轉(zhuǎn)發(fā)流量。
探針說(shuō)明，探測(cè)類型
livenessProbe：kubelet 使用存活探測(cè)器來(lái)確定什么時(shí)候要重啟容器。 例如，存活探測(cè)器可以探測(cè)到應(yīng)用死鎖（應(yīng)用程序在運(yùn)行，但是無(wú)法繼續(xù)執(zhí)行后面的步驟）情況。 重啟這種狀態(tài)下的容器有助于提高應(yīng)用的可用性，即使其中存在缺陷。
readinessProbe：kubelet 使用就緒探測(cè)器可以知道容器何時(shí)準(zhǔn)備好接受請(qǐng)求流量，當(dāng)一個(gè) Pod 內(nèi)的所有容器都就緒時(shí)，才能認(rèn)為該 Pod 就緒。 這種信號(hào)的一個(gè)用途就是控制哪個(gè) Pod 作為 Service 的后端。 若 Pod 尚未就緒，會(huì)被從 Service 的負(fù)載均衡器中剔除。
startupProbe：kubelet 使用啟動(dòng)探測(cè)器來(lái)了解應(yīng)用容器何時(shí)啟動(dòng)。 如果配置了這類探測(cè)器，你就可以控制容器在啟動(dòng)成功后再進(jìn)行存活性和就緒態(tài)檢查， 確保這些存活、就緒探測(cè)器不會(huì)影響應(yīng)用的啟動(dòng)。 啟動(dòng)探測(cè)器可以用于對(duì)慢啟動(dòng)容器進(jìn)行存活性檢測(cè)，避免它們?cè)趩?dòng)運(yùn)行之前就被殺掉
也就是說(shuō)只要readiness 失敗只會(huì)標(biāo)記未就緒，從service的負(fù)載均衡中移除,并不會(huì)重啟pod。
那么readiness探針失敗造成重啟就排除了。
3.2 排查kafka報(bào)錯(cuò)造成服務(wù)重啟：
容器重啟當(dāng)前容器的日志不是故障發(fā)生的日志，需要查看歷史容器的日志。
我知道的有兩種方式可以查看歷史容器日志：
- kubectl logs podName --previous
- 找到目錄
/var/log/pod/容器id/容器名查看歷史容器日志：
懷疑kafka的最直接原因原容器的日志中：
2023-05-12 09:29:16.211 INFO 1 --- [ool-67-thread-1] i.m.c.i.binder.kafka.KafkaMetrics : Failed to bind meter: kafka.consumer.fetch.manager.fetch.size.avg [tag(client-id=consumer-hcp-fdbusiness-svc-12), tag(topic=med-pay-trade), tag(kafka-version=2.5.1), tag(spring.id=med-pay-trade.consumer.consumer-hcp-fdbusiness-svc-12)]. However, this could happen and might be restored in the next refresh.
2023-05-12 09:29:16.211 INFO 1 --- [ool-67-thread-1] i.m.c.i.binder.kafka.KafkaMetrics : Failed to bind meter: kafka.consumer.fetch.manager.records.consumed.rate [tag(client-id=consumer-hcp-fdbusiness-svc-12), tag(topic=med-pay-trade), tag(kafka-version=2.5.1), tag(spring.id=med-pay-trade.consumer.consumer-hcp-fdbusiness-svc-12)]. However, this could happen and might be restored in the next refresh.
2023-05-12 09:29:16.213 INFO 1 --- [ool-67-thread-1] i.m.c.i.binder.kafka.KafkaMetrics : Failed to bind meter: kafka.consumer.fetch.manager.bytes.consumed.rate [tag(client-id=consumer-hcp-fdbusiness-svc-12), tag(topic=med-pay-trade), tag(kafka-version=2.5.1), tag(spring.id=med-pay-trade.consumer.consumer-hcp-fdbusiness-svc-12)]. However, this could happen and might be restored in the next refresh.
2023-05-12 09:29:16.214 INFO 1 --- [ool-67-thread-1] i.m.c.i.binder.kafka.KafkaMetrics : Failed to bind meter: kafka.consumer.fetch.manager.records.per.request.avg [tag(client-id=consumer-hcp-fdbusiness-svc-12), tag(topic=med-pay-trade), tag(kafka-version=2.5.1), tag(spring.id=med-pay-trade.consumer.consumer-hcp-fdbusiness-svc-12)]. However, this could happen and might be restored in the next refresh.
2023-05-12 09:29:16.218 INFO 1 --- [ool-67-thread-1] i.m.c.i.binder.kafka.KafkaMetrics : Failed to bind meter: kafka.consumer.fetch.manager.fetch.size.max [tag(client-id=consumer-hcp-fdbusiness-svc-12), tag(topic=med-pay-trade), tag(kafka-version=2.5.1), tag(spring.id=med-pay-trade.consumer.consumer-hcp-fdbusiness-svc-12)]. However, this could happen and might be restored in the next refresh.
2023-05-12 09:29:16.220 INFO 1 --- [ool-67-thread-1] i.m.c.i.binder.kafka.KafkaMetrics : Failed to bind meter: kafka.consumer.fetch.manager.records.consumed.total [tag(client-id=consumer-hcp-fdbusiness-svc-12), tag(topic=med-pay-trade), tag(kafka-version=2.5.1), tag(spring.id=med-pay-trade.consumer.consumer-hcp-fdbusiness-svc-12)]. However, this could happen and might be restored in the next refresh.
2023-05-12 09:29:16.370 ERROR 1 --- [io-8080-exec-22] c.z.h.f.e.DefaultExceptionHandler : System exception found:
reactor.core.Exceptions$ReactiveException: java.lang.InterruptedException
java.lang.NullPointerException: null
at org.springframework.web.util.UrlPathHelper.removeJsessionid(UrlPathHelper.java:542)
2023-05-12 09:29:17.216 INFO 1 --- [extShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor : Shutting down ExecutorService
2023-05-12 09:29:17.244 INFO 1 --- [extShutdownHook] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'default'
2023-05-12 09:29:17.247 INFO 1 --- [extShutdownHook] o.s.s.c.ThreadPoolTaskScheduler : Shutting down ExecutorService 'taskScheduler'
2023-05-12 09:29:17.248 INFO 1 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown initiated...
2023-05-12 09:29:17.256 INFO 1 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Shutdown completed.
2023-05-12 09:29:17.260 INFO 1 --- [extShutdownHook] com.netflix.discovery.DiscoveryClient : Shutting down DiscoveryClient ...
2023-05-12 09:29:20.261 WARN 1 --- [scoveryClient-1] c.netflix.discovery.TimedSupervisorTask : task supervisor shutting down, can't accept the task
2023-05-12 09:29:20.261 INFO 1 --- [extShutdownHook] com.netflix.discovery.DiscoveryClient : Unregistering ...
2023-05-12 09:29:20.267 INFO 1 --- [extShutdownHook] com.netflix.discovery.DiscoveryClient : DiscoveryClient_HCP-FDBUSINESS-SVC/hcp-fdbusiness-svc-5457d99c89-94ff4:hcp-fdbusiness-svc - deregister status: 200
2023-05-12 09:29:20.275 INFO 1 --- [extShutdownHook] com.netflix.discovery.DiscoveryClient : Completed shut down of DiscoveryClient
Kafka執(zhí)行rebalence 后就馬上報(bào)錯(cuò)，然后就是各種shutdown了。日志再往前翻，也有rebalence，并不會(huì)直接造成服務(wù)被干掉。 而且rebalence并不是很頻繁。Rebalence是kafka非常常見的動(dòng)作，只會(huì)短暫無(wú)法消費(fèi)消息，很快就會(huì)恢復(fù)正常。
到這里就排除了kafka的原因
3.3故障時(shí)間段內(nèi)業(yè)務(wù)高峰。
從主要業(yè)務(wù)數(shù)據(jù)檢查是否異常：
核心的簽約業(yè)務(wù)，并沒有異常數(shù)據(jù)量情況。同時(shí)檢查定時(shí)任務(wù)也沒有發(fā)現(xiàn)異常數(shù)據(jù)量操作。
所以排除故障時(shí)間段內(nèi)業(yè)務(wù)高峰
4.系統(tǒng)原因排查
切換到pod所在物理主機(jī)查看linux操作系統(tǒng)日志:/var/log/messages
May 12 09:28:39 kn-56 kubelet: W0512 09:28:39.680915 21612 eviction_manager.go:330] eviction manager: attempting to reclaim memory
May 12 09:28:39 kn-56 kubelet: I0512 09:28:39.682970 21612 eviction_manager.go:341] eviction manager: must evict pod(s) to reclaim memory
May 12 09:28:39 kn-56 kubelet: I0512 09:28:39.684012 21612 eviction_manager.go:359] eviction manager: pods ranked for eviction: redis-3_med-rhin(d756304c-c34f-4aec-856e-589f94bcccb8), nuclein-svc-40_med-rhin(b23e48a9-1533-4105-9b2b-a7301943ce8d), hcp-fdbusiness-svc-5457d99c89-94ff4_med-rhin(6505583b-894e-4d31-a31a-67d6b9c57e81), nuclein-trip-svc-41_med-rhin(5b9d8572-d645-44ff-b794-8b6e4c07a003), nuclein-trip-svc-57_med-rhin(5332fd71-c56a-4198-886e-f029410c77d8), nuclein-weixin-6cb545fd44-xpbtf_med-rhin(f545f1cf-94fc-445a-81a0-313193a95246), rhin-eureka-1_med-rhin(bdec2717-0868-4ab6-a49b-db18a8d0a8f1), nginx-ingress-controller-dfkw5_ingress-nginx(b6eade3b-cc4e-44d8-91b1-01fefad4d8d7), hcp-wechat-portal-6d4879db4b-t2mp7_med-rhin(c603056d-91b3-4070-a868-24aefb1b1963), nuclein-manage-tender-5c6fc5d796-26nrv_med-rhin(f7876802-efb0-4370-a466-859906c1c4f3), calico-node-djgrl_kube-system(4a0c6908-f716-4cc7-92e6-2c3f41d9a253), kube-proxy-m8xq5_kube-system(96a786d7-aaa2-40ca-907e-bb392c457ea9), node-exporter-767hm_monitoring(c315e60c-2323-4775-a28b-e7ba11dc091f), filebeat-filebeat-vd8ld_med-rhin(a5cefe0a-38fb-48ff-8555-e00cb6cb0e38)
May 12 09:28:39 kn-56 dockerd: time=“2023-05-12T09:28:39.829704332+08:00” level=info msg=“Container ad6332e6c7e6fe491fc2f79d576dea8d1dd48985553c595414e1686abd3faa8d failed to exit within 0 seconds of signal 15 - using the force”
驅(qū)逐pod以回收內(nèi)存。
在阿里云微博中找到了k8s驅(qū)逐pod原因：
Kubernetes用于處理低RAM和磁盤空間情況的驅(qū)逐策略：https://www.alibabacloud.com/blog/kubernetes-eviction-policies-for-handling-low-ram-and-disk-space-situations—part-1_595202
定義了低RAM和低磁盤空間的閾值，當(dāng)達(dá)到這些閾值時(shí)，Kubernetes驅(qū)逐策略就會(huì)起作用。Kubernetes將Pods從節(jié)點(diǎn)中逐出，以解決低RAM和低磁盤空間的問題。
文章介紹有兩種情況會(huì)導(dǎo)致pod驅(qū)逐：
-
RAM和磁盤空間超過一定閾值就會(huì)開始驅(qū)逐pod
檢查節(jié)點(diǎn)的磁盤使用量：
Data目錄下的空間還有很多。 pod運(yùn)行時(shí)的日志文件都是寫入這個(gè)目錄下的。磁盤的使用量一般只會(huì)不斷累積，越來(lái)越大。
所以排除磁盤使用量不足問題所以磁盤超過閾值的情況 -
檢查內(nèi)存使用量情況：
目前看，可用量還是比較多的。節(jié)點(diǎn)內(nèi)存一共64G 可用量有13G
然后問題就是內(nèi)存使用量了。然而一個(gè)節(jié)點(diǎn)上部署的應(yīng)用是不固定的，每個(gè)應(yīng)用占用的內(nèi)存大小也不是固定的。所以大概率還是節(jié)點(diǎn)上的內(nèi)存使用量超過閾值觸發(fā)了Kubernetes驅(qū)逐策略生效。
5.結(jié)論
最終本次故障的原因最終定位到：內(nèi)存使用量問題上。節(jié)點(diǎn)上的內(nèi)存使用量超過閾值觸發(fā)了Kubernetes驅(qū)逐策略生效。文章來(lái)源：http://www.zghlxwxcb.cn/news/detail-618047.html
優(yōu)化建議：文章來(lái)源地址http://www.zghlxwxcb.cn/news/detail-618047.html
- k8s配置調(diào)優(yōu)：
給每個(gè)應(yīng)用加上資源限制。K8s的調(diào)度策略是根據(jù)request和limit來(lái)判斷是否應(yīng)該調(diào)度到目標(biāo)節(jié)點(diǎn)。給關(guān)鍵節(jié)點(diǎn)配置親和與反親和。 - Liunx系統(tǒng)參數(shù)調(diào)優(yōu)：
調(diào)高系統(tǒng)進(jìn)程id數(shù)量:/etc/sysctl.conf kernel.pid_max
調(diào)高文件句柄數(shù)：/etc/security/limits.conf
限制一個(gè)進(jìn)程可以擁有的VMA(虛擬內(nèi)存區(qū)域)的數(shù)量：/etc/sysctl.conf max_map_count
調(diào)整內(nèi)存分配策略：/etc/sysctl.conf vm.overcommit_memory：0 表示內(nèi)核將檢查是否有足夠的可用內(nèi)存供應(yīng)用進(jìn)程使用；如果有足夠的可用內(nèi)存，內(nèi)存申請(qǐng)?jiān)试S；否則，內(nèi)存申請(qǐng)失敗，并把錯(cuò)誤返回給應(yīng)用進(jìn)程。
到了這里，關(guān)于k8s服務(wù)突然中斷重啟原因排查-eviction manager: must evict pod(s) to reclaim memory的文章就介紹完了。如果您還想了解更多內(nèi)容，請(qǐng)?jiān)谟疑辖撬阉鱐OY模板網(wǎng)以前的文章或繼續(xù)瀏覽下面的相關(guān)文章，希望大家以后多多支持TOY模板網(wǎng)！
