我在組內的Java問題排查分享

捉蟲大師發表於2021-12-01
Java

前言

最近翻看以前寫的 PPT， 發現了在2019年做的一次技術分享，關於 Java 問題排查，由於沒什麼公司機密可言，整理下分享給大家~

線上問題處理流程

直接放PPT截圖吧，現在看來依然不過時

image

問題排查

可從三個方面入手

  • 知識：有些問題，思考一下就有答案，就像傳說中多隆那樣，回憶下就知道第83行程式碼有問題~
  • 工具：當然不是每個人都能做到過目不忘，也有可能這程式碼完全不是你寫的，這時就需要靠工具來定位問題
  • 資料：程式執行時產生的資料，也能提供很多線索

知識

知識有很多方面，這裡簡單列舉一下：

  • 語言（本文特指 Java）：如 JVM 知識、多執行緒知識等
  • 框架：如 Dubbo、Spring 等
  • 元件：如 Mysql、RocketMq 等
  • 其他：如網路、作業系統等

舉個例子，我們需要理解 Java 物件從申請到被回收整個過程，這個圖非常清晰，建議爛熟於心：

image

然後也要了解常見的垃圾收集器：

image

吞吐量=單位時間內處理的請求數量=執行程式碼時間 / (執行程式碼時間 + 垃圾回收時間)

以 ParNew + CMS 為例 ，嘗試回答如下幾個問題：

  • 為什麼要分代收集？— 關鍵字：效率
  • 物件什麼時候進入老年代？— 關鍵字：年齡、大小
  • Young GC 與 Full GC 什麼時候發生？— 關鍵字：Eden 不足、Old 不足、Meta 不足、map/System.gc

如果我們瞭解上述的這些知識後，舉個實際例子，當我們發現 Young GC 頻繁觸發，耗時高，該如何優化？

首先思考，Young GC 什麼時候觸發？答案是 Eden 區不足。

接著，Young GC 耗時主要是哪裡耗時？答案是掃描 + 複製，掃描通常很快，複製比較慢。

那我們對症下藥，增加新生代大小試試，結果真的解決問題了，為什麼？我們也分析一下

新生代大小為 M 時，假設物件存活 750ms，young GC間隔 500ms，掃描時間為 T1，複製時間為 T2

  • 新生代大小為 M 時：頻率 2次/s，每次耗時 T1 + T2
  • 新生代擴大為 2M 時：頻率 1次/s，每次耗時 2T1

由於T2遠遠大於T1，所以2T1 < T1 + T2

這就是知識的力量~

工具

Java 棧中的工具，也分為這幾類：

  • JDK 自帶：如 jstat、jstack、jmap、jconsole、jvisualvm
  • 第三方：MAT（eclipse外掛）、GCHisto、GCeasy（線上GC日誌分析工具，https://gceasy.io/）
  • 開源：大名鼎鼎的Arthas、bistoury（去哪網開源）、Async-profiler

這些工具的原理，我們也需要稍微瞭解下，比如 Cpu profiler大概有兩類：

  • 基於取樣：優點是效能開銷低，缺點是取樣有頻率限制，存在SafePoint Bias問題
  • 插樁：所有方法新增 AOP 邏輯，優點是精準採集，缺點是效能開銷高

比如 uber 開源的 uber-common/jvm-profiler，它就是基於取樣的 Cpu profiler，缺點就是存在 SafePoint Bias 問題，比如有一次排查一個 Cpu 佔用問題，就採集到了這樣的火焰圖，可以看到幾乎沒啥用

SafePoint（安全點） 可以簡單理解為 JVM 可以停頓下來的特定位置的點，如果取樣的位置是特定的點，那麼取樣就不具有代表性，因為可能在非 SafePoint 時可能消耗了更多的 Cpu，這種現象就被稱為 SafePoint Bias 問題。

image

但我用另一個 jvm-profiling-tools/async-profiler 來採集，就能看到效能瓶頸：

image

雖然 Async-profiler 也是基於取樣做，但它能避免 SafePoint Bias 問題，原因是它採用了 AsyncGetCallTrace 的黑科技。於是依據 Async-profiler 給出的火焰圖進行優化，Qps 從 58k 漲到 81k，Cpu 反而從72%下降到了41%

image

資料

資料包括：

  • 監控資料，如APM、metric、JVM監控、分散式鏈路追蹤等等資料
  • 程式執行資料：如業務資料、AccessLog、GC log、系統日誌等

這部分就按實際來分析，沒有統一模板可言。

經驗

說了這麼多，從經驗角度總結了如下常見問題該從哪些方面入手：

  • 執行異常：檢視日誌、debug、請求重放
  • 應用僵死：jstack
  • 耗時高：trace跟蹤、Benchmark
  • Cpu利用率高：Cpu profile分析
  • GC頻繁、耗時高：GC log分析
  • OOM、記憶體佔用高、洩漏：dump記憶體分析

案例分享

Cobar僵死，程式埠在，但不能處理請求

先踢掉故障機器，保留現場再排查問題，根據日誌，定位為記憶體洩漏

image

小思考：能通過日誌直接確定是哪裡記憶體洩露嗎？— 答案：不能

具體定位可dump記憶體下載到本地分析，檔案如果太大，可以先壓縮下

jmap -dump:format=b,file=/cobar.bin ${pid}

使用 eclipse 的外掛 MAT 分析，過程就不放了，結果是發現了一個我們對 Cobar 自定義修改導致的 Bug，如果對記憶體分析感興趣，可以直接看我這幾篇實戰文章：

閘道器耗時高

使用 Arthas trace 跟蹤呼叫

trace com.beibei.airborne.embed.extension.PojoUtils generalize

image

接入 Sentinel 導致應用僵死

接入限流降級利器 Sentinel 後，配置一條規則，觸發後導致應用僵死，可使用 jstack 進行排查，一眼就看出問題所在

jstack ${pid} > jstack.txt

image

最後

本文最早分享於2019年12月，剛好過去2年，由於是 PPT 整理而來，行文沒有那麼絲滑，但問題排查的思路、手段依然是這些，大家學廢了嗎？

搜尋關注微信公眾號"捉蟲大師"，後端技術分享，架構設計、效能優化、原始碼閱讀、問題排查、踩坑實踐。

相關文章