現(xiàn)象#

線上某個服務有接口非常慢，通過監(jiān)控鏈路查看發(fā)現(xiàn)，中間的 GAP 時間非常大，實際接口并沒有消耗很多時間，并且在那段時間里有很多這樣的請求。

原因分析#

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

去看了下日志，果然有 OOM 的報錯，但是從報錯信息上并沒辦法找到 Root Cause。

system error: org.springframework.web.util.NestedServletException: Handler dispatch failed; nested exception is java.lang.OutOfMemoryError: Java heap space ? at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1055) ? at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) ? at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ? at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909) ? at javax.servlet.http.HttpServlet.service(HttpServlet.java:681)

另外開發(fā)同學提供了線索，在發(fā)生問題的時候在跑一個大批量的一次性 JOB，懷疑是不是這個 JOB 導致的，馬上把 JOB 代碼拉下來分析了下，JOB 做了分批處理，代碼也沒有發(fā)現(xiàn)什么問題。

雖然我們系統(tǒng)加了下面的 JVM 參數(shù)，但是由于容器部署的原因，這些文件在 pod 被 kill 掉之后沒辦法保留下來。

-XX:+HeapDumpOnOutOfMemoryError -XX:ErrorFile=/logs/oom_dump/xxx.log -XX:HeapDumpPath=/logs/oom_dump/xxx.hprof

這個現(xiàn)象是最近出現(xiàn)的，猜測是最近提交的代碼導致的，于是去分析了最近提交的所有代碼，很不幸的都沒有發(fā)現(xiàn)問題。。。

在分析代碼的過程中，該服務又無規(guī)律的出現(xiàn)了兩次 OOM，只好聯(lián)系運維同學優(yōu)先給這個服務加了 EFS （Amazon 文件系統(tǒng)）等待下次出現(xiàn)能抓住這個問題。

剛掛載完 EFS，很幸運的就碰到了系統(tǒng)出現(xiàn) OOM 的問題。

dump 出來的文件足有 4.8G，話不多說祭出 jvisualvm 進行分析，分析工具都被這個dump文件給搞掛了也報了個java.lang.OutOfMemoryError: Java heap space，加載成功之后就給出了導致OOM的線程。

找到了具體報錯的代碼行號，翻一下業(yè)務代碼，竟然是一個查詢數(shù)據(jù)庫的count操作，這能有啥問題?

仔細看了下里面有個foreach遍歷userId的操作，難道這個userId的數(shù)組非常大?

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

這個userId的數(shù)據(jù)完全是外部傳過來的，并沒有做什么操作，從監(jiān)控上看，這個入參有 64M，馬上聯(lián)系對應系統(tǒng)排查為啥會傳這么多用戶過來查詢，經過一番排查確認他們有個bug，會把所有用戶都發(fā)過來查詢。。。到此問題排查清楚。

解決方案#

對方系統(tǒng)控制傳入userId的數(shù)量，我們自己的系統(tǒng)也對userId做一個限制，問題排查過程比較困難，修改方案總是那么的簡單。

別急，還有一個#

看到這個問題，就想起之前我們還有一個同樣類似的問題導致的故障。

也是突然收到很多告警,還有機器 down 機的告警，打開 CAT 監(jiān)控看的時候，發(fā)現(xiàn)內存已經被打滿了。

操作和上面的是一樣的，拿到 dump 文件之后進行分析，不過這是一個漫長的過程，因為 down了好幾臺機器，最大的文件有12GB。

通過 MAT 分析 dump 文件發(fā)現(xiàn)有幾個巨大的?String（熟悉的味道，熟悉的配方）。

接下來就是早具體的代碼位置了，去查看了下日志，這臺機器已經觸發(fā)自我保護機制了，把代碼的具體位置帶了出來。

經過分析代碼發(fā)現(xiàn)，代碼中的邏輯是查詢 TIDB（是有同步延遲的），發(fā)現(xiàn)在極端情況下會出現(xiàn)將用戶表全部數(shù)據(jù)加載到內存中的現(xiàn)象。

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

總結#

面對 OOM 問題如果代碼不是有明顯的問題，下面幾個JVM參數(shù)相當有用，尤其是在容器化之后。

-XX:+HeapDumpOnOutOfMemoryError -XX:ErrorFile=/logs/oom_dump/xxx.log -XX:HeapDumpPath=/logs/oom_dump/xxx.hprof

另外提一個參數(shù)也很有用，正常來說如果程序出現(xiàn) OOM 之后，就是有代碼存在內存泄漏的風險，這個時候即使能對外提供服務，其實也是有風險的，可能造成更多的請求有問題，所以該參數(shù)非常有必要，可以讓 K8S 快速的再拉起來一個實例。

-XX:+ExitOnOutOfMemoryError

另外，針對這兩個非常類似的問題，對于 SQL 語句，如果監(jiān)測到沒有where條件的全表查詢應該默認增加一個合適的limit作為限制，防止這種問題拖垮整個系統(tǒng)。