線上故障的排查清單,運維拿走不謝!

Linksla發表於2024-02-28
線上故障主要會包括CPU、磁碟、記憶體以及網路問題,而大多數故障可能會包含不止一個層面的問題,所以進行排查時候儘量四個方面依次排查一遍。

同時例如 jstack、jmap 等工具也是不囿於一個方面的問題的,基本上出問題就是df、free、top 三連,然後依次 jstack、jmap 伺候,具體問題具體分析即可。

CPU

一般來講我們首先會排查 CPU 方面的問題。CPU 異常往往還是比較好定位的。
原因包括業務邏輯問題(死迴圈)、頻繁gc以及上下文切換過多。而最常見的往往是業務邏輯(或者框架邏輯)導致的,可以使用jstack來分析對應的堆疊情況。

使用 jstack 分析 CPU 問題

我們先用 ps 命令找到對應程序的pid(如果你有好幾個目標程序,可以先用top看一下哪個佔用比較高)。

接著用 top -H -p pid 來找到 CPU 使用率比較高的一些執行緒

然後將佔用最高的 pid 轉換為 16 進位制 printf '%x\n' pid 得到 nid

接著直接在 jstack 中找到相應的堆疊資訊 jstack pid |grep 'nid' -C5 –color

可以看到我們已經找到了 nid 為 0x42 的堆疊資訊,接著只要仔細分析一番即可。

當然更常見的是我們對整個 jstack 檔案進行分析,通常我們會比較關注 WAITING 和 TIMED_WAITING 的部分,BLOCKED 就不用說了。我們可以使用命令

cat jstack.log | grep "java.lang.Thread.State" | sort -nr | uniq -c

來對 jstack 的狀態有一個整體的把握,如果 WAITING 之類的特別多,那麼多半是有問題啦。

頻繁 gc

當然我們還是會使用 jstack 來分析問題,但有時候我們可以先確定下 gc 是不是太頻繁,使用 jstat -gc pid 1000 命令來對 gc 分代變化情況進行觀察,1000 表示取樣間隔(ms),S0C/S1C、S0U/S1U、EC/EU、OC/OU、MC/MU 分別代表兩個 Survivor 區、Eden 區、老年代、後設資料區的容量和使用量。

YGC/YGT、FGC/FGCT、GCT 則代表 YoungGc 、FullGc 的耗時和次數以及總耗時。如果看到 gc 比較頻繁,再針對 gc 方面做進一步分析,具體可以參考一下 gc 章節的描述。

上下文切換

針對頻繁上下文問題,我們可以使用 vmstat 命令來進行檢視

cs(context switch)一列則代表了上下文切換的次數。

如果我們希望對特定的 pid 進行監控那麼可以使用 pidstat -w pid 命令,cswch 和 nvcswch 表示自願及非自願切換。

磁碟

磁碟問題和 CPU 一樣是屬於比較基礎的。首先是磁碟空間方面,我們直接使用 df -hl 來檢視檔案系統狀態

更多時候,磁碟問題還是效能上的問題。我們可以透過 iostat -d -k -x 來進行分析

最後一列%util可以看到每塊磁碟寫入的程度,而rrqpm/s以及wrqm/s分別表示讀寫速度,一般就能幫助定位到具體哪塊磁碟出現問題了。
另外我們還需要知道是哪個程序在進行讀寫,一般來說開發自己心裡有數,或者用 iotop 命令來進行定位檔案讀寫的來源。

不過這邊拿到的是 tid,我們要轉換成 pid,可以透過 readlink 來找到 pidreadlink -f /proc/*/task/tid/../..。

找到 pid 之後就可以看這個程序具體的讀寫情況cat /proc/pid/io

我們還可以透過 lsof 命令來確定具體的檔案讀寫情況 lsof -p pid

記憶體

記憶體問題排查起來相對比 CPU 麻煩一些,場景也比較多。主要包括 OOM、GC 問題和堆外記憶體。一般來講,我們會先用 free 命令先來檢查一發記憶體的各種情況。

堆內記憶體

記憶體問題大多還都是堆內記憶體問題。表象上主要分為 OOM 和 Stack Overflow。

OOM

JMV 中的記憶體不足,OOM 大致可以分為以下幾種:

Exception in thread “main” java.lang.OutOfMemoryError: unable to create new native thread

這個意思是沒有足夠的記憶體空間給執行緒分配 Java 棧,基本上還是執行緒池程式碼寫的有問題,比如說忘記 shutdown,所以說應該首先從程式碼層面來尋找問題,使用 jstack 或者 jmap。如果一切都正常,JVM 方面可以透過指定Xss來減少單個 thread stack 的大小。另外也可以在系統層面,可以透過修改/etc/security/limits.confnofile 和 nproc 來增大 os 對執行緒的限制。

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

這個意思是堆的記憶體佔用已經達到-Xmx 設定的最大值,應該是最常見的 OOM 錯誤了。解決思路仍然是先應該在程式碼中找,懷疑存在記憶體洩漏,透過 jstack 和 jmap 去定位問題。如果說一切都正常,才需要透過調整Xmx的值來擴大記憶體。

Caused by: java.lang.OutOfMemoryError: Meta space

這個意思是後設資料區的記憶體佔用已經達到XX:MaxMetaspaceSize設定的最大值,排查思路和上面的一致,引數方面可以透過XX:MaxPermSize來進行調整(這裡就不說 1.8 以前的代了)。

Stack Overflow

棧記憶體溢位,這個大家見到也比較多。

Exception in thread “main” java.lang.StackOverflowError

表示執行緒棧需要的記憶體大於 Xss 值,同樣也是先進行排查,引數方面透過Xss來調整,但調整的太大可能又會引起 OOM。

使用 JMAP 定位程式碼記憶體洩漏

上述關於 OOM 和 Stack Overflow 的程式碼排查方面,我們一般使用 JMAPjmap -dump:format=b,file=filename pid來匯出 dump 檔案

透過 mat(Eclipse Memory Analysis Tools)匯入 dump 檔案進行分析,記憶體洩漏問題一般我們直接選 Leak Suspects 即可,mat 給出了記憶體洩漏的建議。另外也可以選擇 Top Consumers 來檢視最大物件報告。

和執行緒相關的問題可以選擇 thread overview 進行分析。除此之外就是選擇 Histogram 類概覽來自己慢慢分析,大家可以搜搜 mat 的相關教程。

日常開發中,程式碼產生記憶體洩漏是比較常見的事,並且比較隱蔽,需要開發者更加關注細節。比如說每次請求都 new 物件,導致大量重複建立物件;進行檔案流操作但未正確關閉;手動不當觸發 gc;ByteBuffer 快取分配不合理等都會造成程式碼 OOM。

另一方面,我們可以在啟動引數中指定-XX:+HeapDumpOnOutOfMemoryError來儲存 OOM 時的 dump 檔案。

gc 問題和執行緒

gc 問題除了影響 CPU 也會影響記憶體,排查思路也是一致的。一般先使用 jstat 來檢視分代變化情況,比如 youngGC 或者 fullGC 次數是不是太多呀;EU、OU 等指標增長是不是異常呀等。

執行緒的話太多而且不被及時 gc 也會引發 oom,大部分就是之前說的unable to create new native thread。除了 jstack 細細分析 dump 檔案外,我們一般先會看下總體執行緒,透過 pstreee -p pid |wc -l。

或者直接透過檢視/proc/pid/task的數量即為執行緒數量。

堆外記憶體

如果碰到堆外記憶體溢位,那可真是太不幸了。首先堆外記憶體溢位表現就是物理常駐記憶體增長快,報錯的話視使用方式都不確定,如果由於使用 Netty 導致的,那錯誤日誌裡可能會出現OutOfDirectMemoryError錯誤,如果直接是 DirectByteBuffer,那會報 OutOfMemoryError: Direct buffer memory

堆外記憶體溢位往往是和 NIO 的使用相關,一般我們先透過 pmap 來檢視下程序佔用的記憶體情況

pmap -x pid | sort -rn -k3 | head -30

這段意思是檢視對應 pid 倒序前 30 大的記憶體段。這邊可以再一段時間後再跑一次命令看看記憶體增長情況,或者和正常機器比較可疑的記憶體段在哪裡。

我們如果確定有可疑的記憶體端,需要透過 gdb 來分析

gdb --batch --pid {pid} -ex "dump memory filename.dump {記憶體起始地址} {記憶體起始地址+記憶體塊大小}"

獲取 dump 檔案後可用 heaxdump 進行檢視hexdump -C filename | less,不過大多數看到的都是二進位制亂碼。

NMT 是 Java7U40 引入的 HotSpot 新特性,配合 jcmd 命令我們就可以看到具體記憶體組成了。需要在啟動引數中加入 -XX:NativeMemoryTracking=summary 或者 -XX:NativeMemoryTracking=detail,會有略微效能損耗。

一般對於堆外記憶體緩慢增長直到爆炸的情況來說,可以先設一個基線

jcmd pid VM.native_memory baseline

然後等放一段時間後再去看看記憶體增長的情況,透過jcmd pid VM.native_memory detail.diff(summary.diff)做一下 summary 或者 detail 級別的 diff。

可以看到 jcmd 分析出來的記憶體十分詳細,包括堆內、執行緒以及 gc(所以上述其他記憶體異常其實都可以用 nmt 來分析),這邊堆外記憶體我們重點關注 Internal 的記憶體增長,如果增長十分明顯的話那就是有問題了。

detail 級別的話還會有具體記憶體段的增長情況,如下圖。

此外在系統層面,我們還可以使用 strace 命令來監控記憶體分配 strace -f -e “brk,mmap,munmap” -p pid

這邊記憶體分配資訊主要包括了 pid 和記憶體地址。

不過其實上面那些操作也很難定位到具體的問題點,關鍵還是要看錯誤日誌棧,找到可疑的物件,搞清楚它的回收機制,然後去分析對應的物件。比如 DirectByteBuffer 分配記憶體的話,是需要 full GC 或者手動 system.gc 來進行回收的(所以最好不要使用-XX:+DisableExplicitGC)。

那麼其實我們可以跟蹤一下 DirectByteBuffer 物件的記憶體情況,透過jmap -histo:live pid手動觸發 fullGC 來看看堆外記憶體有沒有被回收。如果被回收了,那麼大機率是堆外記憶體本身分配的太小了,透過-XX:MaxDirectMemorySize進行調整。如果沒有什麼變化,那就要使用 jmap 去分析那些不能被 gc 的物件,以及和 DirectByteBuffer 之間的引用關係了。

GC 問題

堆內記憶體洩漏總是和 GC 異常相伴。不過 GC 問題不只是和記憶體問題相關,還有可能引起 CPU 負載、網路問題等系列併發症,只是相對來說和記憶體聯絡緊密些,所以我們在此單獨總結一下 GC 相關問題。

我們在 CPU 章介紹了使用 jstat 來獲取當前 GC 分代變化資訊。而更多時候,我們是透過 GC 日誌來排查問題的,在啟動引數中加上-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps來開啟 GC 日誌。

常見的 Young GC、Full GC 日誌含義在此就不做贅述了。

針對 gc 日誌,我們就能大致推斷出 youngGC 與 fullGC 是否過於頻繁或者耗時過長,從而對症下藥。我們下面將對 G1 垃圾收集器來做分析,這邊也建議大家使用 G1-XX:+UseG1GC。

youngGC 過頻繁

youngGC 頻繁一般是短週期小物件較多,先考慮是不是 Eden 區/新生代設定的太小了,看能否透過調整-Xmn、-XX:SurvivorRatio 等引數設定來解決問題。如果引數正常,但是 young gc 頻率還是太高,就需要使用 Jmap 和 MAT 對 dump 檔案進行進一步排查了。

youngGC 耗時過長

耗時過長問題就要看 GC 日誌裡耗時耗在哪一塊了。以 G1 日誌為例,可以關注 Root Scanning、Object Copy、Ref Proc 等階段。Ref Proc 耗時長,就要注意引用相關的物件。Root Scanning 耗時長,就要注意執行緒數、跨代引用。Object Copy 則需要關注物件生存週期。

而且耗時分析它需要橫向比較,就是和其他專案或者正常時間段的耗時比較。比如說圖中的 Root Scanning 和正常時間段比增長較多,那就是起的執行緒太多了。

觸發 fullGC

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

fullGC 的原因可能包括以下這些,以及引數調整方面的一些思路:

  • 併發階段失敗:在併發標記階段,MixGC 之前老年代就被填滿了,那麼這時候 G1 就會放棄標記週期。這種情況,可能就需要增加堆大小,或者調整併發標記執行緒數-XX:ConcGCThreads。

  • 晉升失敗:在 GC 的時候沒有足夠的記憶體供存活/晉升物件使用,所以觸發了 Full GC。這時候可以透過-XX:G1ReservePercent來增加預留記憶體百分比,減少-XX:InitiatingHeapOccupancyPercent來提前啟動標記,-XX:ConcGCThreads來增加標記執行緒數也是可以的。

  • 大物件分配失敗:大物件找不到合適的 region 空間進行分配,就會進行 fullGC,這種情況下可以增大記憶體或者增大-XX:G1HeapRegionSize。

  • 程式主動執行 System.gc():不要隨便寫就對了。

另外,我們可以在啟動引數中配置-XX:HeapDumpPath=/xxx/dump.hprof來 dump fullGC 相關的檔案,並透過 jinfo 來進行 gc 前後的 dump

jinfo -flag +HeapDumpBeforeFullGC pidjinfo -flag +HeapDumpAfterFullGC pidjinfo -flag +HeapDumpBeforeFullGC pidjinfo -flag +HeapDumpAfterFullGC pid

這樣得到 2 份 dump 檔案,對比後主要關注被 gc 掉的問題物件來定位問題。

網路

涉及到網路層面的問題一般都比較複雜,場景多,定位難,成為了大多數開發的噩夢,應該是最複雜的了。這裡會舉一些例子,並從 tcp 層、應用層以及工具的使用等方面進行闡述。

超時

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

  • 讀寫超時。readTimeout/writeTimeout,有些框架叫做 so_timeout 或者 socketTimeout,均指的是資料讀寫超時。注意這邊的超時大部分是指邏輯上的超時。soa 的超時指的也是讀超時。讀寫超時一般都只針對客戶端設定。

  • 連線超時。connectionTimeout,客戶端通常指與服務端建立連線的最大時間。服務端這邊 connectionTimeout 就有些五花八門了, Jetty 中表示空閒連線清理時間,Tomcat 則表示連線維持的最大時間。

  • 其他。包括連線獲取超時 connectionAcquireTimeout 和空閒連線清理超時 idleConnectionTimeout。多用於使用連線池或佇列的客戶端或服務端框架。

我們在設定各種超時時間中,需要確認的是儘量保持客戶端的超時小於服務端的超時,以保證連線正常結束。

在實際開發中,我們關心最多的應該是介面的讀寫超時了。

如何設定合理的介面超時是一個問題。如果介面超時設定的過長,那麼有可能會過多地佔用服務端的 tcp 連線。而如果介面設定的過短,那麼介面超時就會非常頻繁。

服務端介面明明 rt 降低,但客戶端仍然一直超時又是另一個問題。這個問題其實很簡單,客戶端到服務端的鏈路包括網路傳輸、排隊以及服務處理等,每一個環節都可能是耗時的原因。

TCP 佇列溢位

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

如上圖所示,這裡有兩個佇列:syns queue(半連線佇列)、accept queue(全連線佇列)。三次握手,在 server 收到 client 的 syn 後,把訊息放到 syns queue,回覆 syn+ack 給 client,server 收到 client 的 ack,如果這時 accept queue 沒滿,那就從 syns queue 拿出暫存的資訊放入 accept queue 中,否則按 tcp_abort_on_overflow 指示的執行。

tcp_abort_on_overflow 0 表示如果三次握手第三步的時候 accept queue 滿了那麼 server 扔掉 client 發過來的 ack。tcp_abort_on_overflow 1 則表示第三步的時候如果全連線佇列滿了,server 傳送一個 rst 包給 client,表示廢掉這個握手過程和這個連線,意味著日誌裡可能會有很多connection reset / connection reset by peer。

那麼在實際開發中,我們怎麼能快速定位到 tcp 佇列溢位呢?

netstat 命令,執行 netstat -s | egrep “listen|LISTEN”

如上圖所示,overflowed 表示全連線佇列溢位的次數,sockets dropped 表示半連線佇列溢位的次數。

ss 命令,執行 ss -lnt

上面看到 Send-Q 表示第三列的 listen 埠上的全連線佇列最大為 5,第一列 Recv-Q 為全連線佇列當前使用了多少。

接著我們看看怎麼設定全連線、半連線佇列大小吧:

全連線佇列的大小取決於 min(backlog, somaxconn)。backlog 是在 socket 建立的時候傳入的,somaxconn 是一個 os 級別的系統引數。而半連線佇列的大小取決於 max(64, /proc/sys/net/ipv4/tcp_max_syn_backlog)。

在日常開發中,我們往往使用 servlet 容器作為服務端,所以我們有時候也需要關注容器的連線佇列大小。在 Tomcat 中 backlog 叫做acceptCount,在 Jetty 裡面則是acceptQueueSize。

RST 異常

RST 包表示連線重置,用於關閉一些無用的連線,通常表示異常關閉,區別於四次揮手。

在實際開發中,我們往往會看到connection reset / connection reset by peer錯誤,這種情況就是 RST 包導致的。

埠不存在

如果像不存在的埠發出建立連線 SYN 請求,那麼服務端發現自己並沒有這個埠則會直接返回一個 RST 報文,用於中斷連線。

主動代替 FIN 終止連線

一般來說,正常的連線關閉都是需要透過 FIN 報文實現,然而我們也可以用 RST 報文來代替 FIN,表示直接終止連線。實際開發中,可設定 SO_LINGER 數值來控制,這種往往是故意的,來跳過 TIMED_WAIT,提供互動效率,不閒就慎用。

客戶端或服務端有一邊發生了異常,該方向對端傳送 RST 以告知關閉連線

我們上面講的 tcp 佇列溢位傳送 RST 包其實也是屬於這一種。這種往往是由於某些原因,一方無法再能正常處理請求連線了(比如程式崩了,佇列滿了),從而告知另一方關閉連線。

接收到的 TCP 報文不在已知的 TCP 連線內

比如,一方機器由於網路實在太差 TCP 報文失蹤了,另一方關閉了該連線,然後過了許久收到了之前失蹤的 TCP 報文,但由於對應的 TCP 連線已不存在,那麼會直接發一個 RST 包以便開啟新的連線。

接下來我們透過 wireshark 開啟抓到的包,可能就能看到如下圖所示,紅色的就表示 RST 包了。

TIME_WAIT 和 CLOSE_WAIT

TIME_WAIT 和 CLOSE_WAIT 是啥意思相信大家都知道。

線上上時,我們可以直接用命令netstat -n | awk ‘/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}’來檢視 time-wait 和 close_wait 的數量

用 ss 命令會更快ss -ant | awk ‘{++S[$1]} END {for(a in S) print a, S[a]}’

TIME_WAIT

time_wait 的存在一是為了丟失的資料包被後面連線複用,二是為了在 2MSL 的時間範圍內正常關閉連線。它的存在其實會大大減少 RST 包的出現。

過多的 time_wait 在短連線頻繁的場景比較容易出現。這種情況可以在服務端做一些核心引數調優:

    
    
    #表示開啟重用。允許將TIME-WAIT sockets重新用於新的TCP連線,預設為0,表示關閉
    
    
    
    net.ipv4.tcp_tw_reuse = 1
    #表示開啟TCP連線中TIME-WAIT sockets的快速回收,預設為0,表示關閉
    net.ipv4.tcp_tw_recycle = 1

    當然我們不要忘記在 NAT 環境下因為時間戳錯亂導致資料包被拒絕的坑了,另外的辦法就是改小 tcp_max_tw_buckets ,超過這個數的 time_wait 都會被幹掉,不過這也會導致報 time wait bucket table overflow 的錯。

    CLOSE_WAIT

    close_wait 往往都是因為應用程式寫的有問題,沒有在 ACK 後再次發起 FIN 報文。close_wait 出現的機率甚至比 time_wait 要更高,後果也更嚴重。往往是由於某個地方阻塞住了,沒有正常關閉連線,從而漸漸地消耗完所有的執行緒。

    想要定位這類問題,最好是透過 jstack 來分析執行緒堆疊來排查問題,具體可參考上述章節。這裡僅舉一個例子。

    開發同學說應用上線後 CLOSE_WAIT 就一直增多,直到掛掉為止,jstack 後找到比較可疑的堆疊是大部分執行緒都卡在了countdownlatch.await方法,找開發同學瞭解後得知使用了多執行緒但是確沒有 catch 異常,修改後發現異常僅僅是最簡單的升級 sdk 後常出現的class not found。

    一方長期未收到另一方的確認報文,在一定時間或重傳次數後發出 RST 報文

    這種大多也和網路環境相關了,網路環境差可能會導致更多的 RST 報文。

    之前說過 RST 報文多會導致程式報錯,在一個已關閉的連線上讀操作會報connection reset,而在一個已關閉的連線上寫操作則會報connection reset by peer。通常我們可能還會看到broken pipe錯誤,這是管道層面的錯誤,表示對已關閉的管道進行讀寫,往往是在收到 RST,報出connection reset錯後繼續讀寫資料包的錯,這個在 glibc 原始碼註釋中也有介紹。

    我們在排查故障時候怎麼確定有 RST 包的存在呢?當然是使用 tcpdump 命令進行抓包,並使用 wireshark 進行簡單分析了。tcpdump -i en0 tcp -w xxx.cap,en0 表示監聽的網路卡。

    來源:


    來自 “ ITPUB部落格 ” ,連結:https://blog.itpub.net/70013542/viewspace-3007550/,如需轉載,請註明出處,否則將追究法律責任。

    相關文章