
專注用戶體驗(yàn)設(shè)計(jì)與開發(fā)
-
商務(wù)合作
- 郵箱:123456789@qq.com
- 手機(jī):15323711532
- 座機(jī):0755-84185494
- 地址:廣東省深圳市龍崗區(qū)布吉中興路21號基業(yè)大廈
Copyright ? 2015 深圳市鑫惠廣網(wǎng)絡(luò)科技有限公司 粵ICP備2023111395號
最近有運(yùn)維反饋某個(gè)微服務(wù)頻繁重啟,客戶映像特別不好,需要我們盡快看一下。
聽他說完我立馬到監(jiān)控平臺(tái)去看這個(gè)服務(wù)的運(yùn)行情況,確實(shí)重啟了很多次。對于技術(shù)人員來說,這既是壓力也是動(dòng)力,大多數(shù)時(shí)候我們都是沉浸在單調(diào)的業(yè)務(wù)開發(fā)中,對自我的提升有限,久而久之可能會(huì)陷入一種舒適區(qū),遇到這種救火案例一時(shí)間會(huì)有點(diǎn)無所適從,但是沒關(guān)系,畢竟......
“我只是收了火,但沒有熄爐”,借用電影中的一句話表達(dá)一下此時(shí)的心情。
2.初看日志
我當(dāng)即就看這個(gè)服務(wù)的運(yùn)行日志,里面有大量的oom異常,如下:
org.springframework.web.util.NestedServletException: Handlerdispatchfailed; nestedexceptionisjava.lang.OutOfMemoryError: GCoverheadlimitexceeded
整個(gè)服務(wù)基本可以說處于不可用狀態(tài),任何請求過來幾乎都會(huì)報(bào)oom,但是這跟重啟有什么關(guān)系呢?是誰觸發(fā)了重啟呢?這里我暫時(shí)賣個(gè)關(guān)子,后面進(jìn)行解答。
3.k8s健康檢查介紹
我們的服務(wù)部署在k8s中,k8s可以對容器執(zhí)行定期的診斷,要執(zhí)行診斷,kubelet 調(diào)用由容器實(shí)現(xiàn)的 Handler (處理程序)。有三種類型的處理程序:
每次探測都將獲得以下三種結(jié)果之一:
針對運(yùn)行中的容器,kubelet 可以選擇是否執(zhí)行以下三種探針,以及如何針對探測結(jié)果作出反應(yīng):
以上探針介紹內(nèi)容來源于https://kubernetes.io/zh/docs/concepts/workloads/pods/pod-lifecycle/#container-probes
看完探針的相關(guān)介紹,可以基本回答上面的疑點(diǎn)**“oom和重啟有什么關(guān)系?”,**是livenessProbe的鍋,簡單描述一下為什么:
這是服務(wù)的Deployment.yml中關(guān)于livenessProbe和restartPolicy的配置
livenessProbe:failureThreshold:5httpGet:path:/healthport:8080scheme:HTTPinitialDelaySeconds:180periodSeconds:20successThreshold:1timeoutSeconds:10restartPolicy:Always
4.第一次優(yōu)化
內(nèi)存溢出無外乎內(nèi)存不夠用了,而這種不夠用又粗略分兩種情況:
由于我們這個(gè)是一個(gè)老服務(wù),而且在多個(gè)客戶私有化環(huán)境都部署過,都沒出過這個(gè)問題,所以我直接排除了內(nèi)存泄漏的情況,那就將目光投向第二種“內(nèi)存確實(shí)不夠用”,通過對比訪問日志和詢問業(yè)務(wù)人員后得知最近客戶在大力推廣系統(tǒng),所以訪問量確實(shí)是上來了。
“不要一開始就陷入技術(shù)人員的固化思維,認(rèn)為是程序存在問題”
知道了原因那解決手段也就很粗暴了,加內(nèi)存唄,分分鐘改完重新發(fā)布。
終于發(fā)布完成,我打開監(jiān)控平臺(tái)查看服務(wù)的運(yùn)行情況,這次日志里確實(shí)沒有oom的字樣,本次優(yōu)化以迅雷不及掩耳之勢這么快就完了?果然是我想多了,一陣過后我眼睜睜看著pod再次重啟,但詭異的是程序日志里沒有oom,這一次是什么造成了它重啟呢?
我使用kubectl describe pod命令查看一下pod的詳細(xì)信息,重點(diǎn)關(guān)注Last State,里面包括上一次的退出原因和退回code。
可以看到上一次退出是由于OOMKilled,字面意思就是pod由于內(nèi)存溢出被kill,這里的OOMKilled和之前提到的程序日志中輸出的oom異常可千萬不要混為一談,如果pod 中的limit 資源設(shè)置較小,會(huì)運(yùn)行內(nèi)存不足導(dǎo)致 OOMKilled,這個(gè)是k8s層面的oom,這里借助官網(wǎng)的文檔順便介紹一下pod和容器中的內(nèi)存限制。
以下pod內(nèi)存限制內(nèi)容來源于https://kubernetes.io/zh/docs/tasks/configure-pod-container/assign-memory-resource/
*要為容器指定內(nèi)存請求,請?jiān)谌萜髻Y源清單中包含 *resources:requests字段。同理,要指定內(nèi)存限制,請包含 resources:limits。
以下deployment.yml將創(chuàng)建一個(gè)擁有一個(gè)容器的 Pod。容器將會(huì)請求 100 MiB 內(nèi)存,并且內(nèi)存會(huì)被限制在 200 MiB 以內(nèi):
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"]
當(dāng)節(jié)點(diǎn)擁有足夠的可用內(nèi)存時(shí),容器可以使用其請求的內(nèi)存。但是,容器不允許使用超過其限制的內(nèi)存。如果容器分配的內(nèi)存超過其限制,該容器會(huì)成為被終止的候選容器。如果容器繼續(xù)消耗超出其限制的內(nèi)存,則終止容器。如果終止的容器可以被重啟,則 kubelet 會(huì)重新啟動(dòng)它,就像其他任何類型的運(yùn)行時(shí)失敗一樣。
回歸到我們的場景中來講,雖然把jvm內(nèi)存提高了,但是其運(yùn)行環(huán)境(pod、容器)的內(nèi)存限制并沒有提高,所以自然是達(dá)不到預(yù)期狀態(tài)的,解決方式也是很簡單了,提高deployment.yml中memory的限制,比如jvm中-Xmx為1G,那memory的limits至少應(yīng)該大于1G。
至此,第一次優(yōu)化算是真正告一段落。
5.第二次優(yōu)化
第一次優(yōu)化只給我們帶來了短暫的平靜,重啟次數(shù)確實(shí)有所下降,但是離我們追求的目標(biāo)還是相差甚遠(yuǎn),所以亟需來一次更徹底的優(yōu)化,來捍衛(wèi)技術(shù)人員的尊嚴(yán),畢竟我們都是頭頂別墅的人。
頭頂撐不住的時(shí)候,吃點(diǎn)好的補(bǔ)補(bǔ)
上一次頻繁重啟是因?yàn)閮?nèi)存不足導(dǎo)致大量的oom異常,最終k8s健康檢查機(jī)制認(rèn)為pod不健康觸發(fā)了重啟,優(yōu)化手段就是加大jvm和pod的內(nèi)存,這一次的重啟是因?yàn)槭裁茨兀?/p>
前面說過k8s對http形式的健康檢查地址做探測時(shí),如果響應(yīng)的狀態(tài)碼大于等于 200 且小于 400,則診斷被認(rèn)為是成功的,否則就認(rèn)為失敗,這里其實(shí)忽略了一種極其普遍的情況“超時(shí)”,如果超時(shí)了也一并會(huì)歸為失敗。
為什么這里才引出超時(shí)呢,因?yàn)橹叭罩局杏写罅康膱?bào)錯(cuò),很直觀的可以聯(lián)想到健康檢查一定失敗,反觀這次并沒有直接證據(jù),逼迫著發(fā)揮想象力(其實(shí)后來知道通過kubectl describe pod是可以直接觀測到超時(shí)這種情況的)。
現(xiàn)在我們就去反推有哪些情況會(huì)造成超時(shí):
1.cpu 100%,這個(gè)之前確實(shí)遇到過一次,是因?yàn)樗拗鳈C(jī)cpu 100%,造成大量pod停止響應(yīng),最終大面積重啟;
2.網(wǎng)絡(luò)層面出了問題,比如tcp隊(duì)列被打滿,導(dǎo)致請求得不到處理。
3.web容器比如tomcat、jetty的線程池飽和了,這時(shí)后來的任務(wù)會(huì)堆積在線程池的隊(duì)列中;
4.jvm卡頓了,比如讓開發(fā)聞風(fēng)喪膽的fullgc+stw;
以上四種只是通過我的認(rèn)知列舉的,水平有限,更多情況歡迎大家補(bǔ)充。
現(xiàn)在我們一一排除,揪出元兇
1.看了監(jiān)控宿主機(jī)負(fù)載正常,cpu正常,所以排除宿主機(jī)的問題;
2.ss -lnt查看tcp隊(duì)列情況,并沒有堆積、溢出情況,排除網(wǎng)絡(luò)層面問題;
3.jstack查看線程情況,worker線程稍多但沒有到最大值,排除線程池滿的情況;
4.jstat gcutil查看gc情況,gc比較嚴(yán)重,老年代gc執(zhí)行一次平均耗時(shí)1秒左右,持續(xù)時(shí)間50s到60s左右嫌疑非常大。
通過上面的排除法暫定是gc帶來的stw導(dǎo)致jvm卡頓,最終導(dǎo)致健康檢查超時(shí),順著這個(gè)思路我們先優(yōu)化一把看看效果。
開始之前先補(bǔ)一張gc耗時(shí)的截圖,為了查看的直觀性,此圖由arthas的dashboard產(chǎn)生。
說實(shí)話我對gc是沒有什么調(diào)優(yōu)經(jīng)驗(yàn)的,雖然看過比較多的文章,但是連紙上談兵都達(dá)不到,這次也是硬著頭皮進(jìn)行一次“調(diào)參”,調(diào)優(yōu)這件事真是不敢當(dāng)。
具體怎么調(diào)參呢,通過上面gc耗時(shí)的分布,很直觀的拿到一個(gè)訊息,老年代的gc耗時(shí)有點(diǎn)長,而且次數(shù)比較頻繁,雖然圖里只有40次,但是相對于這個(gè)服務(wù)的啟動(dòng)時(shí)間來講已經(jīng)算頻繁了,所以目標(biāo)就是降低老年代gc頻率。
從我了解的gc知識(shí)來看,老年代gc頻繁是由于對象過早晉升導(dǎo)致,本來應(yīng)該等到age達(dá)到晉升閾值才晉升到老年代的,但是由于年輕代內(nèi)存不足,所以提前晉升到了老年代,晉升率過高是導(dǎo)致老年代gc頻繁的主要原因,所以最終轉(zhuǎn)化為如何降低晉升率,有兩種辦法:
1.增大年輕代大小,對象在年輕代得到回收,只有生命周期長的對象才進(jìn)入老年代,這樣老年代增速變慢,gc頻率也就降下來了;
2.優(yōu)化程序,降低對象的生存時(shí)間,盡量在young gc階段回收對象。
由于我對這個(gè)服務(wù)并不是很熟悉,所以很自然的傾向于方法1“調(diào)整內(nèi)存”,具體要怎么調(diào)整呢,這里借用一下美團(tuán)技術(shù)博客中提到的一個(gè)公式來拋磚一下:
圖片內(nèi)容來源于https://tech.meituan.com/2017/12/29/jvm-optimize.html
結(jié)合之前的那張gc耗時(shí)圖可以知道這個(gè)服務(wù)活躍數(shù)據(jù)大小為750m,進(jìn)而得出jvm內(nèi)存各區(qū)域的配比如下:
年輕代:750m*1.5 = 1125m
老年代:750m*2.5 = 1875m
接下來通過調(diào)整過的jvm內(nèi)存配比重新發(fā)布驗(yàn)證效果,通過一段時(shí)間的觀察,老年代gc頻率很明顯降下來了,大部分對象在新生代被回收,整體stw時(shí)間減少,運(yùn)行一個(gè)多月再?zèng)]有遇到自動(dòng)重啟的情況,由此也驗(yàn)證了我之前的猜測“因?yàn)槌掷m(xù)的gc導(dǎo)致健康檢查超時(shí),進(jìn)而觸發(fā)重啟”。
至此,第二次優(yōu)化告一段落。
6.第三次優(yōu)化
第二次優(yōu)化確實(shí)給我們帶來了一段時(shí)間的安寧,后續(xù)的一個(gè)多月宕機(jī)率的統(tǒng)計(jì)不至于啪啪打架構(gòu)部的臉。
剛安生幾天,這不又來活了
有運(yùn)維反饋某服務(wù)在北京客戶的私有化部署環(huán)境有重啟現(xiàn)象,頻率基本上在2天一次,接收到這個(gè)訊息以后我們立馬重視起來,先確定兩個(gè)事:
1.個(gè)例還是普遍現(xiàn)象-個(gè)例,只在這個(gè)客戶環(huán)境出現(xiàn);
2.會(huì)不會(huì)和前兩次優(yōu)化的問題一樣,都是內(nèi)存設(shè)置不合適導(dǎo)致的-不是,新服務(wù),內(nèi)存占用不高,gc也還好。
結(jié)合前面的兩個(gè)推論**“個(gè)例”+“新服務(wù),各項(xiàng)指標(biāo)暫時(shí)正?!埃?*我懷疑會(huì)不會(huì)是給這個(gè)客戶新做的某個(gè)功能存在bug,因?yàn)槟壳笆褂妙l率不高,所以積攢一段時(shí)間才把服務(wù)拖垮。帶著這個(gè)疑惑我采取了守株待兔的方式,shell寫一個(gè)定時(shí)任務(wù),每5s輸出一下關(guān)鍵指標(biāo)數(shù)據(jù),定時(shí)任務(wù)如下:
#!/bin/bash whiletrue; 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
主要關(guān)注的指標(biāo)有網(wǎng)絡(luò)情況、tcp隊(duì)列情況、線程棧情況。
就這樣,一天以后這個(gè)服務(wù)終于重啟了,我一一檢查netstat.log,ss.log,jstack.log這幾個(gè)文件,在jstack.log中問題原因剝繭抽絲般顯現(xiàn)出來,貼一段stack信息讓大家一睹為快:
"qtp1819038759-2508"#2508 prio=5 os_prio=0 tid=0x00005613a850c800 nid=0x4a39 waiting on condition [0x00007fe09ff25000]java.lang.Thread.State: WAITING (parking)atsun.misc.Unsafe.park(Native Method)-parking to wait for <0x00000007221fc9e8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)atjava.util.concurrent.locks.LockSupport.park(LockSupport.java:175)atjava.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2044)atorg.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:393)atorg.apache.http.pool.AbstractConnPool.access$300(AbstractConnPool.java:70)atorg.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:253)-locked <0x00000007199cc158> (a org.apache.http.pool.AbstractConnPool$2)atorg.apache.http.pool.AbstractConnPool$2.get(AbstractConnPool.java:198)atorg.apache.http.impl.conn.PoolingHttpClientConnectionManager.leaseConnection(PoolingHttpClientConnectionManager.java:306)atorg.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:282)atorg.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:190)atorg.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)atorg.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)atorg.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)atorg.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)atcom.aliyun.oss.common.comm.DefaultServiceClient.sendRequestCore(DefaultServiceClient.java:125)atcom.aliyun.oss.common.comm.ServiceClient.sendRequestImpl(ServiceClient.java:123)atcom.aliyun.oss.common.comm.ServiceClient.sendRequest(ServiceClient.java:68)atcom.aliyun.oss.internal.OSSOperation.send(OSSOperation.java:94)atcom.aliyun.oss.internal.OSSOperation.doOperation(OSSOperation.java:149)atcom.aliyun.oss.internal.OSSOperation.doOperation(OSSOperation.java:113)atcom.aliyun.oss.internal.OSSObjectOperation.getObject(OSSObjectOperation.java:273)atcom.aliyun.oss.OSSClient.getObject(OSSClient.java:551)atcom.aliyun.oss.OSSClient.getObject(OSSClient.java:539)atxxx.OssFileUtil.downFile(OssFileUtil.java:212)
大量的線程hang在了 org.apache.http.impl.conn.PoolingHttpClientConnectionManager$1.get(PoolingHttpClientConnectionManager.java:282
這個(gè)是做什么的呢?這個(gè)正是HttpClient中的連接池滿了的跡象,線程在等待可用連接,最終導(dǎo)致jetty的線程被打滿,造成服務(wù)假死,自然是不能及時(shí)響應(yīng)健康檢查,最終觸發(fā)k8s的重啟策略。
最終通過排查代碼發(fā)現(xiàn)是由于使用阿里云oss sdk不規(guī)范導(dǎo)致連接沒有按時(shí)歸還,久而久之就造成了連接池、線程池被占滿的情況,至于為什么只有北京客戶有這個(gè)問題是因?yàn)橹挥羞@一家配置了oss存儲(chǔ),而且這個(gè)屬于新支持的功能,目前尚處于試點(diǎn)階段,所以短時(shí)間量不大,1到2天才出現(xiàn)一次重啟事故。
解決辦法很簡單,就是及時(shí)關(guān)閉ossObject,防止連接泄漏。
7.總結(jié)
通過前前后后一個(gè)多月的持續(xù)優(yōu)化,服務(wù)的可用性又提高了一個(gè)臺(tái)階,于我而言收獲頗豐,對于jvm知識(shí)又回顧了一遍,也能結(jié)合以往知識(shí)進(jìn)行簡單的調(diào)參,對于k8s這一黑盒,也不再那么陌生,學(xué)習(xí)了基本的概念和一些簡單的運(yùn)維指令,最后還是要說一句“工程師對于自己寫的每一行代碼都要心生敬畏,否則可能就會(huì)給公司和客戶帶來資損”。
專注用戶體驗(yàn)設(shè)計(jì)與開發(fā)
Copyright ? 2015 深圳市鑫惠廣網(wǎng)絡(luò)科技有限公司 粵ICP備2023111395號