云棲號資訊：【點擊查看更多行業(yè)資訊】
在這里您可以找到不同行業(yè)的第一手的上云資訊，還在等什么，快來！

線上故障主要會包括 CPU、磁盤、內(nèi)存以及網(wǎng)絡(luò)問題，而大多數(shù)故障可能會包含不止一個層面的問題，所以進行排查時候盡量四個方面依次排查一遍。同時例如 jstack、jmap 等工具也是不囿于一個方面的問題的，基本上出問題就是 df、free、top 三連，然后依次 jstack、jmap 伺候，具體問題具體分析即可。

CPU

一般來講我們首先會排查 CPU 方面的問題。CPU 異常往往還是比較好定位的。原因包括業(yè)務(wù)邏輯問題(死循環(huán))、頻繁 gc 以及上下文切換過多。而最常見的往往是業(yè)務(wù)邏輯(或者框架邏輯)導(dǎo)致的，可以使用 jstack 來分析對應(yīng)的堆棧情況。

使用 jstack 分析 CPU 問題

我們先用 ps 命令找到對應(yīng)進程的 pid(如果你有好幾個目標(biāo)進程，可以先用 top 看一下哪個占用比較高)。
接著用top -H -p pid來找到 CPU 使用率比較高的一些線程

可以看到我們已經(jīng)找到了 nid 為 0x42 的堆棧信息，接著只要仔細分析一番即可。

當(dāng)然更常見的是我們對整個 jstack 文件進行分析，通常我們會比較關(guān)注 WAITING 和 TIMED_WAITING 的部分，BLOCKED 就不用說了。我們可以使用命令cat jstack.log | grep "java.lang.Thread.State" | sort -nr | uniq -c來對 jstack 的狀態(tài)有一個整體的把握，如果 WAITING 之類的特別多，那么多半是有問題啦。

頻繁 gc

當(dāng)然我們還是會使用 jstack 來分析問題，但有時候我們可以先確定下 gc 是不是太頻繁，使用jstat -gc pid 1000命令來對 gc 分代變化情況進行觀察，1000 表示采樣間隔(ms)，S0C/S1C、S0U/S1U、EC/EU、OC/OU、MC/MU 分別代表兩個 Survivor 區(qū)、Eden 區(qū)、老年代、元數(shù)據(jù)區(qū)的容量和使用量。YGC/YGT、FGC/FGCT、GCT 則代表 YoungGc、FullGc 的耗時和次數(shù)以及總耗時。如果看到 gc 比較頻繁，再針對 gc 方面做進一步分析，具體可以參考一下 gc 章節(jié)的描述。

磁盤

磁盤問題和 CPU 一樣是屬于比較基礎(chǔ)的。首先是磁盤空間方面，我們直接使用df -hl來查看文件系統(tǒng)狀態(tài)

不過這邊拿到的是 tid，我們要轉(zhuǎn)換成 pid，可以通過 readlink 來找到 pidreadlink -f /proc/*/task/tid/../..。

內(nèi)存

內(nèi)存問題排查起來相對比 CPU 麻煩一些，場景也比較多。主要包括 OOM、GC 問題和堆外內(nèi)存。一般來講，我們會先用free命令先來檢查一發(fā)內(nèi)存的各種情況。

堆內(nèi)內(nèi)存

內(nèi)存問題大多還都是堆內(nèi)內(nèi)存問題。表象上主要分為 OOM 和 Stack Overflo。

OOM

JMV 中的內(nèi)存不足，OOM 大致可以分為以下幾種：
Exception in thread "main" java.lang.OutOfMemoryError: unable to create new native thread
這個意思是沒有足夠的內(nèi)存空間給線程分配 Java 棧，基本上還是線程池代碼寫的有問題，比如說忘記 shutdown，所以說應(yīng)該首先從代碼層面來尋找問題，使用 jstack 或者 jmap。如果一切都正常，JVM 方面可以通過指定Xss來減少單個 thread stack 的大小。另外也可以在系統(tǒng)層面，可以通過修改/etc/security/limits.confnofile 和 nproc 來增大 os 對線程的限制

Exception in thread "main" java.lang.OutOfMemoryError: Java heap space

這個意思是堆的內(nèi)存占用已經(jīng)達到-Xmx 設(shè)置的最大值，應(yīng)該是最常見的 OOM 錯誤了。解決思路仍然是先應(yīng)該在代碼中找，懷疑存在內(nèi)存泄漏，通過 jstack 和 jmap 去定位問題。如果說一切都正常，才需要通過調(diào)整Xmx的值來擴大內(nèi)存。

Caused by: java.lang.OutOfMemoryError: Meta space

這個意思是元數(shù)據(jù)區(qū)的內(nèi)存占用已經(jīng)達到XX:MaxMetaspaceSize設(shè)置的最大值，排查思路和上面的一致，參數(shù)方面可以通過XX:MaxPermSize來進行調(diào)整(這里就不說 1.8 以前的永久代了)。

Stack Overflow
棧內(nèi)存溢出，這個大家見到也比較多。
Exception in thread "main" java.lang.StackOverflowError

表示線程棧需要的內(nèi)存大于 Xss 值，同樣也是先進行排查，參數(shù)方面通過Xss來調(diào)整，但調(diào)整的太大可能又會引起 OOM。
使用 JMAP 定位代碼內(nèi)存泄漏

上述關(guān)于 OOM 和 Stack Overflo 的代碼排查方面，我們一般使用 JMAPjmap -dump:format=b,file=filename pid來導(dǎo)出 dump 文件

通過 mat(Eclipse Memory Analysis Tools)導(dǎo)入 dump 文件進行分析，內(nèi)存泄漏問題一般我們直接選 Leak Suspects 即可，mat 給出了內(nèi)存泄漏的建議。另外也可以選擇 Top Consumers 來查看最大對象報告。和線程相關(guān)的問題可以選擇 thread overview 進行分析。除此之外就是選擇 Histogram 類概覽來自己慢慢分析，大家可以搜搜 mat 的相關(guān)教程。

日常開發(fā)中，代碼產(chǎn)生內(nèi)存泄漏是比較常見的事，并且比較隱蔽，需要開發(fā)者更加關(guān)注細節(jié)。比如說每次請求都 new 對象，導(dǎo)致大量重復(fù)創(chuàng)建對象；進行文件流操作但未正確關(guān)閉；手動不當(dāng)觸發(fā) gc；ByteBuffer 緩存分配不合理等都會造成代碼 OOM。

另一方面，我們可以在啟動參數(shù)中指定-XX:+HeapDumpOnOutOfMemoryError來保存 OOM 時的 dump 文件。

gc 問題和線程

gc 問題除了影響 CPU 也會影響內(nèi)存，排查思路也是一致的。一般先使用 jstat 來查看分代變化情況，比如 youngGC 或者 fullGC 次數(shù)是不是太多呀；EU、OU 等指標(biāo)增長是不是異常呀等。

線程的話太多而且不被及時 gc 也會引發(fā) oom，大部分就是之前說的unable to create new native thread。除了 jstack 細細分析 dump 文件外，我們一般先會看下總體線程，通過pstreee -p pid |wc -l。

堆外內(nèi)存

如果碰到堆外內(nèi)存溢出，那可真是太不幸了。首先堆外內(nèi)存溢出表現(xiàn)就是物理常駐內(nèi)存增長快，報錯的話視使用方式都不確定，如果由于使用 Netty 導(dǎo)致的，那錯誤日志里可能會出現(xiàn)OutOfDirectMemoryError錯誤，如果直接是 DirectByteBuffer，那會報OutOfMemoryError: Direct buffer memory。

堆外內(nèi)存溢出往往是和 NIO 的使用相關(guān)，一般我們先通過 pmap 來查看下進程占用的內(nèi)存情況pmap -x pid | sort -rn -k3 | head -30，這段意思是查看對應(yīng) pid 倒序前 30 大的內(nèi)存段。這邊可以再一段時間后再跑一次命令看看內(nèi)存增長情況，或者和正常機器比較可疑的內(nèi)存段在哪里。

我們?nèi)绻_定有可疑的內(nèi)存端，需要通過 gdb 來分析gdb --batch --pid {pid} -ex "dump memory filename.dump {內(nèi)存起始地址} {內(nèi)存起始地址+內(nèi)存塊大小}"

獲取 dump 文件后可用 heaxdump 進行查看hexdump -C filename | less，不過大多數(shù)看到的都是二進制亂碼。

NMT 是 Java7U40 引入的 HotSpot 新特性，配合 jcmd 命令我們就可以看到具體內(nèi)存組成了。需要在啟動參數(shù)中加入 -XX:NativeMemoryTracking=summary 或者 -XX:NativeMemoryTracking=detail，會有略微性能損耗。

一般對于堆外內(nèi)存緩慢增長直到爆炸的情況來說，可以先設(shè)一個基線jcmd pid VM.native_memory baseline。

然后等放一段時間后再去看看內(nèi)存增長的情況，通過jcmd pid VM.native_memory detail.diff(summary.diff)做一下 summary 或者 detail 級別的 diff。

可以看到 jcmd 分析出來的內(nèi)存十分詳細，包括堆內(nèi)、線程以及 gc(所以上述其他內(nèi)存異常其實都可以用 nmt 來分析)，這邊堆外內(nèi)存我們重點關(guān)注 Internal 的內(nèi)存增長，如果增長十分明顯的話那就是有問題了。

detail 級別的話還會有具體內(nèi)存段的增長情況，如下圖。

不過其實上面那些操作也很難定位到具體的問題點，關(guān)鍵還是要看錯誤日志棧，找到可疑的對象，搞清楚它的回收機制，然后去分析對應(yīng)的對象。比如 DirectByteBuffer 分配內(nèi)存的話，是需要 full GC 或者手動 system.gc 來進行回收的(所以最好不要使用-XX:+DisableExplicitGC)。那么其實我們可以跟蹤一下 DirectByteBuffer 對象的內(nèi)存情況，通過jmap -histo:live pid手動觸發(fā) fullGC 來看看堆外內(nèi)存有沒有被回收。如果被回收了，那么大概率是堆外內(nèi)存本身分配的太小了，通過-XX:MaxDirectMemorySize進行調(diào)整。如果沒有什么變化，那就要使用 jmap 去分析那些不能被 gc 的對象，以及和 DirectByteBuffer 之間的引用關(guān)系了。

GC 問題
堆內(nèi)內(nèi)存泄漏總是和 GC 異常相伴。不過 GC 問題不只是和內(nèi)存問題相關(guān)，還有可能引起 CPU 負載、網(wǎng)絡(luò)問題等系列并發(fā)癥，只是相對來說和內(nèi)存聯(lián)系緊密些，所以我們在此單獨總結(jié)一下 GC 相關(guān)問題。

我們在 CPU 章介紹了使用 jstat 來獲取當(dāng)前 GC 分代變化信息。而更多時候，我們是通過 GC 日志來排查問題的，在啟動參數(shù)中加上-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps來開啟 GC 日志。

常見的 Young GC、Full GC 日志含義在此就不做贅述了。
針對 gc 日志，我們就能大致推斷出 youngGC 與 fullGC 是否過于頻繁或者耗時過長，從而對癥下藥。我們下面將對 G1 垃圾收集器來做分析，這邊也建議大家使用 G1-XX:+UseG1GC。

youngGC 過頻繁
youngGC 頻繁一般是短周期小對象較多，先考慮是不是 Eden 區(qū)/新生代設(shè)置的太小了，看能否通過調(diào)整-Xmn、-XX:SurvivorRatio 等參數(shù)設(shè)置來解決問題。如果參數(shù)正常，但是 young gc 頻率還是太高，就需要使用 Jmap 和 MAT 對 dump 文件進行進一步排查了。

youngGC 耗時過長
耗時過長問題就要看 GC 日志里耗時耗在哪一塊了。以 G1 日志為例，可以關(guān)注 Root Scanning、Object Copy、Ref Proc 等階段。Ref Proc 耗時長，就要注意引用相關(guān)的對象。Root Scanning 耗時長，就要注意線程數(shù)、跨代引用。Object Copy 則需要關(guān)注對象生存周期。而且耗時分析它需要橫向比較，就是和其他項目或者正常時間段的耗時比較。比如說圖中的 Root Scanning 和正常時間段比增長較多，那就是起的線程太多了。

觸發(fā) fullGC
G1 中更多的還是 mixedGC，但 mixedGC 可以和 youngGC 思路一樣去排查。觸發(fā) fullGC 了一般都會有問題，G1 會退化使用 Serial 收集器來完成垃圾的清理工作，暫停時長達到秒級別，可以說是半跪了。

fullGC 的原因可能包括以下這些，以及參數(shù)調(diào)整方面的一些思路：

• 并發(fā)階段失敗：在并發(fā)標(biāo)記階段，MixGC 之前老年代就被填滿了，那么這時候 G1 就會放棄標(biāo)記周期。這種情況，可能就需要增加堆大小，或者調(diào)整并發(fā)標(biāo)記線程數(shù)-XX:ConcGCThreads。
• 晉升失敗：在 GC 的時候沒有足夠的內(nèi)存供存活/晉升對象使用，所以觸發(fā)了 Full GC。這時候可以通過-XX:G1ReservePercent來增加預(yù)留內(nèi)存百分比，減少-XX:InitiatingHeapOccupancyPercent來提前啟動標(biāo)記，-XX:ConcGCThreads來增加標(biāo)記線程數(shù)也是可以的。
• 大對象分配失敗：大對象找不到合適的 region 空間進行分配，就會進行 fullGC，這種情況下可以增大內(nèi)存或者增大-XX:G1HeapRegionSize。
• 程序主動執(zhí)行 System.gc()：不要隨便寫就對了。

另外，我們可以在啟動參數(shù)中配置-XX:HeapDumpPath=/xxx/dump.hprof來 dump fullGC 相關(guān)的文件，并通過 jinfo 來進行 gc 前后的 dump
jinfo -flag +HeapDumpBeforeFullGC pid
jinfo -flag +HeapDumpAfterFullGC pid
jinfo -flag +HeapDumpBeforeFullGC pid
jinfo -flag +HeapDumpAfterFullGC pid

這樣得到 2 份 dump 文件，對比后主要關(guān)注被 gc 掉的問題對象來定位問題。

網(wǎng)絡(luò)
涉及到網(wǎng)絡(luò)層面的問題一般都比較復(fù)雜，場景多，定位難，成為了大多數(shù)開發(fā)的噩夢，應(yīng)該是最復(fù)雜的了。這里會舉一些例子，并從 tcp 層、應(yīng)用層以及工具的使用等方面進行闡述。

超時
超時錯誤大部分處在應(yīng)用層面，所以這塊著重理解概念。超時大體可以分為連接超時和讀寫超時，某些使用連接池的客戶端框架還會存在獲取連接超時和空閑連接清理超時。

• 讀寫超時。readTimeout/writeTimeout，有些框架叫做 so_timeout 或者 socketTimeout，均指的是數(shù)據(jù)讀寫超時。注意這邊的超時大部分是指邏輯上的超時。soa 的超時指的也是讀超時。讀寫超時一般都只針對客戶端設(shè)置。
• 連接超時。connectionTimeout，客戶端通常指與服務(wù)端建立連接的最大時間。服務(wù)端這邊 connectionTimeout 就有些五花八門了，Jetty 中表示空閑連接清理時間，Tomcat 則表示連接維持的最大時間。
• 其他。包括連接獲取超時 connectionAcquireTimeout 和空閑連接清理超時 idleConnectionTimeout。多用于使用連接池或隊列的客戶端或服務(wù)端框架。

我們在設(shè)置各種超時時間中，需要確認的是盡量保持客戶端的超時小于服務(wù)端的超時，以保證連接正常結(jié)束。
在實際開發(fā)中，我們關(guān)心最多的應(yīng)該是接口的讀寫超時了。

如何設(shè)置合理的接口超時是一個問題。如果接口超時設(shè)置的過長，那么有可能會過多地占用服務(wù)端的 tcp 連接。而如果接口設(shè)置的過短，那么接口超時就會非常頻繁。

服務(wù)端接口明明 rt 降低，但客戶端仍然一直超時又是另一個問題。這個問題其實很簡單，客戶端到服務(wù)端的鏈路包括網(wǎng)絡(luò)傳輸、排隊以及服務(wù)處理等，每一個環(huán)節(jié)都可能是耗時的原因。

TCP 隊列溢出
tcp 隊列溢出是個相對底層的錯誤，它可能會造成超時、rst 等更表層的錯誤。因此錯誤也更隱蔽，所以我們單獨說一說。

如上圖所示，這里有兩個隊列：syns queue(半連接隊列）、accept queue（全連接隊列）。三次握手，在 server 收到 client 的 syn 后，把消息放到 syns queue，回復(fù) syn+ack 給 client，server 收到 client 的 ack，如果這時 accept queue 沒滿，那就從 syns queue 拿出暫存的信息放入 accept queue 中，否則按 tcp_abort_on_overflow 指示的執(zhí)行。
tcp_abort_on_overflow 0 表示如果三次握手第三步的時候 accept queue 滿了那么 server 扔掉 client 發(fā)過來的 ack。tcp_abort_on_overflow 1 則表示第三步的時候如果全連接隊列滿了，server 發(fā)送一個 rst 包給 client，表示廢掉這個握手過程和這個連接，意味著日志里可能會有很多connection reset / connection reset by peer。
那么在實際開發(fā)中，我們怎么能快速定位到 tcp 隊列溢出呢？
netstat 命令，執(zhí)行 netstat -s | egrep "listen|LISTEN"

上面看到 Send-Q 表示第三列的 listen 端口上的全連接隊列最大為 5，第一列 Recv-Q 為全連接隊列當(dāng)前使用了多少。
接著我們看看怎么設(shè)置全連接、半連接隊列大小吧：

全連接隊列的大小取決于 min(backlog, somaxconn)。backlog 是在 socket 創(chuàng)建的時候傳入的，somaxconn 是一個 os 級別的系統(tǒng)參數(shù)。而半連接隊列的大小取決于 max(64, /proc/sys/net/ipv4/tcp_max_syn_backlog)。

在日常開發(fā)中，我們往往使用 servlet 容器作為服務(wù)端，所以我們有時候也需要關(guān)注容器的連接隊列大小。在 Tomcat 中 backlog 叫做acceptCount，在 Jetty 里面則是acceptQueueSize。

RST 異常
RST 包表示連接重置，用于關(guān)閉一些無用的連接，通常表示異常關(guān)閉，區(qū)別于四次揮手。
在實際開發(fā)中，我們往往會看到connection reset / connection reset by peer錯誤，這種情況就是 RST 包導(dǎo)致的。

端口不存在
如果像不存在的端口發(fā)出建立連接 SYN 請求，那么服務(wù)端發(fā)現(xiàn)自己并沒有這個端口則會直接返回一個 RST 報文，用于中斷連接。

主動代替 FIN 終止連接
一般來說，正常的連接關(guān)閉都是需要通過 FIN 報文實現(xiàn)，然而我們也可以用 RST 報文來代替 FIN，表示直接終止連接。實際開發(fā)中，可設(shè)置 SO_LINGER 數(shù)值來控制，這種往往是故意的，來跳過 TIMED_WAIT，提供交互效率，不閑就慎用。

客戶端或服務(wù)端有一邊發(fā)生了異常，該方向?qū)Χ税l(fā)送 RST 以告知關(guān)閉連接
我們上面講的 tcp 隊列溢出發(fā)送 RST 包其實也是屬于這一種。這種往往是由于某些原因，一方無法再能正常處理請求連接了(比如程序崩了，隊列滿了)，從而告知另一方關(guān)閉連接。

接收到的 TCP 報文不在已知的 TCP 連接內(nèi)
比如，一方機器由于網(wǎng)絡(luò)實在太差 TCP 報文失蹤了，另一方關(guān)閉了該連接，然后過了許久收到了之前失蹤的 TCP 報文，但由于對應(yīng)的 TCP 連接已不存在，那么會直接發(fā)一個 RST 包以便開啟新的連接。

一方長期未收到另一方的確認報文，在一定時間或重傳次數(shù)后發(fā)出 RST 報文
這種大多也和網(wǎng)絡(luò)環(huán)境相關(guān)了，網(wǎng)絡(luò)環(huán)境差可能會導(dǎo)致更多的 RST 報文。

之前說過 RST 報文多會導(dǎo)致程序報錯，在一個已關(guān)閉的連接上讀操作會報connection reset，而在一個已關(guān)閉的連接上寫操作則會報connection reset by peer。通常我們可能還會看到broken pipe錯誤，這是管道層面的錯誤，表示對已關(guān)閉的管道進行讀寫，往往是在收到 RST，報出connection reset錯后繼續(xù)讀寫數(shù)據(jù)報的錯，這個在 glibc 源碼注釋中也有介紹。

我們在排查故障時候怎么確定有 RST 包的存在呢？當(dāng)然是使用 tcpdump 命令進行抓包，并使用 wireshark 進行簡單分析了。tcpdump -i en0 tcp -w xxx.cap，en0 表示監(jiān)聽的網(wǎng)卡。

TIME_WAIT
time_wait 的存在一是為了丟失的數(shù)據(jù)包被后面連接復(fù)用，二是為了在 2MSL 的時間范圍內(nèi)正常關(guān)閉連接。它的存在其實會大大減少 RST 包的出現(xiàn)。

過多的 time_wait 在短連接頻繁的場景比較容易出現(xiàn)。這種情況可以在服務(wù)端做一些內(nèi)核參數(shù)調(diào)優(yōu):

表示開啟重用。允許將TIME-WAIT sockets重新用于新的TCP連接，默認為0，表示關(guān)閉

net.ipv4.tcp_tw_reuse = 1

表示開啟TCP連接中TIME-WAIT sockets的快速回收，默認為0，表示關(guān)閉

net.ipv4.tcp_tw_recycle = 1

表示開啟重用。允許將TIME-WAIT sockets重新用于新的TCP連接，默認為0，表示關(guān)閉

net.ipv4.tcp_tw_reuse = 1

表示開啟TCP連接中TIME-WAIT sockets的快速回收，默認為0，表示關(guān)閉

net.ipv4.tcp_tw_recycle = 1
當(dāng)然我們不要忘記在 NAT 環(huán)境下因為時間戳錯亂導(dǎo)致數(shù)據(jù)包被拒絕的坑了，另外的辦法就是改小tcp_max_tw_buckets，超過這個數(shù)的 time_wait 都會被干掉，不過這也會導(dǎo)致報time wait bucket table overflow的錯。

CLOSE_WAIT
close_wait 往往都是因為應(yīng)用程序?qū)懙挠袉栴}，沒有在 ACK 后再次發(fā)起 FIN 報文。close_wait 出現(xiàn)的概率甚至比 time_wait 要更高，后果也更嚴(yán)重。往往是由于某個地方阻塞住了，沒有正常關(guān)閉連接，從而漸漸地消耗完所有的線程。

想要定位這類問題，最好是通過 jstack 來分析線程堆棧來排查問題，具體可參考上述章節(jié)。這里僅舉一個例子。

開發(fā)同學(xué)說應(yīng)用上線后 CLOSE_WAIT 就一直增多，直到掛掉為止，jstack 后找到比較可疑的堆棧是大部分線程都卡在了countdownlatch.await方法，找開發(fā)同學(xué)了解后得知使用了多線程但是確沒有 catch 異常，修改后發(fā)現(xiàn)異常僅僅是最簡單的升級 sdk 后常出現(xiàn)的class not found。

【云棲號在線課堂】每天都有產(chǎn)品技術(shù)專家分享！
課程地址：https://yqh.aliyun.com/zhibo
立即加入社群，與專家面對面，及時了解課程最新動態(tài)！
【云棲號在線課堂 社群】https://c.tb.cn/F3.Z8gvnK

原文發(fā)布時間：2020-04-29
本文作者：fredalxin
本文來自：“互聯(lián)網(wǎng)架構(gòu)師 微信公眾號”，了解相關(guān)信息可以關(guān)注“互聯(lián)網(wǎng)架構(gòu)師”

上云就看云棲號：更多云資訊，上云案例，最佳實踐，產(chǎn)品入門，訪問：https://yqh.aliyun.com/

創(chuàng)作挑戰(zhàn)賽新人創(chuàng)作獎勵來咯，堅持創(chuàng)作打卡瓜分現(xiàn)金大獎

總結(jié)

以上是生活随笔為你收集整理的java 日志乱码_【开发者成长】JAVA 线上故障排查完整套路！的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網(wǎng)站內(nèi)容還不錯，歡迎將生活随笔推薦給好友。