記一次線上 OOM 和性能優化

你們好，我是鴨血粉絲（你們會親切的喊我 「阿粉」），是一位喜歡吃鴨血粉絲的程序員，回想起以前線上出現 OOM 的場景，畢竟當時是第一次遇到這麼 緊髒 的大事，要好好記錄下來。

1 事情回顧

在某次週五，經過 Grafana 監控，發現線上環境忽然出現CPU和內存飆升的狀況：

可是看到網絡輸出和輸入流量都不是很高，因此網站被別人攻擊的機率不高，後來其它服務器的負荷居高不下。

阿粉先 dump 下當時的堆棧信息，保留現場，接着進行了簡單的分析，爲了穩住用戶，通知運維一臺一臺服務器進行從新啓動，讓你們繼續使用服務。

接着就開始分析和回顧事情了

2 開始分析

2.1 日誌分析

建議你們瞭解一些經常使用的 Linux 語法，例如 Grep 查詢命令，是日誌分析的一大利器，還能經過正則表達式查詢更多內容。

既然服務器在某個時間點出現了高負荷，因而就先去找一開始出現問題的服務器，去找耗時比較長的服務，例如我當時去找數據庫耗時的服務，因爲發生 OOM 時的日誌已經被刷掉，因而我大體描述一下：

[admin@xxx xxxyyyy]$ grep '15:14:' common-dal-digest.log |  grep -E '[0-9]{4,}ms'
2018-08-25 15:14:21,656 - [(xxxxMapper,getXXXListByParams,Y,1089ms)](traceId=5da451277e14418abf5eea18fd2b61bf)

很明顯，上述語句是 查詢在15:14那一分鐘內，在common-dal-digest.log文件中，耗時超過1000ms的SQL服務（查的是耗時超過10秒的服務）。

日誌中有個特殊的標誌 traceId，在請求鏈路中是惟一的，因此根據這個標誌能分析單請求的全鏈路操做，建議你們的日誌框架中也加上這種字段，讓服務可追溯和排查。

經過 traceId去查 http 保存的訪問日誌，定位在該時間點內，分發到該服務器上的用戶請求。還有根據該traceId，定位到整個調用流程所使用到的服務，發現的確十分耗時...

因而拿到了該請求具體信息，包括用戶的登陸手機號碼，由於這個時候，其它幾臺服務器也出現了 CPU 和內存負載升高，因而根據手機號查詢了其它幾臺服務器的訪問日誌，發現同一個請求，該用戶也調用了不少次...

因而初步確認了某個耗時接口

2.2 使用 MAT 分析 dump 文件

官方介紹：

MAT 是 Memory Analyzer 的簡稱，它是一款功能強大的 Java 堆內存分析器。能夠用於查找內存泄露以及查看內存消耗狀況。MAT 是基於Eclipse開發的，是一款免費的性能分析工具。讀者能夠在 http://www.eclipse.org/mat/ 下載並使用 MAT。

在前面提到，出現問題時，順手保存了一份堆棧信息，使用工具打開後，效果圖以下所示：

整個應用的內存大小 1.6G，而後有一塊內存塊居然佔用了 1.4G，佔比達到了 87.5%，這也太離譜了吧！

因而阿粉決定好好分析該對象的引用樹，右鍵選擇【class_reference】，查看對象列表，和觀察 GC 日誌，定位到具體的對象信息。

2.3 根本緣由

經過日誌分析以及 dump 文件分析，都指向了某個文件導出接口，接着在代碼中分析該接口具體調用鏈路，發現導出的數據不少，並且老代碼進行計算的邏輯嵌套了不少 for 循環，並且是 for 循環調用數據庫，計算效率極低。

模擬了該用戶在這個接口的所調用數據量，須要查詢多個表，而後 for 循環中大概會計算個 100w+ 次，致使阻塞了其它請求，因爲請求未結束，java 對象沒法被 GC 回收，線上的服務器 CPU 和內存使用狀況一直飆升。

3 性能優化

3.1 業務、代碼邏輯梳理

點開該段代碼的 git 提交記錄，發現是我在實習期寫的時候，個人心裏是崩潰的，當時對業務不熟悉，直接循環調用了老代碼，並且也沒有測試過這麼大的數據量，因此 GG了。

而後我就開始作代碼性能優化，首先仔細梳理了一下整個業務流程，經過增長 SQL 查詢條件，減小數據庫 IO 和查詢返回的數據量，優化判斷條件，減小 for 嵌套、循環次數和計算量。

3.2 經過 VisualVM 進行對比

官方描述：

VisualVM，可以監控線程，內存狀況，查看方法的CPU時間和內存中的對象，已被GC的對象，反向查看分配的堆棧(如100個String對象分別由哪幾個對象分配出來的).

該插件不須要另外下載，在 ${JAVA_HOME}/bin 目錄下就能找到，因此安裝了 jdk 就能使用它~

對比了新老代碼所佔用的 CPU 時間和內存狀態

優化前：

優化後：

經過上述優化以後，計算 1w 條數據量，進行導出成報表文件，在老代碼須要 48s，新代碼降低到了 8s，不過這是大數據量的狀況下，實際用戶的數據沒有這麼多，因此基本上知足了線上 99% 的用戶使用。（看到這個結果時，阿粉露出了「純潔的微笑」）

固然，因爲這些數據是本地開發環境新增長的，與出現 OOM 問題的用戶數據量還有些差異，但經過優化後的代碼，已經在數據庫查詢的時候就過濾掉不少無效的數據，在 for 循環計算前也加了過濾條件，因此真正計算起來起來就下降了不少計算量！

恩，本身代碼優化好了，還要等測試爸爸們測試後纔敢上線，此次要瘋狂造數據!

4 技術總結

阿粉週末會本身作點飯🍚，喜歡看王剛老師的視頻，以爲最後出現的 「技術總結」 很棒，讓我可以快速記住重要步驟

（但學習跟作飯同樣，仍是得通過反覆看和實踐才能好好記住，哼兒哈兒，大夥知道阿粉想說的是啥了吧哈哈哈）

4.1 開發注意點

在開發初期，阿粉沒有考慮到性能問題，想着知足需求就完成任務，但數據量一大起來，就有可能出現這些 OOM 問題，因此之後開發時，須要先提早考慮如下幾點：

1. 梳理設計流程
2. 考慮是否有性能問題
3. 與產品經理商量控制查詢條件，減小查詢的範圍
4. 與數據庫交互時，減小無效的查詢，合併查詢和合並更新操做
5. 減小 for 循環，尤爲注意多層 for 循環嵌套問題！
6. 調用老代碼要注意=-=

4.2 應對故障注意點

出現問題時也不要驚慌，好好去解決它纔是王道，「在解決問題中學到更多技術」

能夠參考如下步驟：

1. 保留現場，dump 堆棧信息
2. 進行限流，對出現問題的接口進行降級
3. 如沒有降級措施，服務器自己沒法快速恢復正常，聯繫運維重啓進行恢復的同時，記錄下有可能出現問題的數據，等待後面修復
4. 日誌、堆棧信息分析
5. 定位問題並解決

5 多說兩句

在定位到問題時，看到是阿粉寫的，本來覺得會受到批評，但領導並無責怪我，還叫阿粉以後好好改，避免下次出現這種問題，心情很開朗，但願各位小夥伴也能遇到這種開明的領導。（確定不是阿粉的顏值高）

在此次問題排查過程當中，熟悉了問題排查步驟，鞏固了 jdk 工具的使用方法和流程，也加深了對業務的理解程度，果真 「遇到問題可以快速成長」

同時解決 BUG 後，阿粉的心裏更開心了，下班後點了一份小碗鴨血粉絲。

各位小夥伴看完以爲有趣或者有用，來個點贊和關注，讓阿粉能升級吃大碗哈哈哈~