Java 問題排查技術分享
前言
最近翻看以前寫的 PPT， 發現了在2019年做的一次技術分享，關于 Java 問題排查，由于沒什么公司機密可言，整理下分享給大家~
線上問題處理流程
直接放PPT截圖吧，現在看來依然不過時
問題排查
可從三個方面入手
-
知識：有些問題，思考一下就有答案，就像傳說中多隆那樣，回憶下就知道第83行代碼有問題~
-
工具：當然不是每個人都能做到過目不忘，也有可能這代碼完全不是你寫的，這時就需要靠工具來定位問題
-
數據：程序運行時產生的數據，也能提供很多線索
知識
知識有很多方面，這里簡單列舉一下：
-
語言（本文特指 Java）：如 JVM 知識、多線程知識等
-
框架：如 Dubbo、Spring 等
-
組件：如 Mysql、RocketMq 等
-
其他：如網絡、操作系統等
舉個例子，我們需要理解 Java 對象從申請到被回收整個過程，這個圖非常清晰，建議爛熟于心：
然后也要了解常見的垃圾收集器：
吞吐量=單位時間內處理的請求數量=運行代碼時間 / (運行代碼時間 + 垃圾回收時間)
以 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 問題。
但我用另一個 jvm-profiling-tools/async-profiler 來采集，就能看到性能瓶頸：
雖然 Async-profiler 也是基于采樣做，但它能避免 SafePoint Bias 問題，原因是它采用了 AsyncGetCallTrace 的黑科技。于是依據 Async-profiler 給出的火焰圖進行優化，Qps 從 58k 漲到 81k，Cpu 反而從72%下降到了41%
數據
數據包括：
-
監控數據，如APM、metric、JVM監控、分布式鏈路追蹤等等數據
-
程序運行數據：如業務數據、AccessLog、GC log、系統日志等
這部分就按實際來分析，沒有統一模板可言。
經驗
說了這么多，從經驗角度總結了如下常見問題該從哪些方面入手：
-
執行異常：查看日志、debug、請求重放
-
應用僵死：jstack
-
耗時高：trace跟蹤、Benchmark
-
Cpu利用率高：Cpu profile分析
-
GC頻繁、耗時高：GC log分析
-
OOM、內存占用高、泄漏：dump內存分析
案例分享
Cobar僵死，進程端口在，但不能處理請求
先踢掉故障機器，保留現場再排查問題，根據日志，定位為內存泄漏
小思考：能通過日志直接確定是哪里內存泄露嗎？— 答案：不能
具體定位可dump內存下載到本地分析，文件如果太大，可以先壓縮下
jmap -dump:format=b,file=/cobar.bin ${pid}
使用 eclipse 的插件 MAT 分析，過程就不放了，結果是發現了一個我們對 Cobar 自定義修改導致的 Bug
網關耗時高
使用 Arthas trace 跟蹤調用
- trace com.beibei.airborne.embed.extension.PojoUtils generalize
接入 Sentinel 導致應用僵死
接入限流降級利器 Sentinel 后，配置一條規則，觸發后導致應用僵死，可使用 jstack 進行排查，一眼就看出問題所在
- jstack ${pid} > jstack.txt
最后
本文最早分享于2019年12月，剛好過去2年，由于是 PPT 整理而來，行文沒有那么絲滑，但問題排查的思路、手段依然是這些，大家學廢了嗎？
