我在組內的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 整理而來,行文沒有那么絲滑,但問題排查的思路、手段依然是這些,大家學廢了嗎?


搜索關注微信公眾號"捉蟲大師",后端技術分享,架構設計、性能優化、源碼閱讀、問題排查、踩坑實踐。


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM