記錄一次線(xiàn)上服務(wù)OOM(內(nèi)存溢出)排查
當(dāng)前位置:點(diǎn)晴教程→知識(shí)管理交流
→『 技術(shù)文檔交流 』
OOMOOM是"Out of Memory"的縮寫(xiě),意為內(nèi)存不足或內(nèi)存溢出。在計(jì)算機(jī)科學(xué)中,當(dāng)一個(gè)程序嘗試使用比系統(tǒng)可用內(nèi)存更多的內(nèi)存時(shí),就會(huì)發(fā)生OOM錯(cuò)誤。這種情況通常發(fā)生在程序試圖分配內(nèi)存空間,但操作系統(tǒng)無(wú)法滿(mǎn)足請(qǐng)求,因?yàn)樗呀?jīng)沒(méi)有足夠的空閑內(nèi)存來(lái)提供給該程序。 老實(shí)說(shuō),在我印象里OOM問(wèn)題只存在于網(wǎng)上案例中,練習(xí)編碼時(shí)常兩年半,還是第一次遇到。不過(guò)既然遇到了,那就要盡快排查問(wèn)題并解決掉,不然真要和群里大哥說(shuō)的一樣:要領(lǐng)盒飯了。 問(wèn)題下午兩點(diǎn)新版本上線(xiàn),其中一個(gè)消費(fèi)者服務(wù)的內(nèi)存增長(zhǎng)速度異常迅速,在短短五分鐘內(nèi)就用完了2G內(nèi)存并自動(dòng)重啟了pod,之后又在五分鐘內(nèi)OOM了,在四十分鐘內(nèi)服務(wù)的pod已經(jīng)重啟了八十幾次,要知道我們之前這個(gè)消費(fèi)者服務(wù)正常運(yùn)行時(shí)候只用了不到500M。 分析首先進(jìn)行初步分析,這是一個(gè)消費(fèi)者服務(wù)并且新版本的需求中并沒(méi)有新增消費(fèi)topic,并且業(yè)務(wù)量也沒(méi)有大的波動(dòng),不存在是業(yè)務(wù)訪(fǎng)問(wèn)量驟增導(dǎo)致OOM,所以極大概率會(huì)是代碼問(wèn)題。當(dāng)然,每一個(gè)版本的新代碼都非常多,需求也比較龐雜,直接去看代碼肯定是不行的,這時(shí)候就要麻煩部門(mén)的運(yùn)維大佬了,讓他給我們dump一下,給出一個(gè)內(nèi)存溢出時(shí)的性能記錄文件,通過(guò)這個(gè)文件可以分析內(nèi)存分配、線(xiàn)程創(chuàng)建、CPU使用、阻塞、程序詳細(xì)跟蹤信息等。 我這里使用的Go語(yǔ)言開(kāi)發(fā),一般用pprof文件進(jìn)行分析,運(yùn)維給出的文件有以下6個(gè):
內(nèi)存OOM,那最重要的當(dāng)然是mem文件,也就是內(nèi)存分配剖析數(shù)據(jù),不過(guò)很不幸,服務(wù)重啟速度太快了,運(yùn)維大佬dump的時(shí)候正好處于服務(wù)剛重啟的時(shí)候,所以mem文件中顯示的內(nèi)存才占用不到20M,并且占比上也沒(méi)看出有什么問(wèn)題。想讓運(yùn)維再幫忙dump一下內(nèi)存快要OOM的時(shí)候,但是為了線(xiàn)上服務(wù)的穩(wěn)定性版本已經(jīng)回退了,無(wú)法重新dump,只能從其他幾個(gè)文件中查找問(wèn)題了。 除了內(nèi)存占用分析,在性能問(wèn)題分析中CPU占用分析也是極為重要的一環(huán),這一查看就有意思了,CPU總的使用率雖然不高,但是這個(gè)占比就比較奇怪了。第一占比的 之后繼續(xù)查看互斥鎖的情況,其實(shí)這個(gè)文件在目前這種情況下排查的價(jià)值已經(jīng)不大了,因?yàn)槌霈F(xiàn)問(wèn)題的是內(nèi)存溢出而不是CPU占用率,并且CPU占用率確實(shí)不是很高,而且Go中是有檢索死鎖的機(jī)制,大部分死鎖是能夠被Go發(fā)現(xiàn)并報(bào)一個(gè) 接下來(lái)查看阻塞操作的分析情況,從解析結(jié)果中可以看出,select的阻塞時(shí)間遙遙領(lǐng)先,select出現(xiàn)這種情況只會(huì)是存在case但是沒(méi)有default的時(shí)候,當(dāng)所有case不符合的時(shí)候,負(fù)責(zé)這個(gè)select的goroutine會(huì)阻塞住直到存在符合的case出現(xiàn)才會(huì)喚醒繼續(xù)走下去,當(dāng)時(shí)我看到這我滿(mǎn)腦子問(wèn)號(hào),誰(shuí)家好人select不加default啊? 再查看線(xiàn)程創(chuàng)建情況,由于pod剛啟動(dòng)不久,所以這個(gè)文件也看不出什么東西,很正常的線(xiàn)程創(chuàng)建。 看到這里還是沒(méi)能定位到問(wèn)題所在,但是別急,我們還有最重要的文件還沒(méi)看,那就是trace文件,它可以記錄程序執(zhí)行的詳細(xì)跟蹤信息,包括函數(shù)調(diào)用、Goroutine 的創(chuàng)建和調(diào)度,使用go自帶的pprof分析工具打開(kāi)trace文件
會(huì)出現(xiàn)以下本地頁(yè)面: 在Goroutine分析中,可以鎖定真正的問(wèn)題所在了,在go-zero的core包下的collection文件在不到一秒內(nèi)創(chuàng)建了兩萬(wàn)多的Goroutine,雖然兩萬(wàn)多數(shù)量不多,但是這個(gè)速度十分異常,最重要的是這個(gè)定時(shí)輪就很奇怪,這個(gè)項(xiàng)目中根本沒(méi)有定時(shí)任務(wù),接下來(lái)就很容易查詢(xún)了,只要查找這次提交的代碼中哪里使用到了collection包。 經(jīng)過(guò)一番全局搜索后,最終確定了問(wèn)題代碼:
在新上線(xiàn)的版本中只有這一處用到了collection包,原本這里的意思是將建立一個(gè)緩存放到上下文中去傳遞,但是乍一看我沒(méi)有看出有什么問(wèn)題,過(guò)期時(shí)間也設(shè)置了,按照我原有理解過(guò)期時(shí)間到了就會(huì)自動(dòng)釋放掉,為什么還是會(huì)內(nèi)存溢出了?但是我忽然意識(shí)到應(yīng)該不是緩存引發(fā)的內(nèi)存溢出,可能是協(xié)程過(guò)多引發(fā)的內(nèi)存溢出,因?yàn)橐粋€(gè)初始協(xié)程是2KB左右,如果數(shù)量過(guò)多也會(huì)造成內(nèi)存不夠。 為了探究根本原因,我點(diǎn)進(jìn)了collection包的源碼進(jìn)行查看,在其中 之后點(diǎn)進(jìn)去這個(gè)方法進(jìn)一步查看,可以看到這個(gè)定時(shí)輪的結(jié)構(gòu)體,里面包含了四個(gè)channel以及一些其他數(shù)據(jù)結(jié)構(gòu),粗略估計(jì)這一個(gè) 但是這個(gè)定時(shí)輪為什么會(huì)創(chuàng)建那么多呢?為什么不會(huì)關(guān)閉,按理說(shuō)go-zero的源碼不應(yīng)該會(huì)有這么大的漏洞,繼續(xù)查看這個(gè)定時(shí)輪的 答案是會(huì)在程序停止運(yùn)行的時(shí)候進(jìn)行調(diào)用。所以如果程序仍在運(yùn)行,就會(huì)有無(wú)限制的協(xié)程創(chuàng)建定時(shí)輪,這時(shí)候定時(shí)輪因?yàn)闊o(wú)法關(guān)閉所以協(xié)程也不會(huì)進(jìn)行銷(xiāo)毀,有點(diǎn)類(lèi)似于守護(hù)線(xiàn)程,所以在協(xié)程無(wú)限制的創(chuàng)建下最終導(dǎo)致了線(xiàn)上內(nèi)存OOM了。 解決那是不是說(shuō)明go-zero的這塊源碼存在問(wèn)題?其實(shí)不是的,是我們使用方法錯(cuò)誤,正確的使用方法不應(yīng)該將緩存創(chuàng)建在上下文中,而應(yīng)該創(chuàng)建一個(gè)全局緩存,讓所有的上下文都公用這一個(gè)緩存,這樣就不會(huì)發(fā)生定時(shí)輪無(wú)限創(chuàng)建的問(wèn)題。 后續(xù)將這塊緩存放到了全局中,之后再重新發(fā)布觀(guān)察了一小時(shí)左右,服務(wù)內(nèi)存穩(wěn)定在了500M以下,與以往服務(wù)消耗內(nèi)存幾乎一致。 歷時(shí)兩小時(shí)戰(zhàn)斗,終于免于“領(lǐng)盒飯”了。 下班! ?轉(zhuǎn)自https://www.cnblogs.com/lemondu/p/18652339 該文章在 2025/1/10 8:56:26 編輯過(guò) |
關(guān)鍵字查詢(xún)
相關(guān)文章
正在查詢(xún)... |