Java 問(wèn)題排查技術(shù)分享
前言
最近翻看以前寫的 PPT， 發(fā)現(xiàn)了在2019年做的一次技術(shù)分享，關(guān)于 Java 問(wèn)題排查，由于沒(méi)什么公司機(jī)密可言，整理下分享給大家~
線上問(wèn)題處理流程
直接放PPT截圖吧，現(xiàn)在看來(lái)依然不過(guò)時(shí)
問(wèn)題排查
可從三個(gè)方面入手
知識(shí)：有些問(wèn)題，思考一下就有答案，就像傳說(shuō)中多隆那樣，回憶下就知道第83行代碼有問(wèn)題~ 工具：當(dāng)然不是每個(gè)人都能做到過(guò)目不忘，也有可能這代碼完全不是你寫的，這時(shí)就需要靠工具來(lái)定位問(wèn)題 數(shù)據(jù)：程序運(yùn)行時(shí)產(chǎn)生的數(shù)據(jù)，也能提供很多線索
知識(shí)
知識(shí)有很多方面，這里簡(jiǎn)單列舉一下：
語(yǔ)言（本文特指 Java）：如 JVM 知識(shí)、多線程知識(shí)等 框架：如 Dubbo、Spring 等 組件：如 Mysql、RocketMq 等 其他：如網(wǎng)絡(luò)、操作系統(tǒng)等
舉個(gè)例子，我們需要理解 Java 對(duì)象從申請(qǐng)到被回收整個(gè)過(guò)程，這個(gè)圖非常清晰，建議爛熟于心：
然后也要了解常見(jiàn)的垃圾收集器：
吞吐量=單位時(shí)間內(nèi)處理的請(qǐng)求數(shù)量=運(yùn)行代碼時(shí)間 / (運(yùn)行代碼時(shí)間 + 垃圾回收時(shí)間)
以 ParNew + CMS 為例 ，嘗試回答如下幾個(gè)問(wèn)題：
為什么要分代收集？— 關(guān)鍵字：效率 對(duì)象什么時(shí)候進(jìn)入老年代？— 關(guān)鍵字：年齡、大小 Young GC 與 Full GC 什么時(shí)候發(fā)生？— 關(guān)鍵字：Eden 不足、Old 不足、Meta 不足、map/System.gc
如果我們了解上述的這些知識(shí)后，舉個(gè)實(shí)際例子，當(dāng)我們發(fā)現(xiàn) Young GC 頻繁觸發(fā)，耗時(shí)高，該如何優(yōu)化？
首先思考，Young GC 什么時(shí)候觸發(fā)？答案是 Eden 區(qū)不足。
接著，Young GC 耗時(shí)主要是哪里耗時(shí)？答案是掃描 + 復(fù)制，掃描通常很快，復(fù)制比較慢。
那我們對(duì)癥下藥，增加新生代大小試試，結(jié)果真的解決問(wèn)題了，為什么？我們也分析一下
新生代大小為 M 時(shí)，假設(shè)對(duì)象存活 ?750ms，young GC間隔 500ms，掃描時(shí)間為 T1，復(fù)制時(shí)間為 T2
新生代大小為 M 時(shí)：頻率 2次/s，每次耗時(shí) T1 + T2 新生代擴(kuò)大為 2M 時(shí)：頻率 1次/s，每次耗時(shí) 2T1
由于T2遠(yuǎn)遠(yuǎn)大于T1，所以2T1 < T1 + T2
這就是知識(shí)的力量~
工具
Java 棧中的工具，也分為這幾類：
JDK 自帶：如 jstat、jstack、jmap、jconsole、jvisualvm 第三方：MAT（eclipse插件）、GCHisto、GCeasy（在線GC日志分析工具，https://gceasy.io/） 開源：大名鼎鼎的Arthas、bistoury（去哪網(wǎng)開源）、Async-profiler
這些工具的原理，我們也需要稍微了解下，比如 Cpu profiler大概有兩類：
基于采樣：優(yōu)點(diǎn)是性能開銷低，缺點(diǎn)是采樣有頻率限制，存在SafePoint Bias問(wèn)題 插樁：所有方法添加 ?AOP 邏輯，優(yōu)點(diǎn)是精準(zhǔn)采集，缺點(diǎn)是性能開銷高
比如 uber 開源的 uber-common/jvm-profiler，它就是基于采樣的 Cpu profiler，缺點(diǎn)就是存在 SafePoint Bias 問(wèn)題，比如有一次排查一個(gè) Cpu 占用問(wèn)題，就采集到了這樣的火焰圖，可以看到幾乎沒(méi)啥用
SafePoint（安全點(diǎn)） 可以簡(jiǎn)單理解為 JVM 可以停頓下來(lái)的特定位置的點(diǎn)，如果采樣的位置是特定的點(diǎn)，那么采樣就不具有代表性，因?yàn)榭赡茉诜?SafePoint 時(shí)可能消耗了更多的 Cpu，這種現(xiàn)象就被稱為 SafePoint Bias 問(wèn)題。
但我用另一個(gè) jvm-profiling-tools/async-profiler 來(lái)采集，就能看到性能瓶頸：
雖然 Async-profiler 也是基于采樣做，但它能避免 SafePoint Bias 問(wèn)題，原因是它采用了 AsyncGetCallTrace 的黑科技。于是依據(jù) Async-profiler 給出的火焰圖進(jìn)行優(yōu)化，Qps 從 58k 漲到 81k，Cpu 反而從72%下降到了41%
數(shù)據(jù)
數(shù)據(jù)包括：
監(jiān)控?cái)?shù)據(jù)，如APM、metric、JVM監(jiān)控、分布式鏈路追蹤等等數(shù)據(jù) 程序運(yùn)行數(shù)據(jù)：如業(yè)務(wù)數(shù)據(jù)、AccessLog、GC log、系統(tǒng)日志等
這部分就按實(shí)際來(lái)分析，沒(méi)有統(tǒng)一模板可言。
經(jīng)驗(yàn)
說(shuō)了這么多，從經(jīng)驗(yàn)角度總結(jié)了如下常見(jiàn)問(wèn)題該從哪些方面入手：
執(zhí)行異常：查看日志、debug、請(qǐng)求重放 應(yīng)用僵死：jstack 耗時(shí)高：trace跟蹤、Benchmark Cpu利用率高：Cpu profile分析 GC頻繁、耗時(shí)高：GC log分析 OOM、內(nèi)存占用高、泄漏：dump內(nèi)存分析
案例分享
Cobar僵死，進(jìn)程端口在，但不能處理請(qǐng)求
先踢掉故障機(jī)器，保留現(xiàn)場(chǎng)再排查問(wèn)題，根據(jù)日志，定位為內(nèi)存泄漏
小思考：能通過(guò)日志直接確定是哪里內(nèi)存泄露嗎？— 答案：不能
具體定位可dump內(nèi)存下載到本地分析，文件如果太大，可以先壓縮下
jmap -dump:format=b,file=/cobar.bin ${pid}
使用 eclipse 的插件 MAT 分析，過(guò)程就不放了，結(jié)果是發(fā)現(xiàn)了一個(gè)我們對(duì) Cobar 自定義修改導(dǎo)致的 Bug，如果對(duì)內(nèi)存分析感興趣，可以直接看我這幾篇實(shí)戰(zhàn)文章：
網(wǎng)關(guān)耗時(shí)高
使用 Arthas trace 跟蹤調(diào)用
trace com.beibei.airborne.embed.extension.PojoUtils generalize
接入 Sentinel 導(dǎo)致應(yīng)用僵死
接入限流降級(jí)利器 Sentinel 后，配置一條規(guī)則，觸發(fā)后導(dǎo)致應(yīng)用僵死，可使用 jstack 進(jìn)行排查，一眼就看出問(wèn)題所在
jstack ${pid} > jstack.txt
最后
本文最早分享于2019年12月，剛好過(guò)去2年，由于是 PPT 整理而來(lái)，行文沒(méi)有那么絲滑，但問(wèn)題排查的思路、手段依然是這些，大家學(xué)廢了嗎？