一：背景
1. 講故事
這個月初，一位朋友加微信求助他的程式出現了 CPU 偶發性爆高，希望能有償解決一下，
從描述看，這個問題應該困擾了很久，還是醫院的朋友給力，開門就是 100塊 紅包 ??????，那既然是偶發性爆高，人工不行，還得用 procdump 自動抓，用 procdump -ma -s 5 -n 2 -c 70 w3wp 埋伏好，幾天后如愿生成了兩個dump，太妙了，接下來就用 windbg 分析吧，
二：Windbg 分析
1. 真的是cpu爆高嗎
一切只相信資料，這里用 !tp 看一下此時 machine 的cpu值，
0:062:x86> !tp
CPU utilization: 83%
Worker Thread: Total: 37 Running: 6 Idle: 31 MaxLimit: 8191 MinLimit: 4
Work Request in Queue: 0
--------------------------------------
Number of Timers: 2
--------------------------------------
Completion Port Thread:Total: 1 Free: 1 MaxFree: 8 CurrentLimit: 1 MaxLimit: 1000 MinLimit: 4
從資料看，此時 CPU utilization: 83%, 沒毛病，
2. 查看執行緒耗時
既然是偶發性的bug，而且也說了可能是醫生操作了什么觸發了什么條件才導致的，剛好這里也有 2 個dump，那就比一下各個執行緒的耗時吧，這里只提取 top5 ，
0:062:x86> .time
Debug session time: Thu Dec 16 14:31:45.000 2021 (UTC + 8:00)
System Uptime: not available
Process Uptime: 0 days 1:20:48.000
Kernel time: 0 days 0:08:43.000
User time: 0 days 1:08:19.000
0:062:x86> !runaway
User Mode Time
Thread Time
62:7188 0 days 0:18:05.343
44:6c90 0 days 0:16:16.687
39:86e8 0 days 0:14:57.734
32:1d8c 0 days 0:01:02.546
35:23a4 0 days 0:00:58.250
0:062:x86> .time
Debug session time: Thu Dec 16 14:32:00.000 2021 (UTC + 8:00)
System Uptime: not available
Process Uptime: 0 days 1:21:03.000
Kernel time: 0 days 0:08:45.000
User time: 0 days 1:08:41.000
0:062:x86> !runaway
User Mode Time
Thread Time
62:7188 0 days 0:18:11.875
44:6c90 0 days 0:16:23.156
39:86e8 0 days 0:15:04.156
32:1d8c 0 days 0:01:02.546
35:23a4 0 days 0:00:58.250
從資訊看，間隔15s的dump，相對來說 62,44,39 這三個執行緒耗時最多，所以這三個執行緒值得繼續挖一挖，
3. 查看執行緒堆疊
接下來用 ~62s; !clrstack;~44s; !clrstack;~39s; !clrstack 切到這三個執行緒看下堆疊情況，如下圖所示：
從堆疊中看，并沒有用戶代碼，這就很尷尬了，我一度懷疑是不是 webform 的同步背景關系導致的，但好歹我還是有一些經驗，既然 !clrstack 看不到，那就用 !dumpstack ，
0:062:x86> !dumpstack
OS Thread Id: 0x7188 (62)
TEB information is not available so a stack size of 0xFFFF is assumed
Current frame: (MethodDesc 6b0e1b58 +0x1c System.Collections.Generic.ObjectEqualityComparer`1[[System.__Canon, mscorlib]].Equals(System.__Canon, System.__Canon))
ChildEBP RetAddr Caller, Callee
3867ebfc 6b440484 (MethodDesc 6b0db558 +0x54 System.Collections.Generic.List`1[[System.__Canon, mscorlib]].Contains(System.__Canon))
3867ec18 24bbc3c5 (MethodDesc 25e2ba88 +0x845 xxx.bl_baseInfo.getBljl(System.String, System.String)), calling 2f23072e
3867ec84 6b466d0b (MethodDesc 6b0dcb5c +0x7b System.String.TrimHelper(Int32)), calling (MethodDesc 6b0d1cf4 +0 System.Globalization.CharUnicodeInfo.IsWhiteSpace(Char))
3867ec98 24bbba00 (MethodDesc 2a6eca54 +0x1b8 xxx_blcx.Button1_Click(System.Object, System.EventArgs)), calling (MethodDesc 25e2ba88 +0 xxx.getBljl(System.String, System.String))
3867ecb8 05b5d487 05b5d487
3867ecec 6092da13 (MethodDesc 5fdff5c0 System.Web.UI.WebControls.Button.OnClick(System.EventArgs))
3867ed04 5ffdd1cd (MethodDesc 5fdff5e8 +0xcd System.Web.UI.WebControls.Button.RaisePostBackEvent(System.String))
3867ed1c 5ffdd0fd (MethodDesc 5fdff5e0 +0xd System.Web.UI.WebControls.Button.System.Web.UI.IPostBackEventHandler.RaisePostBackEvent(System.String))
...
真是太奇怪了，用戶代碼 xxx.bl_baseInfo.getBljl 怎么跑到非托管堆疊 ? 這真是第一次遇到，從堆疊上看，程式在 xxx.bl_baseInfo.getBljl() 方法中遇到了問題，接下來用 !dso 把堆物件都匯出來，
0:062:x86> !dso
Error requesting heap segment b4fe0000
Failed to retrieve segments for gc heap
Unable to determine bounds of gc heap
我去，這個 dump 的堆疊被破壞了，可能是 cpu 爆高導致的，也有可能是抓的不好，這下太折磨了，得，只能用 kb 到非托管堆疊上找方法引數，
0:062:x86> kb
# ChildEBP RetAddr Args to Child
00 3867ebfc 6b440484 cd0a25a8 124e2c7c 0efb330c mscorlib_ni!System.Collections.Generic.ObjectEqualityComparer`1[System.__Canon].Equals(System.__Canon, System.__Canon)$##6003913+0x1c
01 3867ec18 24bbc3c5 cd0a25a8 132b35e4 132b35cc mscorlib_ni!System.Collections.Generic.List`1[System.__Canon].Contains(System.__Canon)$##600398F+0x54
WARNING: Frame IP not in any known module. Following frames may be wrong.
02 3867ec98 24bbba00 0e3aead8 8412256c 3867ecc0 0x24bbc3c5
03 3867ecb8 05b5d487 0a3d6f00 3867f170 5381fbca 0x24bbba00
04 3867ecec 6092da13 0a3d6e48 00000000 132a20c0 0x5b5d487
05 3867ed04 5ffdd1cd 124ca1a8 80208dfc 80208dfc System_Web_ni![COLD] System.Web.UI.WebControls.Button.OnClick(System.EventArgs)$##60029E3+0xb
...
接下來我們 !do 一下 132b35cc 地址，看看是什么 list，
0:062:x86> !do 132b35cc
Name: System.Collections.Generic.List`1[[xxx.Model.me_zyblbr, xxx]]
MethodTable: 29f36c8c
EEClass: 6b0aedc4
Size: 24(0x18) bytes
File: C:\Windows\Microsoft.Net\assembly\GAC_32\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
MT Field Offset Type VT Attr Value Name
6b4aea10 4001871 4 System.__Canon[] 0 instance 8e8054e0 _items
6b513c04 4001872 c System.Int32 1 instance 233139 _size
6b513c04 4001873 10 System.Int32 1 instance 233139 _version
6b512104 4001874 8 System.Object 0 instance 00000000 _syncRoot
6b4aea10 4001875 4 System.__Canon[] 0 static <no information>
用輸出中可以看到，這個 list=23w 條記錄，它正在 list.Contains 處，有了這些資訊，接下來就可以把原始碼匯出來，簡化后的代碼如下：
public IList<xxx> getBljl(string as_search, string as_ztbz)
{
IList<me_zyblbr> list = new List<me_zyblbr>();
using (CDataBase cDataBase = new CDataBase("xxx"))
{
var text = "select xxxx from xxx";
OracleDataReader oracleDataReader = cDataBase.SetReader(text);
while (oracleDataReader.Read())
{
if (!list.Contains(me_zyblbr))
{
list.Insert(0, me_zyblbr);
}
}
oracleDataReader.Close();
return list;
}
return list;
}
眼尖的朋友肯定能注意到，在資料量大的情況下，這里的 list.Insert(0, me_zyblbr); 有大問題，畢竟 list.Insert 的復雜度是 O(N)，針對 23w 來說總的時間復雜度就是：
n(n-1)/2 = 23w(23w-1)/2 = 26,450,000,000 = 264億，
然后就是 3個這樣的執行緒就一起把cpu給抬起來了，
4. 到底是什么sql陳述句導致
雖然問題根已找到，但朋友最關心的是這位醫生到底輸入了什么導致 sql 查詢了如此大的資料, 不知道醫生要扣錢還是他們要向上面有個交代??????， 由于堆，堆疊都 被損壞了，找起來還是很麻煩的，我用了 sos 中的 !lno, !dumpheap 都是報錯,徹底趴窩了，最后想了下 sosex 中也有一個 !mdso 命令，終于一路坎坷的找到了重要的 OracleParameter 引數，
0:062:x86> !mdso
Thread 62:
Location Object Type
------------------------------------------------------------
EDI: 132b35cc System.Collections.Generic.List`1[[xxx.me_zyblbr, xxx]]
3867ec08 124e2c7c System.Collections.Generic.ObjectEqualityComparer`1[[xxx.me_zyblbr, xxx]]
3867ec44 132b3a5c Oracle.DataAccess.Client.OracleParameter
0:062:x86> !mdt 132b3a5c
132b3a5c (Oracle.DataAccess.Client.OracleParameter)
__identity:NULL (System.Object)
m_pOpoPrmValCtx:4e691200 (System.UIntPtr)
m_paramName:125fe6f0 (System.String) Length=5, String=":xxx"
m_sourceColumn:NULL (System.String)
m_sourceVersion:0x200 (System.Data.DataRowVersion)
m_dbType:0x0 (System.Data.DbType)
m_oraDbType:0x77 (NVarchar2) (Oracle.DataAccess.Client.OracleDbType)
m_bOracleDbTypeExSet:false (System.Boolean)
m_maxSize:0xffffffff (System.Int32)
m_maxArrayBindSize:NULL (System.Int32[])
m_nullable:false (System.Boolean)
m_value:132b3af8 (System.String) Length=6, String="%高血壓病%"
原來是醫生模糊查詢了一個 高血壓病 導致的，，，
不過這里主要是想告訴大家的是,當由于記憶體遭到一定程度的破壞導致 sos 徹底趴窩也不要怕，可能還有其他的插件可以救我們于水火之中，多一個插件多一條路哈，
三：總結
總的來說，這次偶發的CPU爆高事故，犯的相對比較低級，對 List.Insert 的復雜度可能也不是很了解，也有可能是為了趕業務所欠的債吧，改發也相對簡單，先用 add 送到 list，最后再統一按規則做一下重整排序，
轉載請註明出處，本文鏈接：https://www.uj5u.com/net/387656.html
標籤：C#
上一篇：當動態桌面遇上 HTML5