一:背景 1. 講故事 最近也挺奇怪,看到了兩起 CPU 爆高的案例,且誘因也是一致的,覺得有一些代表性,合併分享出來幫助大家來避坑吧,閑話不多說,直接上 windbg 分析。 二:WinDbg 分析 1. CPU 真的爆高嗎 這裡要提醒一下,別人說爆高不一定真的就是爆高,我們一定要拿數據說話,可以 ...
一:背景
1. 講故事
最近也挺奇怪,看到了兩起 CPU 爆高的案例,且誘因也是一致的,覺得有一些代表性,合併分享出來幫助大家來避坑吧,閑話不多說,直接上 windbg 分析。
二:WinDbg 分析
1. CPU 真的爆高嗎
這裡要提醒一下,別人說爆高不一定真的就是爆高,我們一定要拿數據說話,可以用 !tp
觀察下。
0:000> !tp
logStart: 132
logSize: 200
CPU utilization: 59 %
Worker Thread: Total: 6 Running: 6 Idle: 0 MaxLimit: 10 MinLimit: 4
Work Request in Queue: 0
--------------------------------------
Number of Timers: 3
--------------------------------------
Completion Port Thread:Total: 2 Free: 2 MaxFree: 8 CurrentLimit: 2 MaxLimit: 10 MinLimit: 4
雖然卦中的 CPU 不低但也不是我理想的閾值,不過分析也是可以分析的,知道了 CPU 的利用率,接下來我們看下這個 CPU 猛不猛,使用 !cpuid
看下核心數。
0:000> !cpuid
CP F/M/S Manufacturer MHz
0 6,167,1 <unavailable> 199
1 6,167,1 <unavailable> 199
2 6,167,1 <unavailable> 199
3 6,167,1 <unavailable> 199
只有四個核心,看樣子這 CPU 不咋地哈,接下來的問題是誰導致了 CPU 爆高呢?
2. 是誰導致的 CPU 爆高
如果你剛纔仔細看 !tp
的輸出,應該會發現這麼一句話 Total: 6 Running: 6
,這表示當前線程池中的所有工作線程火力全開,有了這個現象,思路就比較明朗了,為什麼會火力全開,這些線程此時都在乾什麼? 我們使用 ~*e !clrstack
觀察一下。
0:000> ~*e !clrstack
...
OS Thread Id: 0x1dd8 (58)
Child SP IP Call Site
...
00000065F623F360 00007ffc38383a06 xxx+c__DisplayClass18_0.b__0(System.Object)
00000065F623FA00 00007ffc385680e2 System.Threading.ThreadPoolWorkQueue.Dispatch() [/_/src/libraries/System.Private.CoreLib/src/System/Threading/ThreadPoolWorkQueue.cs @ 729]
00000065F623FA90 00007ffc9638e3ee System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart() [/_/src/libraries/System.Private.CoreLib/src/System/Threading/PortableThreadPool.WorkerThread.cs @ 63]
00000065F623FBA0 00007ffc96372eaf System.Threading.Thread.StartCallback() [/_/src/coreclr/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs @ 105]
00000065F623FE30 00007ffc9730af03 [DebuggerU2MCatchHandlerFrame: 00000065f623fe30]
OS Thread Id: 0x15a8 (59)
Child SP IP Call Site
00000065F63BE6F8 00007ffca6905d14 [InlinedCallFrame: 00000065f63be6f8] Interop+Winsock.recv(System.Net.Sockets.SafeSocketHandle, Byte*, Int32, System.Net.Sockets.SocketFlags)
00000065F63BE6F8 00007ffc38521441 [InlinedCallFrame: 00000065f63be6f8] Interop+Winsock.recv(System.Net.Sockets.SafeSocketHandle, Byte*, Int32, System.Net.Sockets.SocketFlags)
00000065F63BE6C0 00007ffc38521441 ILStubClass.IL_STUB_PInvoke(System.Net.Sockets.SafeSocketHandle, Byte*, Int32, System.Net.Sockets.SocketFlags)
00000065F63BE790 00007ffc385679d1 System.Net.Sockets.Socket.Receive(Byte[], Int32, Int32, System.Net.Sockets.SocketFlags, System.Net.Sockets.SocketError ByRef) [/_/src/libraries/System.Net.Sockets/src/System/Net/Sockets/Socket.cs @ 1473]
...
00000065F63BF140 00007ffc3838ae0b xxx+c__DisplayClass18_0.b__0(System.Object)
00000065F63BF7E0 00007ffc385680e2 System.Threading.ThreadPoolWorkQueue.Dispatch() [/_/src/libraries/System.Private.CoreLib/src/System/Threading/ThreadPoolWorkQueue.cs @ 729]
00000065F63BF870 00007ffc9638e3ee System.Threading.PortableThreadPool+WorkerThread.WorkerThreadStart() [/_/src/libraries/System.Private.CoreLib/src/System/Threading/PortableThreadPool.WorkerThread.cs @ 63]
00000065F63BF980 00007ffc96372eaf System.Threading.Thread.StartCallback() [/_/src/coreclr/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs @ 105]
00000065F63BFC10 00007ffc9730af03 [DebuggerU2MCatchHandlerFrame: 00000065f63bfc10]
通過仔細觀察各個線程的線程棧,發現最多的是 xxx+c__DisplayClass18_0.b__0
方法,從底層的 PortableThreadPool
來看,這是 C# 自己封裝的線程池,說明這是由 線程池工作線程創建的,再輔助一張截圖:
接下來的方向是 xxx+c__DisplayClass18_0.b__0
為何方神聖,可能有些朋友對這種方法命名很奇怪,這裡解釋一下,一般都是 await, async
的底層弄出來的,由大量的狀態機方法所致。
3. c__DisplayClass18_0 到底寫了什麼
知道了這個方法,接下來可以用 ILSPY 去觀察下這段代碼,截圖如下:
上面這段代碼不知道大家有沒有看出什麼問題? 至少我看到這樣的代碼我就知道 CPU 為什麼會爆高了,兩點原因。
- 偷懶,無腦往線程池丟,導致線程增多
- 線程中方法時間複雜度高。
關於時間複雜度高,在子函數很容易就能找到諸如此類代碼,將一個 hash 用在了一個它最不擅長的地方,複雜度一下子就上來了。
public static xxx Getxxx(xxx conxx)
{
xxx xxxInfo2 = conxxx;
lock (xxx)
{
return hashxxxnfo.Where((xxxInfo x) => x.xxx == xxx.xxx && x.xxx == xxx.intPtr)?.FirstOrDefault();
}
}
4. 其他dump呢
剛纔我也說了,最近是連續看到了兩個,另外一個也是很奇葩的,而且還更嚴重,使用 !tp
觀察一下。
0:000> !tp
CPU utilization: 92%
Worker Thread: Total: 16 Running: 16 Idle: 0 MaxLimit: 32767 MinLimit: 16
Work Request in Queue: 17
AsyncTimerCallbackCompletion TimerInfo@000000e644d32df0
Unknown Function: 00007fff29dc17d0 Context: 000000e136337f58
Unknown Function: 00007fff29dc17d0 Context: 000000e136344798
Unknown Function: 00007fff29dc17d0 Context: 000000e1363479a8
...
Unknown Function: 00007fff29dc17d0 Context: 000000e135730720
Unknown Function: 00007fff29dc17d0 Context: 000000e13573ccd8
--------------------------------------
Number of Timers: 0
--------------------------------------
Completion Port Thread:Total: 1 Free: 1 MaxFree: 32 CurrentLimit: 1 MaxLimit: 1000 MinLimit: 16
從卦中看,cpu利用率更高,線程池隊列還有任務堆積,用同樣的方式也洞察出了它的問題代碼,也是一個無腦丟。
5. 如何優化
要想把 CPU 弄下去,無非就是在 生產端 和 消費端 進行雙向打磨。
- 生產端
嚴格控制線程
的個數,以排隊的方式定時定量的處理,嚴禁無腦丟,因為運行的線程少了,cpu自然就下去了。
- 消費端
很多朋友寫代碼不註意時間複雜度,或者根本不關心,導致數據量稍微大一點,代碼就接近死迴圈,真的是無語死了,所以儘量把代碼性能優化再優化,提高單次處理速度,讓 消費端 接待能力 大大超出 生產端。
三:總結
這兩個 CPU 爆高事故還是非常經典的,根子上還是有不少初中級程式員具有 偷懶 + 無視演算法
的思維,謹以這篇讓後來的朋友少踩坑吧!