作者 | Mason MA

【Arthas 官方社區(qū)正在舉行征文活動，參加即有獎品拿哦~點擊投稿】

Arthas 是個不錯的工具，這里要再安利一波，當(dāng)然整個過程還用到了其他工具，如 MAT、YourKIT（這個是付費的），結(jié)合起來使用更加便于發(fā)現(xiàn)和解決問題。期間還和開發(fā)大佬多次溝通，分別獲取了不同的信息。

一鍵安裝并啟動 Arthas

• 方式一：通過 Cloud Toolkit 實現(xiàn) Arthas 一鍵遠程診斷

Cloud Toolkit 是阿里云發(fā)布的免費本地 IDE 插件，幫助開發(fā)者更高效地開發(fā)、測試、診斷并部署應(yīng)用。通過插件，可以將本地應(yīng)用一鍵部署到任意服務(wù)器，甚至云端（ECS、EDAS、ACK、ACR 和 小程序云等）；并且還內(nèi)置了 Arthas 診斷、Dubbo工具、Terminal 終端、文件上傳、函數(shù)計算 和 MySQL 執(zhí)行器等工具。不僅僅有 IntelliJ IDEA 主流版本，還有 Eclipse、Pycharm、Maven 等其他版本。

推薦使用 IDEA 插件下載 Cloud Toolkit 來使用 Arthas：http://t.tb.cn/2A5CbHWveOXzI7sFakaCw8

• 方式二：直接下載

地址：https://github.com/alibaba/arthas。

現(xiàn)象

• 建索引的后臺應(yīng)用，感覺用不到那么大內(nèi)存，現(xiàn)在用到了并且隔兩天就會 oom，需要重啟；
• 有全量數(shù)據(jù)和增量數(shù)據(jù)，OOM 大多發(fā)生在全量數(shù)據(jù)寫入階段，且 OOM 基本都在凌晨首次觸發(fā)全量數(shù)據(jù)更新時出現(xiàn)；
• 業(yè)務(wù)應(yīng)用使用了 G1 收集器（高級高級…）。

內(nèi)心 OS：糟糕，G1 還不熟可怎么辦，先想個辦法把大佬們支開，我自己再慢慢研究。

我還有點別的事兒，我等會再看

茍膽假設(shè)

在現(xiàn)有掌握的信息下判斷，大膽假設(shè)一下，反正猜錯了又不會賠錢。

• 是否是因為全量數(shù)據(jù)寫入，超過了堆的承載能力，導(dǎo)致了 OOM？
• 業(yè)務(wù)是否有 static 容器使用不當(dāng)，一直沒回收，一直往里 put 元素，所以需要兩天 OOM 一次？
• 內(nèi)存不夠，是哪些對象占用最多，先找出來看看？
• 有沒有大對象？

發(fā)抖求證

基本信息

進程啟動參數(shù)

-Xms12g -Xmx12g -XX:+UseG1GC -XX:InitiatingHeapOccupancyPercent=70 -XX:MaxGCPauseMillis=200 -XX:G1HeapWastePercent=20 -XX:+PrintAdaptiveSizePolicy -XX:+UseStringDeduplication -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationStoppedTime -XX:+PrintTenuringDistribution -Xloggc:/home/search/fse2/gc.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=2 -XX:GCLogFileSize=512M -XX:+UnlockDiagnosticVMOptions -XX:+PrintNMTStatistics -XX:NativeMemoryTracking=summary

可以看到，使用了 G1 收集器，這個之前做業(yè)務(wù)開發(fā)的時候還不常見呢，畢竟是為大內(nèi)存打造的追求低延遲的垃圾回收器。關(guān)于 G1 收集器的一些基本特性，大家可以去搜集一些資料。大概主要包括以下幾項：

• Region 分區(qū)機制
• SATB，全稱是 Snapshot-At-The-Beginning，由字面理解，是 GC 開始時活著的對象的一個快照
• Rset，全稱是 Remembered Set，是輔助 GC 過程的一種結(jié)構(gòu)，空間換時間思想
• Pause Prediction Model 即停頓預(yù)測模型

從 G1 的這些屬性來看，它期望做到減少人為操作調(diào)優(yōu)，實現(xiàn)自動化的調(diào)優(yōu)（說到這里，感覺本次出現(xiàn)的 OOM 似乎跟垃圾收集器本身關(guān)聯(lián)并不大，并不是因為業(yè)務(wù)量大堆內(nèi)存不夠用，可能根本原因在代碼邏輯層面），并且適應(yīng)在硬件成本降低，大內(nèi)存堆逐漸變多的場景（后面還有 ZGC 和 Shenandoah，同樣是可以管理超大內(nèi)存并停頓很低的神奇垃圾收集器）。

已經(jīng)有GC日志了，那先看看日志，發(fā)現(xiàn)一處異常：

#### 這里Heap回收的還只是300多M內(nèi)存 [Eden: 316.0M(956.0M)->0.0B(1012.0M) Survivors: 48.0M->44.0M Heap: 359.2M(12.0G)->42.0M(12.0G)][Times: user=0.31 sys=0.01, real=0.05 secs] 2020-06-09T02:59:23.489+0800: 2020-06-09T02:59:23.489+0800: 35.922: Total time for which application threads were stopped: 0.0578199 seconds, Stopping threads took: 0.0000940 seconds 35.922: [GC concurrent-root-region-scan-start] ...... ...... ...... #### 這個點Heap回收的就是11G內(nèi)存了 [Eden: 724.0M(1012.0M)->0.0B(540.0M) Survivors: 44.0M->72.0M Heap: 11.5G(12.0G)->355.6M(12.0G)] [Times: user=1.51 sys=0.07, real=0.26 secs] 2020-06-09T03:12:36.329+0800: 828.762: Total time for which application threads were stopped: 0.2605902 seconds, Stopping threads took: 0.0000600 seconds

初次調(diào)試

增加 -XX:G1ReservePercent 選項的值，為“目標(biāo)空間”增加預(yù)留內(nèi)存量。

減少 -XX:InitiatingHeapOccupancyPercent 提前啟動標(biāo)記周期

懷疑在 GC 的當(dāng)時，有大量數(shù)據(jù)全量寫入，內(nèi)存還沒回收完，寫進大量對象，導(dǎo)致了 OOM，于是調(diào)了啟動周期，占比由 70 下降到55，提前觸發(fā)，預(yù)留更多堆空間。

GC 變得頻繁了，但是內(nèi)存占用過大的問題并沒有得到解釋。并且是否會再次在凌晨出現(xiàn) OOM 還需要等。。。于是還要繼續(xù)看看有沒有別的問題。

繼續(xù)挖掘

有疑點沒有解答，肯定是要繼續(xù)挖掘的，抄起鍵盤就是干，一頓操作猛如虎。

Arthas

不知道哪位已經(jīng)安裝了，先拿來用用看吧，大概用到了以下幾個命令：

dashboard

看看基本情況，線程數(shù)，堆大小，老年代大小，使用占比情況。首次看到這里時，eden 和 old 區(qū)的占用都挺高的， 70~80% 吧（當(dāng)時忘了截圖）。內(nèi)存使用率比較高。

thread

看看線程數(shù)有沒有異常，線程數(shù)正常，只是找出了資源占用比較高的線程，其中一個線程在后面其他信息統(tǒng)計中還會出現(xiàn)：

YJPAgent-Telemetry ctrl-bidsearch-rank-shard1 YJPAgent-RequestListener ctrl-bidsearch-rank-shard1

居然有兩個線程是 YourKit 監(jiān)控工具的 agent，看來這個監(jiān)控工具對性能影響還挺大的。

profiler

分別采集一下內(nèi)存和 CPU 的火焰圖數(shù)據(jù)：

# 內(nèi)存 profiler start --event alloc ### profiler stop# 默認CPU profiler start ### profiler stop

• CPU

• 內(nèi)存

[外鏈圖片轉(zhuǎn)存失敗,源站可能有防盜鏈機制,建議將圖片保存下來直接上傳(img-v5AKgv8x-1591961960707)(https://ucc.alicdn.com/pic/developer-ecology/a92b9a0699104ebe90c822a8499ac2e1.png)]

從 CPU 火焰圖看到，G1 收集器線程居然占了一半資源，可能采集當(dāng)時正在進行 GC，不過，除此之外，基本都能定位到是一個叫 IncrementIndexService 的類，使用了比較多的 CPU 和內(nèi)存資源。

如果業(yè)務(wù)代碼真的存在缺陷，那么一定在這個流程里，后來經(jīng)過溝通，發(fā)現(xiàn)這個應(yīng)用處理任務(wù)主要入口的確是在這里面。先持有保留意見。

thread 看到的線程和 profiler 看到的 class，都最終定位到是同一個業(yè)務(wù)流程。

開始驗證之前的猜想：

1. 是否在全量數(shù)據(jù)寫入的時候有大量對象涌入內(nèi)存？

計算了一些業(yè)務(wù)代碼獲取數(shù)據(jù)的量，元數(shù)據(jù)大約也就在 1.3G 左右，就算全量寫入，也不應(yīng)該占用 12G 的堆內(nèi)存，所以猜測全量數(shù)據(jù)寫入時，代碼邏輯可能有什么缺陷，導(dǎo)致 1.3G 的原數(shù)據(jù)被封裝成遠大于 1.3G 的對象了。

2. 是否有 static 容器？

有，但是經(jīng)過 watch 觀察，沒有發(fā)現(xiàn)容器只 put 不 remove 的情況，命令如下：

watch com.xxx.classname method "{params,target}" -x 3

3. 有沒有大對象？

對于 G1，默認將堆分成 2048 個 Region，12G 的堆，一個 Region 是 6M，超過 3M 才是大對象。

jmap histo 30123

至少輸出的數(shù)據(jù)中，大對象不是 G1 定義的大對象。

MAT

既然沒什么發(fā)現(xiàn)，就把堆 dump 出來吧。如果不想或者不能 dump，也可以用 jmap histo 查看內(nèi)存占用，優(yōu)點是不用 dump，缺點是通常不能很好的和業(yè)務(wù)代碼之間建立關(guān)聯(lián)。

警告：jmap 或者 Arthas 的 heapdump 操作之前一定要斷開流量。好在我們這個服務(wù)沒有線上流量，建索引有延遲，可能短暫影響搜索體驗。

dump 出來之后，發(fā)現(xiàn)有 7 個 G，這么大的文件一般很難傳到本地來分析了，于是用 MAT，占用服務(wù)器 1 個 G 內(nèi)存進行分析，分析完成的結(jié)果下載到本地。

線程名稱和之前發(fā)現(xiàn)的信息吻合，點開 detail 有驚喜。

一串奇怪的字符串，有點像 XML，好像在拼裝著什么，于是找到業(yè)務(wù)大佬請教，發(fā)現(xiàn)的確有拼裝 solrDocument 的邏輯，而且，經(jīng)過 YourKit 輸出部分對象值的片段，可以發(fā)現(xiàn)有大部分是在重復(fù)拼裝，大概意思如下：

<xml> ... <country>CA</country> <country>CA</country> <country>CA</country> <country>CA</country> <country>CA</country> ...n次重復(fù) <country>US</country> <country>US</country> <country>US</country> <country>US</country> <country>US</country> <country>US</country> ...n次重復(fù) <country>UK</country> <country>UK</country> ... </xml>

代碼邏輯修改其實比較簡單了，業(yè)務(wù)開發(fā)大佬們比較熟悉業(yè)務(wù)流程，很快就就有了修改方案。

調(diào)整之后發(fā)現(xiàn)，內(nèi)存使用量下降了很多。

直接降到了 4-5G 左右，如果是這樣的話，即便全量數(shù)據(jù)寫入時，正在做垃圾回收，應(yīng)該還是夠用的。但是感覺這個代碼邏輯里面，應(yīng)該還有優(yōu)化空間，不過，先解決問題，優(yōu)化可以做下一步操作。

復(fù)盤

無論從哪個工具得出的數(shù)據(jù)，都顯示 IncrementIndexService 這個類的邏輯可能有問題，最終問題的根本和 G1 參數(shù)設(shè)置好像也沒什么關(guān)系，代碼邏輯缺陷才是根源，再擴大內(nèi)存可能或者調(diào)整 JVM 參數(shù)，也只能將故障緩解，但是不能解決。

• 從進程到線程到代碼

• 獲取 JVM 基本信息，收集器，啟動參數(shù)等信息

• 查看現(xiàn)有的日志，GC 日志，業(yè)務(wù)日志

• 溝通業(yè)務(wù)場景，了解輸入數(shù)據(jù)規(guī)模等等

• 猜想可能存在的原因，大膽的猜

• 使用工具（Arthas、MAT、YourKit、JDK 自帶命令等等）挖掘信息，火焰圖、耗能線程、線程棧 堆dump，占比分析 大對象 …

• 結(jié)合數(shù)據(jù)重新梳理，發(fā)現(xiàn)業(yè)務(wù)代碼的關(guān)聯(lián)和可能存在的缺陷，可以嘗試調(diào)整參數(shù)

• 業(yè)務(wù)代碼若有 bug，修復(fù) bug

Arthas 征文活動火熱進行中

Arthas 官方正在舉行征文活動，如果你有：

• 使用 Arthas 排查過的問題
• 對 Arthas 進行源碼解讀
• 對 Arthas 提出建議
• 不限，其它與 Arthas 有關(guān)的內(nèi)容

歡迎參加征文活動，還有獎品拿哦~點擊投稿

“阿里巴巴云原生關(guān)注微服務(wù)、Serverless、容器、Service Mesh 等技術(shù)領(lǐng)域、聚焦云原生流行技術(shù)趨勢、云原生大規(guī)模的落地實踐，做最懂云原生開發(fā)者的公眾號。”

總結(jié)

以上是生活随笔為你收集整理的“举报”阿里巴巴 Arthas，大幅降低 OOM Trouble shooting 门槛的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網(wǎng)站內(nèi)容還不錯，歡迎將生活随笔推薦給好友。