完了!線上又發生 OOM 了!
現象
線上某個服務有接口非常慢,通過監控鏈路查看發現,中間的 GAP 時間非常大,實際接口并沒有消耗很多時間,并且在那段時間里有很多這樣的請求。

原因分析
先從監控鏈路分析了一波,發現請求是已經打到服務上了,處理之前不知道為什么等了 3s,猜測是不是機器當時負載太大了,通過 QPS 監控查看發現,在接口慢的時候 CPU 突然增高,同時也頻繁的 GC ,并且時間很長,但是請求量并不大,并且這臺機器很快就因為 Heap滿了而被下掉了。

去看了下日志,果然有 OOM 的報錯,但是從報錯信息上并沒辦法找到 Root Cause。
另外開發同學提供了線索,在發生問題的時候在跑一個大批量的一次性 JOB,懷疑是不是這個 JOB 導致的,馬上把 JOB 代碼拉下來分析了下,JOB 做了分批處理,代碼也沒有發現什么問題。
雖然我們系統加了下面的 JVM 參數,但是由于容器部署的原因,這些文件在 pod 被 kill 掉之后沒辦法保留下來。
這個現象是最近出現的,猜測是最近提交的代碼導致的,于是去分析了最近提交的所有代碼,很不幸的都沒有發現問題。。。
在分析代碼的過程中,該服務又無規律的出現了兩次 OOM,只好聯系運維同學優先給這個服務加了 EFS (Amazon 文件系統)等待下次出現能抓住這個問題。
剛掛載完 EFS,很幸運的就碰到了系統出現 OOM 的問題。
dump 出來的文件足有 4.8G,話不多說祭出 jvisualvm 進行分析,分析工具都被這個dump文件給搞掛了也報了個java.lang.OutOfMemoryError: Java heap space,加載成功之后就給出了導致OOM的線程。

找到了具體報錯的代碼行號,翻一下業務代碼,竟然是一個查詢數據庫的count操作,這能有啥問題?
仔細看了下里面有個foreach?遍歷userId?的操作,難道這個userId的數組非常大?

找到class按照大小排序,占用最多的是一個 byte 數組,有 1.07G,char 數組也有1.03G,byte 數組都是數字,直接查看 char 數組吧,點進去查看具體內容,果然是那條count語句,一條 SQL 1.03G 難以想象。。。


這個userId?的數據完全是外部傳過來的,并沒有做什么操作,從監控上看,這個入參有 64M,馬上聯系對應系統排查為啥會傳這么多用戶過來查詢,經過一番排查確認他們有個bug,會把所有用戶都發過來查詢。。。到此問題排查清楚。
解決方案
對方系統控制傳入userId?的數量,我們自己的系統也對userId做一個限制,問題排查過程比較困難,修改方案總是那么的簡單。
別急,還有一個
看到這個問題,就想起之前我們還有一個同樣類似的問題導致的故障。
也是突然收到很多告警,還有機器 down 機的告警,打開 CAT 監控看的時候,發現內存已經被打滿了。

操作和上面的是一樣的,拿到 dump 文件之后進行分析,不過這是一個漫長的過程,因為 down了好幾臺機器,最大的文件有12GB。
通過 MAT 分析 dump 文件發現有幾個巨大的 String(熟悉的味道,熟悉的配方)。

接下來就是早具體的代碼位置了,去查看了下日志,這臺機器已經觸發自我保護機制了,把代碼的具體位置帶了出來。
經過分析代碼發現,代碼中的邏輯是查詢 TIDB(是有同步延遲的),發現在極端情況下會出現將用戶表全部數據加載到內存中的現象。

于是找 DBA 拉取了對應時間段 TIDB 的慢查詢,果然命中了。

總結
面對 OOM 問題如果代碼不是有明顯的問題,下面幾個JVM參數相當有用,尤其是在容器化之后。
另外提一個參數也很有用,正常來說如果程序出現 OOM 之后,就是有代碼存在內存泄漏的風險,這個時候即使能對外提供服務,其實也是有風險的,可能造成更多的請求有問題,所以該參數非常有必要,可以讓 K8S 快速的再拉起來一個實例。
另外,針對這兩個非常類似的問題,對于 SQL 語句,如果監測到沒有where?條件的全表查詢應該默認增加一個合適的limit作為限制,防止這種問題拖垮整個系統。






























