前言

作為一名 java 開發(fā)者，經(jīng)常會(huì)遇到服務(wù)不可用的問題排查。導(dǎo)致問題的原因可能是多種多樣的，但是在預(yù)先不知道是什么原因?qū)е碌姆?wù)不可用的時(shí)候，通用的排查手段和流程是相似的。

在具體的一些排查方式中涉及到linux的shell命令的使用，但平常又很少用到，導(dǎo)致每次要用到了，都要去重新去搜索。

所以本篇文章記錄一下通用的排查方式，并且盡可能得將其流程化，從而方便后續(xù)的排查，節(jié)省時(shí)間成本。

隨著一次次的問題排查，經(jīng)驗(yàn)會(huì)更加豐富，排查方式也會(huì)不斷優(yōu)化和進(jìn)步，也能夠?qū)VM和系統(tǒng)資源等方面的知識(shí)進(jìn)一步了解。這篇文章不會(huì)寫完了之后就封存不動(dòng)了，而是會(huì)持續(xù)得更新。

接下來就進(jìn)入排查流程，并逐一介紹每個(gè)流程中要做的事情，

觀察監(jiān)控

問題排查必須要建立在有監(jiān)控和日志的基礎(chǔ)上，否則都沒法入手問題調(diào)查。觀察系統(tǒng)資源和JVM的監(jiān)控，基本上能夠快速找到服務(wù)不可用的直接原因和不可用的時(shí)間點(diǎn)。

如果連監(jiān)控都沒有，那么首先要做的事情就是應(yīng)該給Java服務(wù)和所在的服務(wù)器加上監(jiān)控。

從監(jiān)控中我們往往能夠看出以下幾方面導(dǎo)致服務(wù)不可用的原因：

• JVM中的內(nèi)存不夠用了，發(fā)生了OOM - Out of memory的報(bào)錯(cuò)。（通常是堆內(nèi)存）
• 宿主機(jī)的CPU資源不夠用了
• 宿主機(jī)的內(nèi)存資源不夠用了

JVM 監(jiān)控

首先要查看的就是JVM的內(nèi)存，下面是一個(gè)包含一些JVM內(nèi)存指標(biāo)的監(jiān)控截圖。

從這張圖中可以很好的看出JVM堆內(nèi)存和非堆內(nèi)存的情況。最常關(guān)注的就是：

• Eden 新生代內(nèi)存占用
• Old 老年代內(nèi)存占用情況
• Metaspace 內(nèi)存占用情況

如果以上的內(nèi)存實(shí)際占用隨著時(shí)間不斷增加，最終臨近相對(duì)應(yīng)的最大值時(shí)（used >> max），基本就可以確認(rèn)是因?yàn)閮?nèi)存占用過多導(dǎo)致的服務(wù)不可用了。

需要注意的是，不同的虛擬機(jī)和垃圾回收對(duì)于以上的內(nèi)存空間的劃分不同，但問題的思考上是一致的，即究竟哪塊內(nèi)存占用超出了預(yù)設(shè)的值。

如果確實(shí)發(fā)現(xiàn)了內(nèi)存占用的異常，那么就應(yīng)該先去看日志記錄中，在應(yīng)用首次不可用那個(gè)時(shí)間點(diǎn)，是否出現(xiàn)了Out of memory的報(bào)錯(cuò)日志。這一步是為了確定我們基于監(jiān)控直觀獲得的初步結(jié)論。下文中會(huì)介紹如何去查看這些日志。

其實(shí)這一步不做也可以，因?yàn)楦鶕?jù)經(jīng)驗(yàn)來看，如果直觀得發(fā)現(xiàn)服務(wù)不可用的時(shí)刻的內(nèi)存占用超出max的值，那么基本上就是發(fā)生了OOM。

接下來繼續(xù)排查以下內(nèi)容：

• 是否是因?yàn)镴VM啟動(dòng)時(shí)，設(shè)置的堆內(nèi)存、Metaspace過小導(dǎo)致內(nèi)存不夠用。隨著業(yè)務(wù)的發(fā)展、代碼功能的不斷增加，不再適應(yīng)現(xiàn)在的應(yīng)用的內(nèi)存使用了；
• 如果新生代突然的飆升導(dǎo)致內(nèi)存超出，那么應(yīng)該是存在某個(gè)大量業(yè)務(wù)的堆積，或者非常多的數(shù)據(jù)進(jìn)入JVM堆內(nèi)存中。比如線程池中隊(duì)列的數(shù)據(jù)堆積，數(shù)據(jù)庫查詢一下子查出海量數(shù)據(jù)。
• 如果是老年代持續(xù)地、肉眼可見的上升，那么可能是出現(xiàn)的內(nèi)存泄漏。比如在一個(gè)類中維護(hù)了一個(gè)static的List，隨著時(shí)間的增長，這個(gè)List越來越大。

如果懷疑是第一點(diǎn)，那么就去重新設(shè)置JVM的資源分配即可；針對(duì)2、3點(diǎn)則需要進(jìn)一步進(jìn)行Dump 文件分析，后文中會(huì)進(jìn)行介紹。

宿主機(jī)監(jiān)控

如果JVM的監(jiān)控并沒有什么異常，這時(shí)候就應(yīng)該去看看是不是宿主機(jī)的問題。一臺(tái)宿主機(jī)上往往會(huì)部署很多服務(wù)或者運(yùn)行很多進(jìn)程，如果其他進(jìn)程搶占了過多的資源（往往就是CPU、內(nèi)存），也會(huì)導(dǎo)致服務(wù)不可用。

下圖是一個(gè)通過Node Exporter來采集的系統(tǒng)資源的部分指標(biāo)的截圖：

通過這張圖就是很清晰得看出是否是因?yàn)橄到y(tǒng)的資源不夠用導(dǎo)致的問題。

解決這類問題，有三個(gè)方向上的解決方式：

• 一，是不是宿主機(jī)放的服務(wù)太多了，不應(yīng)該把重要的服務(wù)和其他一些不穩(wěn)定的應(yīng)用放在一起；
• 二，是不是宿主機(jī)的配置太差了，可以提升宿主機(jī)的資源配置；
• 三，是不是JVM的內(nèi)存設(shè)置太高了，現(xiàn)在的Java服務(wù)壓根用不了那么大的內(nèi)存，應(yīng)該將內(nèi)存設(shè)置小點(diǎn)，否則JVM總想著想系統(tǒng)申請(qǐng)內(nèi)存資源。

通過日志確定是OOM

集中的日志收集系統(tǒng)

分布式應(yīng)用部署的如今，基本上現(xiàn)在所有公司都有自己的日志收集系統(tǒng)，很少需要去機(jī)器上的log文件上查看日志了。開源常用的有：

• ELK Elasticsearch+Logstash+Kibana
• Skywalking + Elasticsearch
• PLG (Promtail+Loki+Grafana)

在這些日志系統(tǒng)中，選擇相應(yīng)的時(shí)間段和Out of memory的關(guān)鍵字就能判斷出是否出現(xiàn)了內(nèi)存溢出。

機(jī)器上查看日志

一般有了日志系統(tǒng)后就不需要再到機(jī)器上查看日志了，但有一些日志可能需要單獨(dú)輸出。比如我們有時(shí)候需要查看GarbageCollection的情況。

想要將GC的情況輸出到特定的日志文件中，可以使用下面的JVM啟動(dòng)參數(shù)：

-XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintTenuringDistribution -XX:+PrintHeapAtGC -XX:+PrintReferenceGC -XX:+PrintGCApplicationStoppedTime -XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1 -Xloggc:${SYSTEM_LOG_DIR}/gc-%t.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=14 -XX:GCLogFileSize=100M

先介紹一下這些參數(shù)的作用：

-XX:+PrintGCDetails

記錄詳細(xì)的 GC 日志，包括每次垃圾回收的類型（如 Minor GC、Major GC）、內(nèi)存分代的使用情況（年輕代、老年代等）、回收前后內(nèi)存的變化等信息。

-XX:+PrintGCDateStamps

為每條 GC 日志添加時(shí)間戳。

-XX:+PrintTenuringDistribution

打印每次垃圾回收時(shí)晉升年齡分布（Tenuring Distribution），記錄哪些對(duì)象從年輕代（Eden 區(qū)）晉升到老年代，以及晉升的條件（如對(duì)象的存活年齡）。

-XX:+PrintHeapAtGC

在每次 GC 開始和結(jié)束時(shí)，打印詳細(xì)的堆內(nèi)存使用情況。

-XX:+PrintReferenceGC

打印對(duì)軟引用（SoftReference）、弱引用（WeakReference）、虛引用（PhantomReference）對(duì)象的回收信息。

-XX:+PrintGCApplicationStoppedTime

記錄應(yīng)用程序因?yàn)?GC 停頓的時(shí)間。

-XX:+PrintSafepointStatistics

打印 JVM 安全點(diǎn)（Safepoint）相關(guān)的統(tǒng)計(jì)信息。安全點(diǎn)是 JVM 停止所有應(yīng)用線程以執(zhí)行特定任務(wù)（如 GC）的點(diǎn)。輸出包括進(jìn)入安全點(diǎn)的時(shí)間、原因以及線程的暫停時(shí)間等

-XX:PrintSafepointStatisticsCount=<n>

定義打印的安全點(diǎn)統(tǒng)計(jì)的次數(shù)，如果設(shè)置為 1，表示每次達(dá)到安全點(diǎn)時(shí)打印統(tǒng)計(jì)信息。

-Xloggc:<file>

指定 GC 日志輸出的文件路徑

-XX:+UseGCLogFileRotation

開啟 GC 日志文件輪轉(zhuǎn)功能，當(dāng)日志文件達(dá)到指定大小時(shí)，會(huì)生成一個(gè)新文件，而不是覆蓋原文件。

-XX:NumberOfGCLogFiles=<n>

設(shè)置 GC 日志文件的最大數(shù)量。超過此數(shù)量時(shí)，舊的日志文件會(huì)被自動(dòng)刪除，默認(rèn)值是 10。

-XX:GCLogFileSize=<size>

設(shè)置單個(gè) GC 日志文件的大小上限。這里設(shè)置為 100M，即日志文件超過 100MB 后會(huì)創(chuàng)建新的日志文件。

去log中找到那個(gè)時(shí)刻的gc情況，就能很好知道在垃圾回收中存在的問題。下面就是一次正常的GC情況的日志記錄：

{Heap before GC invocations=410 (full 0):
 garbage-first heap   total 1402880K, used 1252020K [0x0000000080000000, 0x0000000080102ad0, 0x0000000100000000)
  region size 1024K, 822 young (841728K), 5 survivors (5120K)
 Metaspace       used 214892K, capacity 236788K, committed 237056K, reserved 337920K
  class space    used 26519K, capacity 30174K, committed 30208K, reserved 131072K
2025-01-07T15:49:31.806+0800: 7390.574: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 54001664 bytes, new threshold 15 (max 15)
- age   1:    1242448 bytes,    1242448 total
- age   2:     240440 bytes,    1482888 total
- age   3:     287160 bytes,    1770048 total
- age   4:      82880 bytes,    1852928 total
- age   5:      55912 bytes,    1908840 total
- age   6:      29800 bytes,    1938640 total
- age   7:      25160 bytes,    1963800 total
- age   8:     231416 bytes,    2195216 total
- age   9:      81152 bytes,    2276368 total
- age  10:     323552 bytes,    2599920 total
- age  11:     225480 bytes,    2825400 total
- age  12:      96504 bytes,    2921904 total
- age  13:      82944 bytes,    3004848 total
- age  14:     262752 bytes,    3267600 total
- age  15:      48672 bytes,    3316272 total
2025-01-07T15:49:31.833+0800: 7390.601: [SoftReference, 0 refs, 0.0000535 secs]2025-01-07T15:49:31.833+0800: 7390.601: [WeakReference, 162 refs, 0.0000281 secs]2025-01-07T15:49:31.834+0800: 7390.601: [FinalReference, 427 refs, 0.0017021 secs]2025-01-07T15:49:31.835+0800: 7390.603: [PhantomReference, 5 refs, 0 refs, 0.0000161 secs]2025-01-07T15:49:31.835+0800: 7390.603: [JNI Weak Reference, 0.0001040 secs], 0.0308174 secs]
   [Parallel Time: 26.4 ms, GC Workers: 4]
      [GC Worker Start (ms): Min: 7390574.6, Avg: 7390574.6, Max: 7390574.7, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 3.0, Avg: 3.7, Max: 4.4, Diff: 1.4, Sum: 14.8]
      [Update RS (ms): Min: 19.9, Avg: 20.5, Max: 21.0, Diff: 1.1, Sum: 82.2]
         [Processed Buffers: Min: 305, Avg: 327.5, Max: 345, Diff: 40, Sum: 1310]
      [Scan RS (ms): Min: 0.2, Avg: 0.2, Max: 0.2, Diff: 0.0, Sum: 0.7]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 1.5, Avg: 1.8, Max: 2.0, Diff: 0.5, Sum: 7.2]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Termination Attempts: Min: 1, Avg: 1.2, Max: 2, Diff: 1, Sum: 5]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.2]
      [GC Worker Total (ms): Min: 26.2, Avg: 26.3, Max: 26.3, Diff: 0.1, Sum: 105.1]
      [GC Worker End (ms): Min: 7390600.9, Avg: 7390600.9, Max: 7390600.9, Diff: 0.0]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 4.2 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 2.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.2 ms]
      [Free CSet: 0.7 ms]
   [Eden: 817.0M(817.0M)->0.0B(816.0M) Survivors: 5120.0K->6144.0K Heap: 1222.7M(1370.0M)->241.4M(1370.0M)]
Heap after GC invocations=411 (full 0):
 garbage-first heap   total 1402880K, used 247151K [0x0000000080000000, 0x0000000080102ad0, 0x0000000100000000)
  region size 1024K, 6 young (6144K), 6 survivors (6144K)
 	Metaspace       used 214892K, capacity 236788K, committed 237056K, reserved 337920K
  class space    used 26519K, capacity 30174K, committed 30208K, reserved 131072K
}
 [Times: user=0.11 sys=0.00, real=0.03 secs]

Dump 文件分析

如果懷疑或者確認(rèn)了是OOM的問題，那么接下來就是查看究竟是哪些業(yè)務(wù)導(dǎo)致了OOM，這時(shí)候就需要去分析內(nèi)存的詳細(xì)信息了。

Dump 文件下載

如果發(fā)生了OOM，進(jìn)程就會(huì)卡住，此時(shí)就應(yīng)該登錄到服務(wù)器上去立馬把內(nèi)存導(dǎo)出到文件中，從而進(jìn)一步分析。

獲取Java進(jìn)程號(hào)

ps -ef | grep java

或

jps

dump 內(nèi)存文件

jmap -dump:format=b,file=dumplog.hprof <pid>

-F選項(xiàng)用于強(qiáng)制執(zhí)行堆轉(zhuǎn)儲(chǔ)，通常在目標(biāo)進(jìn)程（PID 6885）無響應(yīng)或掛起時(shí)使用。如果進(jìn)程已經(jīng)完全掛起，jmap命令本身也可能卡住，因?yàn)樗枰c目標(biāo)JVM進(jìn)行交互才能生成dump文件。

使用 VisualVM 查看下載的hprof文件

從中尋找異常（數(shù)量多、占用內(nèi)存大）的對(duì)象，一般只要找到了異常的對(duì)象，就能知道是哪部分的代碼出了問題。

常用的Linux shell命令

查看占用內(nèi)存最多的進(jìn)程

如果是系統(tǒng)內(nèi)存異常，往往需要知道是哪個(gè)進(jìn)程占用內(nèi)存過多，擠占了JVM所需的內(nèi)存。

ps -aux | sort -k4nr | head -10

其中k4表示按照內(nèi)存排序，如果想通過cpu占用排序使用k3。

查看進(jìn)程狀態(tài)

ps -p <pid> -o stat

用于查看進(jìn)程是否異常。

查看進(jìn)程中占用時(shí)間片較長的線程

top -Hp <pid>

查看GC情況

jstat -gcutil <pid> 1000

每隔一秒（1000）來打印一下gc和JVM內(nèi)存的情況。

到此這篇關(guān)于Java服務(wù)不可用問題排查和解決的文章就介紹到這了,更多相關(guān)Java服務(wù)不可用內(nèi)容請(qǐng)搜索腳本之家以前的文章或繼續(xù)瀏覽下面的相關(guān)文章希望大家以后多多支持腳本之家！

最新評(píng)論