記一次 .NET 某電商醫(yī)藥網(wǎng)站 CPU 爆高分析
作者：一線碼農(nóng)聊技術(shù)
前些天有位朋友找到我，說(shuō)他們的網(wǎng)站會(huì)有CPU瞬高的情況，在網(wǎng)上找相關(guān)資料最終找到我這邊，想讓我?guī)兔Ψ治鱿抡厥?？像這種CPU瞬高，比較好的方式就是用procdump自動(dòng)化的抓取，萬(wàn)不可手工去抓，接下來(lái)就上 windbg 分析吧。
一、背景
1. 講故事
準(zhǔn)備明年把.NET高級(jí)調(diào)試的訓(xùn)練營(yíng)的課程進(jìn)行重構(gòu)，采用案例引導(dǎo)式，而CPU爆高類(lèi)有不少是程序員在寫(xiě)代碼的時(shí)候不注意時(shí)間復(fù)雜度，在數(shù)據(jù)量稍微大一點(diǎn)的情況直接幻化成了死循環(huán)，時(shí)間復(fù)雜度這東西是學(xué)校的數(shù)據(jù)結(jié)構(gòu)課程，有心的朋友在寫(xiě)多層循環(huán)的時(shí)候腦子里面一定要過(guò)一遍，今天就給大家?guī)б黄祟?lèi)案例，也算是繼續(xù)豐富我的新課程體系。
前些天有位朋友找到我，說(shuō)他們的網(wǎng)站會(huì)有CPU瞬高的情況，在網(wǎng)上找相關(guān)資料最終找到我這邊，想讓我?guī)兔Ψ治鱿抡厥?？像這種CPU瞬高，比較好的方式就是用procdump自動(dòng)化的抓取，萬(wàn)不可手工去抓，接下來(lái)就上 windbg 分析吧。
二、WinDbg分析
1. 為什么會(huì)CPU爆高
以終為始，先看看CPU是否真的高，可以用 !tp 和 !cpuid 命令觀察，這里稍微提一下，為什么要用 !cpuid 看看CPU的能力呢？這是因?yàn)槲以?jīng)分析過(guò)只有 2core 的CPU。尼瑪，只有2個(gè)core，還分析個(gè)毛線哈，干脆把機(jī)器關(guān)了，這樣CPU就不高了。。。自此以后我就留了一個(gè)心眼，輸出參考如下：
0:033> !tp
CPU utilization: 100%
Worker Thread: Total: 5 Running: 5 Idle: 0 MaxLimit: 32767 MinLimit: 4
Work Request in Queue: 11
Unknown Function: 00007ffbfaa417d0 Context: 00000283733c3718
Unknown Function: 00007ffbfaa417d0 Context: 0000027f26f50cb0
Unknown Function: 00007ffbfaa417d0 Context: 0000028377199f58
AsyncTimerCallbackCompletion TimerInfo@0000028371c46820
AsyncTimerCallbackCompletion TimerInfo@0000028371d06800
Unknown Function: 00007ffbfaa417d0 Context: 00000283756d3248
Unknown Function: 00007ffbfaa417d0 Context: 0000027f26f63578
Unknown Function: 00007ffbfaa417d0 Context: 00000283733d0160
Unknown Function: 00007ffbfaa417d0 Context: 00000283756a72d8
Unknown Function: 00007ffbfaa417d0 Context: 00000283771a6828
Unknown Function: 00007ffbfaa417d0 Context: 000002837719d1f8
--------------------------------------
Number of Timers: 0
--------------------------------------
Completion Port Thread:Total: 3 Free: 2 MaxFree: 8 CurrentLimit: 2 MaxLimit: 1000 MinLimit: 4
0:033> !cpuid
CP F/M/S Manufacturer MHz
0 6,106,6 <unavailable> 2800
1 6,106,6 <unavailable> 2800
2 6,106,6 <unavailable> 2800
3 6,106,6 <unavailable> 2800從卦中可以看出當(dāng)前線程池隊(duì)列稍有積壓，5個(gè)托管線程全部被打滿，并且當(dāng)前機(jī)器是4個(gè)核，看樣子是有4個(gè)線程在滿負(fù)荷跑呀。。。
2. 線程都在干什么
為了追蹤線程都在干什么？使用 ~*e !clrstack 觀察各個(gè)線程的調(diào)用棧，結(jié)合程序的瞬高特性，捕獲了一個(gè)相對(duì)來(lái)說(shuō)高度可疑的代碼，參考如下：
OS Thread Id: 0x2f00 (33)
Child SP IP Call Site
000000f2a42fd508 00007ffbfd72b0a7 System.String.Equals(System.String, System.String) [f:\dd\ndp\clr\src\BCL\system\string.cs @ 647]
000000f2a42fd510 00007ffba1715a0b xxx.StockAsyncDbTask+c__DisplayClass4_1.b__6(xxx.GoodsInfo)
000000f2a42fd540 00007ffba118c6ca System.Linq.Enumerable.FirstOrDefault[[System.__Canon, mscorlib]](System.Collections.Generic.IEnumerable`1<System.__Canon>, System.Func`2<System.__Canon,Boolean>)
000000f2a42fd5b0 00007ffba1716008 xxx.StockAsyncDbTask+c__DisplayClass4_0.b__2(xxx.GoodsInfo)
000000f2a42fd670 00007ffbfd720505 System.Collections.Generic.List`1[[System.__Canon, mscorlib]].ForEach(System.Action`1<System.__Canon>) [f:\dd\ndp\clr\src\BCL\system\collections\generic\list.cs @ 553]
000000f2a42fd6c0 00007ffba1349e7e xxx.SaveStockToDb()
000000f2a42fd760 00007ffba13487ed xxx.DoWork()
000000f2a42fd7b0 00007ffba1348631 xxx.QuartzScheduler.QuartzJob.Quartz.IJob.Execute(Quartz.IJobExecutionContext)
000000f2a42fd8b0 00007ffba0f8ca12 Quartz.Core.JobRunShell+d__9.MoveNext()
000000f2a42fdb80 00007ffba0f83150 System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[[Quartz.Core.JobRunShell+d__9, Quartz]](d__9 ByRef) [f:\dd\ndp\clr\src\BCL\system\runtime\compilerservices\AsyncMethodBuilder.cs @ 322]
000000f2a42fdc30 00007ffba0f8309d Quartz.Core.JobRunShell.Run(System.Threading.CancellationToken)
000000f2a42fdd30 00007ffba0f829f4 Quartz.Core.QuartzSchedulerThread+c__DisplayClass28_0.b__0()
000000f2a42fdd60 00007ffbfd7abe4e System.Threading.Tasks.Task`1[[System.__Canon, mscorlib]].InnerInvoke() [f:\dd\ndp\clr\src\BCL\system\threading\Tasks\Future.cs @ 680]
000000f2a42fddb0 00007ffbfd7aaf27 System.Threading.Tasks.Task.Execute() [f:\dd\ndp\clr\src\BCL\system\threading\Tasks\Task.cs @ 2498]
000000f2a42fddf0 00007ffbfd73df12 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\executioncontext.cs @ 980]
000000f2a42fdec0 00007ffbfd73dd95 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\executioncontext.cs @ 928]
000000f2a42fdef0 00007ffbfd7ab1e1 System.Threading.Tasks.Task.ExecuteWithThreadLocal(System.Threading.Tasks.Task ByRef) [f:\dd\ndp\clr\src\BCL\system\threading\Tasks\Task.cs @ 2827]
000000f2a42fdfa0 00007ffbfd7aa8c1 System.Threading.Tasks.Task.ExecuteEntry(Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\Tasks\Task.cs @ 2767]
000000f2a42fdfe0 00007ffbfd708e46 System.Threading.ThreadPoolWorkQueue.Dispatch() [f:\dd\ndp\clr\src\BCL\system\threading\threadpool.cs @ 820]根據(jù)卦中的顯示找到了問(wèn)題方法，為了保護(hù)客戶隱私，這里稍微會(huì)模糊一下，主要是看下復(fù)雜度的骨架結(jié)構(gòu)。
圖片
從卦象看里面至少包含了3層for循環(huán)，所以時(shí)間復(fù)雜度是 O(N3) 次方，學(xué)過(guò)數(shù)據(jù)結(jié)構(gòu)和算法的朋友應(yīng)該知道，這個(gè)復(fù)雜度不得了，要逆天了。
3. O(N3) 是禍根嗎？
要想知道 O(N3) 是不是禍根，得要看有沒(méi)有給它不停的施肥翻土，可以找找相關(guān)的集合，使用 !dso 命令觀察即可。
0:033> !dso
OS Thread Id: 0x2f00 (33)
RSP/REG Object Name
rbx 0000028227b4be70 xxx.GoodsInfo
000000F2A42FD520 0000028029c02038 System.Collections.Generic.List`1[[xxx.GoodsInfo, xxx.Model]]
...
000000F2A42FD708 0000027f277d3de8 System.Collections.Generic.Dictionary`2[[System.String, mscorlib],[xxx_DataGrab, xxx.Data]]
0:033> !do 0000027f277d3de8
Name: System.Collections.Generic.Dictionary`2[[System.String, mscorlib],[xxx_DataGrab,xxx.Data]]
MethodTable: 00007ffba12b82f8
EEClass: 00007ffbfd345c10
Size: 80(0x50) bytes
File: C:\Windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
MT Field Offset Type VT Attr Value Name
00007ffbfd1d8538 4001887 8 System.Int32[] 0 instance 0000027f27d51328 buckets
00007ffbfe422618 4001888 10 ...non, mscorlib]][] 0 instance 0000027f27d51350 entries
00007ffbfd1d85a0 4001889 38 System.Int32 1 instance 1 count
00007ffbfd1d85a0 400188a 3c System.Int32 1 instance 1 version
00007ffbfd1d85a0 400188b 40 System.Int32 1 instance -1 freeList
00007ffbfd1d85a0 400188c 44 System.Int32 1 instance 0 freeCount
00007ffbfd1c7790 400188d 18 ...Canon, mscorlib]] 0 instance 00000282274c1978 comparer
00007ffbfd1c57c0 400188e 20 ...Canon, mscorlib]] 0 instance 0000027f27cfc630 keys
00007ffbfd1eef60 400188f 28 ...Canon, mscorlib]] 0 instance 0000000000000000 values
00007ffbfd1d5dd8 4001890 30 System.Object 0 instance 0000000000000000 _syncRoot
0:033> !do 0000028029c02038
Name: System.Collections.Generic.List`1[[xxx, xxx.Model]]
MethodTable: 00007ffba126e830
EEClass: 00007ffbfd362af8
Size: 40(0x28) bytes
File: C:\Windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
MT Field Offset Type VT Attr Value Name
00007ffbfd1ee250 40018a0 8 System.__Canon[] 0 instance 00000283278195b0 _items
00007ffbfd1d85a0 40018a1 18 System.Int32 1 instance 21863 _size
00007ffbfd1d85a0 40018a2 1c System.Int32 1 instance 0 _version
00007ffbfd1d5dd8 40018a3 10 System.Object 0 instance 0000000000000000 _syncRoot
00007ffbfd1ee250 40018a4 8 System.__Canon[] 0 static <no information>從卦中可以看到第一層的dictionary只有1條記錄，第二層的 List 有高達(dá) 2.1w 數(shù)據(jù)，第三層的 dbStocks 在線程棧沒(méi)有找到，我也懶得找到了，起碼發(fā)現(xiàn)了第二層的 list 確實(shí)比較大，加上數(shù)據(jù)的佐證，基本上就找到了問(wèn)題所在，也滿足程序的瞬高的現(xiàn)象。
4. 解決方案
知道了復(fù)雜度高，優(yōu)化的方向就是降低時(shí)間復(fù)雜度，將 O(N3) 降低到 O(N)，方法就是在深層循環(huán)之前提前用 Dictionary 或者 HashSet 來(lái)預(yù)存數(shù)據(jù)，將后面的 for 循環(huán)變成字段的key查找，而key查找則是 O(1)。
為了讓大家有個(gè)宏觀概念，我讓 chatgpt 給我生成一個(gè) O(N2) 到 O(N) 的例子，參考代碼如下：
public class GoodsInfo
{
public int Spid { get; set; }
// 其他屬性...
}
public class Stock
{
public int Spid { get; set; }
// 其他屬性...
}
public class Optimizer
{
// 原始O(N^2)復(fù)雜度的查找方法
public List<GoodsInfo> FindMatchingGoodsInfoO_N2(List<GoodsInfo> goodsInfos, List<Stock> stocks, int targetSpid)
{
List<GoodsInfo> result = new List<GoodsInfo>();
foreach (var goodsInfo in goodsInfos)
{
foreach (var stock in stocks)
{
if (goodsInfo.Spid == stock.Spid && stock.Spid == targetSpid)
{
result.Add(goodsInfo);
}
}
}
return result;
}
// 優(yōu)化后的O(N)復(fù)雜度的查找方法
public List<GoodsInfo> FindMatchingGoodsInfoO_N(List<GoodsInfo> goodsInfos, List<Stock> stocks, int targetSpid)
{
HashSet<int> stockSpids = new HashSet<int>(stocks.Select(s => s.Spid));
List<GoodsInfo> result = new List<GoodsInfo>();
foreach (var goodsInfo in goodsInfos)
{
if (stockSpids.Contains(goodsInfo.Spid) && goodsInfo.Spid == targetSpid)
{
result.Add(goodsInfo);
}
}
return result;
}
}可以看到 chatgpt 很聰明，用 HashSet 來(lái)化煞。
三：總結(jié)
說(shuō)實(shí)話像這種生產(chǎn)事故，我以前在公司的項(xiàng)目中也會(huì)偶發(fā)的遇到，都是趕時(shí)間，加班加點(diǎn)寫(xiě)出來(lái)的代碼，只想把功能寫(xiě)出來(lái)早點(diǎn)下班，復(fù)雜度高？后面再說(shuō)吧。。。代碼寫(xiě)的太好，容易被老板優(yōu)化。
責(zé)任編輯：武曉燕
來(lái)源：
一線碼農(nóng)聊技術(shù)
