一：背景

1. 講故事

這個(gè)月初，一位朋友加微信求助他的程序出現(xiàn)了 CPU 偶發(fā)性爆高，希望能有償解決一下。

從描述看，這個(gè)問(wèn)題應(yīng)該困擾了很久，還是醫(yī)院的朋友給力，開(kāi)門就是 100塊 紅包 🤣🤣🤣，那既然是偶發(fā)性爆高，人工不行，還得用 procdump 自動(dòng)抓，用 procdump -ma -s 5 -n 2 -c 70 w3wp 埋伏好，幾天后如愿生成了兩個(gè)dump，太妙了，接下來(lái)就用 windbg 分析吧。

二：Windbg 分析

1. 真的是cpu爆高嗎

一切只相信數(shù)據(jù)，這里用 !tp 看一下此時(shí) 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

從數(shù)據(jù)看，此時(shí) CPU utilization: 83%, 沒(méi)毛病。

2. 查看線程耗時(shí)

既然是偶發(fā)性的bug，而且也說(shuō)了可能是醫(yī)生操作了什么觸發(fā)了什么條件才導(dǎo)致的，剛好這里也有 2 個(gè)dump，那就比一下各個(gè)線程的耗時(shí)吧，這里只提取 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.000Kernel?time:?0?days?0:08:43.000User?time:?0?days?1:08:19.0000:062:x86>?!runawayUser?Mode?TimeThread???????Time62:7188?????0?days?0:18:05.34344:6c90?????0?days?0:16:16.68739:86e8?????0?days?0:14:57.73432:1d8c?????0?days?0:01:02.54635:23a4?????0?days?0:00:58.2500: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.000Kernel?time:?0?days?0:08:45.000User?time:?0?days?1:08:41.0000:062:x86>?!runawayUser?Mode?TimeThread???????Time62:7188?????0?days?0:18:11.87544:6c90?????0?days?0:16:23.15639:86e8?????0?days?0:15:04.15632:1d8c?????0?days?0:01:02.54635:23a4?????0?days?0:00:58.250

從信息看，間隔15s的dump，相對(duì)來(lái)說(shuō) 62,44,39 這三個(gè)線程耗時(shí)最多，所以這三個(gè)線程值得繼續(xù)挖一挖。

3. 查看線程棧

接下來(lái)用 ~62s; !clrstack;~44s; !clrstack;~39s; !clrstack 切到這三個(gè)線程看下棧情況，如下圖所示：

從棧中看，并沒(méi)有用戶代碼，這就很尷尬了，我一度懷疑是不是 webform 的同步上下文導(dǎo)致的，但好歹我還是有一些經(jīng)驗(yàn)，既然 !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() 方法中遇到了問(wèn)題，接下來(lái)用 !dso 把堆對(duì)象都導(dǎo)出來(lái)。

0:062:x86>?!dso Error?requesting?heap?segment?b4fe0000 Failed?to?retrieve?segments?for?gc?heap Unable?to?determine?bounds?of?gc?heap

我去，這個(gè) dump 的棧被破壞了，可能是 cpu 爆高導(dǎo)致的，也有可能是抓的不好，這下太折磨了，得，只能用 kb 到非托管棧上找方法參數(shù)。

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 ...

接下來(lái)我們 !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>

用輸出中可以看到，這個(gè) list=23w 條記錄，它正在 list.Contains 處，有了這些信息，接下來(lái)就可以把源碼導(dǎo)出來(lái)，簡(jiǎn)化后的代碼如下：

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;}

眼尖的朋友肯定能注意到，在數(shù)據(jù)量大的情況下，這里的 list.Insert(0, me_zyblbr); 有大問(wèn)題，畢竟 list.Insert 的復(fù)雜度是 O(N)，針對(duì) 23w 來(lái)說(shuō)總的時(shí)間復(fù)雜度就是：

n(n-1)/2 = 23w(23w-1)/2 = 26,450,000,000 = 264億 。

然后就是 3個(gè)這樣的線程就一起把cpu給抬起來(lái)了。

4. 到底是什么sql語(yǔ)句導(dǎo)致

雖然問(wèn)題根已找到，但朋友最關(guān)心的是這位醫(yī)生到底輸入了什么導(dǎo)致 sql 查詢了如此大的數(shù)據(jù), 不知道醫(yī)生要扣錢還是他們要向上面有個(gè)交代😂😂😂， 由于堆，棧都 被損壞了，找起來(lái)還是很麻煩的，我用了 sos 中的 !lno, !dumpheap 都是報(bào)錯(cuò),徹底趴窩了，最后想了下 sosex 中也有一個(gè) !mdso 命令，終于一路坎坷的找到了重要的 OracleParameter 參數(shù)。

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.OracleParameter0: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="%高血壓病%"

原來(lái)是醫(yī)生模糊查詢了一個(gè) 高血壓病 導(dǎo)致的。。。

不過(guò)這里主要是想告訴大家的是,當(dāng)由于內(nèi)存遭到一定程度的破壞導(dǎo)致 sos 徹底趴窩也不要怕，可能還有其他的插件可以救我們于水火之中，多一個(gè)插件多一條路哈。

三：總結(jié)

總的來(lái)說(shuō)，這次偶發(fā)的CPU爆高事故，犯的相對(duì)比較低級(jí)，對(duì) List.Insert 的復(fù)雜度可能也不是很了解，也有可能是為了趕業(yè)務(wù)所欠的債吧，改發(fā)也相對(duì)簡(jiǎn)單，先用 add 送到 list，最后再統(tǒng)一按規(guī)則做一下重整排序。

END

工作中的你，是否已遇到 ...?

1. CPU爆高

2. 內(nèi)存暴漲

3. 資源泄漏

4. 崩潰死鎖

5. 程序呆滯

等緊急事件，全公司都指望著你能解決...? 危難時(shí)刻才能展現(xiàn)你的技術(shù)價(jià)值，作為專注于.NET高級(jí)調(diào)試的技術(shù)博主，歡迎微信搜索: 一線碼農(nóng)聊技術(shù)，免費(fèi)協(xié)助你分析Dump文件，希望我能將你的踩坑經(jīng)驗(yàn)分享給更多的人。

總結(jié)

以上是生活随笔為你收集整理的记一次 .NET 某市附属医院 Web程序 偶发性CPU爆高分析的全部?jī)?nèi)容，希望文章能夠幫你解決所遇到的問(wèn)題。

如果覺(jué)得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。