先說一下題外話,一個監控別人系統運行狀態的程序,結果自己出問題了,有時候想一想還是挺諷刺的,哈哈,開個玩笑,我們回到正題,前些天有位朋友找到我,說他們的系統會偶發性CPU爆高,CPU上去了就下不來了,讓我幫忙看一下怎么回事,而且自己也分析過了,沒找到哪里有問題,寫監控的都是高手,給我的第一感覺就是這個dump可能解決起來不容易,不管怎么說,有了dump就開干吧!
作為調試人,第一準則就是不要輕信任何人透露給你的信息,因為人家在這塊是一個小白,往往他的信息會把你帶偏,我們只相信數據即可,切記!!! 所以我們先用 !tp 觀察下CPU使用率。
0:198> !tpCPU utilization: 100%Worker Thread: Total: 197 Running: 42 Idle: 154 MaxLimit: 32767 MinLimit: 8Work Request in Queue: 0--------------------------------------Number of Timers: 0--------------------------------------Completion Port Thread:Total: 10 Free: 5 MaxFree: 16 CurrentLimit: 10 MaxLimit: 1000 MinLimit: 8
從卦中信息看當前 CPU=100%,還是蠻慘的,那到底誰在吃CPU資源呢?根據經驗先查一下是不是觸發了2代GC,接下來用 !t 觀察下是否有GC標記。
0:198> !tThreadCount: 214UnstartedThread: 0BackgroundThread: 211PendingThread: 0DeadThread: 1Hosted Runtime: no Lock ID OSID ThreadOBJ State GC Mode GC Alloc Context Domain Count Apt Exception 0 1 276f0 000002789526b5f0 2a020 Preemptive 0000000000000000:0000000000000000 000002789525e840 0 MTA 2 2 25e5c 0000027895296d00 2b220 Preemptive 0000000000000000:0000000000000000 000002789525e840 0 MTA (Finalizer) 3 3 260e8 00000278ae35f0c0 202b020 Preemptive 0000000000000000:0000000000000000 000002789525e840 0 MTA ... 169 2113 10c20 00000278c26766c0 1029220 Preemptive 00000278B5D7D188:00000278B5D7D188 000002789525e840 1 MTA (GC) (Threadpool Worker) xxxException 00000278b5d46ce0 ...
尼瑪從卦中的 (GC) 來看,還真的觸發了GC,接下來的研究方向就是洞察下是不是CPU爆高的禍首。
要尋找這個問題的答案,首先就是看下這次GC是不是 FullGC 即可,可以切到 169 號線程,觀察下線程棧。
0:169> k 10 # Child-SP RetAddr Call Site00 000000c4`36ffb798 00007ffc`d5f14313 ntdll!NtWaitForSingleObject+0x1401 000000c4`36ffb7a0 00007ffc`c927cb27 KERNELBASE!WaitForSingleObjectEx+0x9302 000000c4`36ffb840 00007ffc`c927cadf clr!CLREventWaitHelper2+0x3c03 000000c4`36ffb880 00007ffc`c927ca5c clr!CLREventWaitHelper+0x1f04 000000c4`36ffb8e0 00007ffc`c926bd32 clr!CLREventBase::WaitEx+0x7c05 000000c4`36ffb970 00007ffc`c9269bc4 clr!ThreadSuspend::SuspendRuntime+0x32c06 000000c4`36ffba60 00007ffc`c91814e3 clr!ThreadSuspend::SuspendEE+0x12807 000000c4`36ffbb60 00007ffc`c9185f51 clr!WKS::GCHeap::GarbageCollectGeneration+0xb708 000000c4`36ffbbc0 00007ffc`c9260f56 clr!WKS::gc_heap::trigger_gc_for_alloc+0x2d09 000000c4`36ffbc00 00007ffc`c6b0f7e7 clr!JIT_NewArr1+0xa970a 000000c4`36ffc030 00007ffc`6a388270 mscorlib_ni!System.String.ToCharArray+0x27 [f:/dd/ndp/clr/src/BCL/system/string.cs @ 758] 0b 000000c4`36ffc080 00007ffc`6a3880ed 0x00007ffc`6a3882700c 000000c4`36ffc100 00007ffc`6a56056d 0x00007ffc`6a3880ed0d 000000c4`36ffc150 00007ffc`6a3cd749 0x00007ffc`6a56056d0e 000000c4`36ffc1b0 00007ffc`c911989d 0x00007ffc`6a3cd7490f 000000c4`36ffc220 00007ffc`c9119764 clr!ExceptionTracker::CallHandler+0xfd
從卦中看此時的GC還處于早期的 SuspendEE 階段,無法獲取內部的 settings 結構,這就比較麻煩了,那怎么辦呢?只能看看 GarbageCollectGeneration 的第一個參數有沒有保存在棧中,要是沒有就慘了。。。方法簽名如下:
size_tGCHeap::GarbageCollectGeneration (unsigned int gen, gc_reason reason){}
根據 x64調用協定,gen是保存在 rdx 寄存器里,接下來觀察匯編代碼。
0:000> uf 00007ffc`c91814e3clr!WKS::GCHeap::GarbageCollectGeneration:00007ffc`c918142c 48895c2418 mov qword ptr [rsp+18h],rbx00007ffc`c9181431 89542410 mov dword ptr [rsp+10h],edx00007ffc`c9181435 48894c2408 mov qword ptr [rsp+8],rcx00007ffc`c918143a 55 push rbp00007ffc`c918143b 56 push rsi00007ffc`c918143c 57 push rdi00007ffc`c918143d 4154 push r1200007ffc`c918143f 4155 push r1300007ffc`c9181441 4156 push r1400007ffc`c9181443 4157 push r15...0:169> dd 000000c4`36ffbbc0-0x8+0x10 L1000000c4`36ffbbc8 00000000
從卦中看,謝天謝地,edx保存在 rsp+10h 的位置,通過dp觀察內存地址的值發現是0,也就表示當前是 0 代GC,這種smallgc 經常觸發是很正常的,并不是我們CPU爆高的誘因,接下來就陷入迷茫了。。。
撞了南墻之后得要看看其他路子,其實剛才用 !t 觀察線程列表的時候我就注意到一個特征,那就是很多線程上掛了異常,截圖如下:
圖片
從卦中看此時有19個線程在拋 xxxResultException 異常,做過開發的朋友都知道,如果頻繁的拋異常是很耗CPU資源的,因為它要設計到用戶態到內核態的切換,如果有 19 個線程一起拋異常,那絕對是一個災難。。。
有些朋友說我cpu猛一點是不是就可以了,哈哈,理論上是可以的,可以用 !cpuid 觀察下這臺機器的cpu核心數。
0:169> !cpuidCP F/M/S Manufacturer MHz 0 6,167,1 <unavailable> 3408 1 6,167,1 <unavailable> 3408 2 6,167,1 <unavailable> 3408 3 6,167,1 <unavailable> 3408 4 6,167,1 <unavailable> 3408 5 6,167,1 <unavailable> 3408 6 6,167,1 <unavailable> 3408 7 6,167,1 <unavailable> 3408
從證據鏈的完整性上來說,其實這里還需要再做一個驗證,就是19個線程拋異常不代表他們的并發性,言外之意就是能不能再找一些其他證據,怎么找其他證據呢?
做C#開發的朋友應該知道,Exception 屬于引用類型,如果密集拋了很多異常,那托管堆上自然就有很多,直到GC回收,所以我們觀察下這個時間差即可,使用 !wdae 命令,這里為了隱私性我就模糊了哈。
0:169> !wdae 384 of Type: xxxResultException 000002789fdb6478 000002789fdb69b0 000002789fdb9848Message: xxxFailedInner Exception: (none)Stack:IP Function00007ffc6a269861 xxx.ChannelAsyncOperation`1[[System.Int32, mscorlib]].End(Int32, Boolean)... 411 of Type: xxxResultException 000002789fdb6e90 000002789fdb7090 000002789fdb72a8Message: xxxClosedInner Exception: (none)Stack:IP Function00007ffc6a269861 xxx.ChannelAsyncOperation`1[[System.Int32, mscorlib]].End(Int32, Boolean)...808 Exceptions in 12 unique type/stack combinations (duplicate types in similar stacks may be rethrows)
從卦中看當前拋了808個異常,大多是和channel通信有關,結合16個線程并發拋,這就穩了,看樣子cpu爆高期間就是由于高頻的拋異常所致,分析出這些信息之后,就是告訴朋友把這些異常給解決掉即可。
CPU爆高的誘因非常多,高頻的拋異常就屬于其中一例,其實這種通信時發生了突發異常正是 Polly 這種 彈性和瞬態故障處理庫 大顯身手的地方。
本文鏈接:http://www.www897cc.com/showinfo-26-76498-0.html記一次 .NET某設備監控自動化系統 CPU爆高分析
聲明:本網頁內容旨在傳播知識,若有侵權等問題請及時與本網聯系,我們將在第一時間刪除處理。郵件:2376512515@qq.com
上一篇: 如何實現一個支持海量大并發的服務?