關鍵詞：k8s、jvm、高可用
1.背景
最近有運維反饋某個微服務頻繁重啟，客戶映像特別不好，需要我們盡快看一下。
聽他說完我立馬到監控平台去看這個服務的運行情況，確實重啟了很多次。對於技術人員來說，這既是壓力也是動力，大多數時候我們都是沉浸在單調的業務開發中，對自我的提升有限，久而久之可能會陷入一種舒適區，遇到這種救火案例一時間會有點無所適從，但是沒關系，畢竟......
“我只是收了火，但沒有熄爐”，借用電影中的一句話表達一下此時的心情。
2.初看日志
我當即就看這個服務的運行日志，里面有大量的oom異常，如下：
org.springframework.web.util.NestedServletException: Handler dispatch failed; nested exception is java.lang.OutOfMemoryError: GC overhead limit exceeded
整個服務基本可以說處於不可用狀態，任何請求過來幾乎都會報oom，但是這跟重啟有什么關系呢？是誰觸發了重啟呢？這里我暫時賣個關子，后面進行解答。
3.k8s健康檢查介紹
我們的服務部署在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
看完探針的相關介紹，可以基本回答上面的疑點“oom和重啟有什么關系？”，是livenessProbe的鍋，簡單描述一下為什么：
-
服務啟動；
-
k8s通過livenessProbe中配置的健康檢查Handler做定期診斷（我們配置的是HttpGetAction）；
-
由於oom所以HttpGetAction返回的http status code是500，被k8s認定為Failure（失敗）-容器未通過診斷；
-
k8s認為pod不健康，決定“殺死”它然后重新啟動。
這是服務的Deployment.yml中關於livenessProbe和restartPolicy的配置
livenessProbe:
failureThreshold: 5
httpGet:
path: /health
port: 8080
scheme: HTTP
initialDelaySeconds: 180
periodSeconds: 20
successThreshold: 1
timeoutSeconds: 10
restartPolicy: Always
4.第一次優化
內存溢出無外乎內存不夠用了，而這種不夠用又粗略分兩種情況：
-
存在內存泄漏情況，本來應該清理的對象但是並沒有被清理，比如HashMap以自定義對象作為Key時對hashCode和equals方法處理不當時可能會發生；
-
內存確實不夠用了，比如訪問量突然上來了；
由於我們這個是一個老服務，而且在多個客戶私有化環境都部署過，都沒出過這個問題，所以我直接排除了內存泄漏的情況，那就將目光投向第二種“內存確實不夠用”，通過對比訪問日志和詢問業務人員后得知最近客戶在大力推廣系統，所以訪問量確實是上來了。
“不要一開始就陷入技術人員的固化思維，認為是程序存在問題”
知道了原因那解決手段也就很粗暴了，加內存唄，分分鍾改完重新發布。
終於發布完成，我打開監控平台查看服務的運行情況，這次日志里確實沒有oom的字樣，本次優化以迅雷不及掩耳之勢這么快就完了？果然是我想多了，一陣過后我眼睜睜看着pod再次重啟，但詭異的是程序日志里沒有oom，這一次是什么造成了它重啟呢？
我使用kubectl describe pod命令查看一下pod的詳細信息，重點關注Last State，里面包括上一次的退出原因和退回code。
可以看到上一次退出是由於OOMKilled，字面意思就是pod由於內存溢出被kill，這里的OOMKilled和之前提到的程序日志中輸出的oom異常可千萬不要混為一談，如果pod 中的limit 資源設置較小，會運行內存不足導致 OOMKilled，這個是k8s層面的oom，這里借助官網的文檔順便介紹一下pod和容器中的內存限制。
以下pod內存限制內容來源於https://kubernetes.io/zh/docs/tasks/configure-pod-container/assign-memory-resource/
要為容器指定內存請求，請在容器資源清單中包含 resources：requests 字段。同理，要指定內存限制，請包含 resources：limits。
以下deployment.yml將創建一個擁有一個容器的 Pod。容器將會請求 100 MiB 內存，並且內存會被限制在 200 MiB 以內：
apiVersion: v1
kind: Pod
metadata:
name: memory-demo
namespace: mem-example
spec:
containers:
- name: memory-demo-ctr
image: polinux/stress
resources:
limits:
memory: "200Mi"
requests:
memory: "100Mi"
command: ["stress"]
args: ["--vm", "1", "--vm-bytes", "150M", "--vm-hang", "1"]
當節點擁有足夠的可用內存時，容器可以使用其請求的內存。但是，容器不允許使用超過其限制的內存。如果容器分配的內存超過其限制，該容器會成為被終止的候選容器。如果容器繼續消耗超出其限制的內存，則終止容器。如果終止的容器可以被重啟，則 kubelet 會重新啟動它，就像其他任何類型的運行時失敗一樣。
回歸到我們的場景中來講，雖然把jvm內存提高了，但是其運行環境（pod、容器）的內存限制並沒有提高，所以自然是達不到預期狀態的，解決方式也是很簡單了，提高deployment.yml中memory的限制，比如jvm中-Xmx為1G，那memory的limits至少應該大於1G。
至此，第一次優化算是真正告一段落。
5.第二次優化
第一次優化只給我們帶來了短暫的平靜，重啟次數確實有所下降，但是離我們追求的目標還是相差甚遠，所以亟需來一次更徹底的優化，來捍衛技術人員的尊嚴，畢竟我們都是頭頂別墅的人。
頭頂撐不住的時候，吃點好的補補
上一次頻繁重啟是因為內存不足導致大量的oom異常，最終k8s健康檢查機制認為pod不健康觸發了重啟，優化手段就是加大jvm和pod的內存，這一次的重啟是因為什么呢？
前面說過k8s對http形式的健康檢查地址做探測時，如果響應的狀態碼大於等於 200 且小於 400，則診斷被認為是成功的，否則就認為失敗，這里其實忽略了一種極其普遍的情況“超時”，如果超時了也一並會歸為失敗。
為什么這里才引出超時呢，因為之前日志中有大量的報錯，很直觀的可以聯想到健康檢查一定失敗，反觀這次並沒有直接證據，逼迫着發揮想象力（其實后來知道通過kubectl describe pod是可以直接觀測到超時這種情況的）。
現在我們就去反推有哪些情況會造成超時：
1.cpu 100%，這個之前確實遇到過一次，是因為宿主機cpu 100%，造成大量pod停止響應，最終大面積重啟；
2.網絡層面出了問題，比如tcp隊列被打滿，導致請求得不到處理。感興趣的可以參考我之前的文章CLOSE_WAIT導致服務假死；
3.web容器比如tomcat、jetty的線程池飽和了，這時后來的任務會堆積在線程池的隊列中；
4.jvm卡頓了，比如讓開發聞風喪膽的fullgc+stw;
以上四種只是通過我的認知列舉的，水平有限，更多情況歡迎大家補充。
現在我們一一排除，揪出元凶
1.看了監控宿主機負載正常，cpu正常，所以排除宿主機的問題；
2.ss -lnt查看tcp隊列情況，並沒有堆積、溢出情況，排除網絡層面問題；
3.jstack查看線程情況，worker線程稍多但沒有到最大值，排除線程池滿的情況；
4.jstat gcutil查看gc情況，gc比較嚴重，老年代gc執行一次平均耗時1秒左右，持續時間50s到60s左右嫌疑非常大。
通過上面的排除法暫定是gc帶來的stw導致jvm卡頓，最終導致健康檢查超時，順着這個思路我們先優化一把看看效果。
開始之前先補一張gc耗時的截圖，為了查看的直觀性，此圖由arthas的dashboard產生。
說實話我對gc是沒有什么調優經驗的，雖然看過比較多的文章，但是連紙上談兵都達不到，這次也是硬着頭皮進行一次“調參”，調優這件事真是不敢當。
具體怎么調參呢，通過上面gc耗時的分布，很直觀的拿到一個訊息，老年代的gc耗時有點長，而且次數比較頻繁，雖然圖里只有40次，但是相對於這個服務的啟動時間來講已經算頻繁了，所以目標就是降低老年代gc頻率。
從我了解的gc知識來看，老年代gc頻繁是由於對象過早晉升導致，本來應該等到age達到晉升閾值才晉升到老年代的，但是由於年輕代內存不足，所以提前晉升到了老年代，晉升率過高是導致老年代gc頻繁的主要原因，所以最終轉化為如何降低晉升率，有兩種辦法：
1.增大年輕代大小，對象在年輕代得到回收，只有生命周期長的對象才進入老年代，這樣老年代增速變慢，gc頻率也就降下來了；
2.優化程序，降低對象的生存時間，盡量在young gc階段回收對象。
由於我對這個服務並不是很熟悉，所以很自然的傾向於方法1“調整內存”，具體要怎么調整呢，這里借用一下美團技術博客中提到的一個公式來拋磚一下：
圖片內容來源於https://tech.meituan.com/2017/12/29/jvm-optimize.html
結合之前的那張gc耗時圖可以知道這個服務活躍數據大小為750m，進而得出jvm內存各區域的配比如下：
年輕代：750m*1.5 = 1125m
老年代：750m*2.5 = 1875m
接下來通過調整過的jvm內存配比重新發布驗證效果，通過一段時間的觀察，老年代gc頻率很明顯降下來了，大部分對象在新生代被回收，整體stw時間減少，運行一個多月再沒有遇到自動重啟的情況，由此也驗證了我之前的猜測“因為持續的gc導致健康檢查超時，進而觸發重啟”。
至此，第二次優化告一段落。
6.第三次優化
第二次優化確實給我們帶來了一段時間的安寧，后續的一個多月宕機率的統計不至於啪啪打架構部的臉。
剛安生幾天，這不又來活了
有運維反饋某服務在北京客戶的私有化部署環境有重啟現象，頻率基本上在2天一次，接收到這個訊息以后我們立馬重視起來，先確定兩個事：
1.個例還是普遍現象-個例，只在這個客戶環境出現；
2.會不會和前兩次優化的問題一樣，都是內存設置不合適導致的-不是，新服務，內存占用不高，gc也還好。
結合前面的兩個推論“個例”+“新服務，各項指標暫時正常“，我懷疑會不會是給這個客戶新做的某個功能存在bug，因為目前使用頻率不高，所以積攢一段時間才把服務拖垮。帶着這個疑惑我采取了守株待兔的方式，shell寫一個定時任務，每5s輸出一下關鍵指標數據，定時任務如下：
#!/bin/bash
while true ; do
/bin/sleep 5
netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}' >> netstat.log
ss -lnt >> ss.log
jstack 1 >> jstack.log
done
主要關注的指標有網絡情況、tcp隊列情況、線程棧情況。
就這樣，一天以后這個服務終於重啟了，我一一檢查netstat.log，ss.log，jstack.log這幾個文件，在jstack.log中問題原因剝繭抽絲般顯現出來，貼一段stack信息讓大家一睹為快：
"qtp1819038759-2508" #2508 prio=5 os_prio=0 tid=0x00005613a850c800 nid=0x4a39 waiting on condition [0x00007fe09ff25000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000007221fc9e8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2044)
at org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:393)
at org.apache.http.pool.AbstractConnPool.access$300(AbstractConnPool.java:70)
at org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:253)
- locked <0x00000007199cc158> (a org.apache.http.pool.AbstractConnPool$2)
at org.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:198)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:306)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:282)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:190)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at com.aliyun.oss.common.comm.DefaultServiceClient.sendRequestCore(DefaultServiceClient.java:125)
at com.aliyun.oss.common.comm.ServiceClient.sendRequestImpl(ServiceClient.java:123)
at com.aliyun.oss.common.comm.ServiceClient.sendRequest(ServiceClient.java:68)
at com.aliyun.oss.internal.OSSOperation.send(OSSOperation.java:94)
at com.aliyun.oss.internal.OSSOperation.doOperation(OSSOperation.java:149)
at com.aliyun.oss.internal.OSSOperation.doOperation(OSSOperation.java:113)
at com.aliyun.oss.internal.OSSObjectOperation.getObject(OSSObjectOperation.java:273)
at com.aliyun.oss.OSSClient.getObject(OSSClient.java:551)
at com.aliyun.oss.OSSClient.getObject(OSSClient.java:539)
at xxx.OssFileUtil.downFile(OssFileUtil.java:212)
大量的線程hang在了 org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:282
這個是做什么的呢？這個正是HttpClient中的連接池滿了的跡象，線程在等待可用連接，最終導致jetty的線程被打滿，造成服務假死，自然是不能及時響應健康檢查，最終觸發k8s的重啟策略。
最終通過排查代碼發現是由於使用阿里雲oss sdk不規范導致連接沒有按時歸還，久而久之就造成了連接池、線程池被占滿的情況，至於為什么只有北京客戶有這個問題是因為只有這一家配置了oss存儲，而且這個屬於新支持的功能，目前尚處於試點階段，所以短時間量不大，1到2天才出現一次重啟事故。
解決辦法很簡單，就是及時關閉ossObject，防止連接泄漏。
7.總結
通過前前后后一個多月的持續優化，服務的可用性又提高了一個台階，於我而言收獲頗豐，對於jvm知識又回顧了一遍，也能結合以往知識進行簡單的調參，對於k8s這一黑盒，也不再那么陌生，學習了基本的概念和一些簡單的運維指令，最后還是要說一句“工程師對於自己寫的每一行代碼都要心生敬畏，否則可能就會給公司和客戶帶來資損”。
8.推薦閱讀
