记一次 .NET 某上市工业智造 CPU+内存+挂死 三高分析
一：背景
1. 講故事
上個月有位朋友加wx告知他的程序有掛死現象，詢問如何進一步分析，截圖如下：
看這位朋友還是有一定的分析基礎，可能玩的少，缺乏一定的分析經驗，當我簡單分析之后，我發現這個dump挺有意思的， CPU，內存，掛死 三樣全占，程序悲慘莫過于此。。。
既然找到我，我得想辦法化解他的痛苦😄😄😄，由易到難我們逐一分析這三樣都是因為什么原因所致？
二：三高分析
1. 掛死原因
根據 40+ 的dump分析經驗，掛死大多是由于某種情況導致線程卡死，導致后續請求堆積在 threadpool 中，要想驗證，可以使用 !tp 命令查看線程池隊列。
0:000>?!tp CPU?utilization:?81% Worker?Thread:?Total:?65?Running:?65?Idle:?0?MaxLimit:?32767?MinLimit:?64 Work?Request?in?Queue:?2831Unknown?Function:?00007ffffcba1750??Context:?0000022ab04d4a58Unknown?Function:?00007ffffcba1750??Context:?0000022ab03e4ce8...Unknown?Function:?00007ffffcba1750??Context:?0000022ab825ec88Unknown?Function:?00007ffffcba1750??Context:?0000022ab825a458Unknown?Function:?00007ffffcba1750??Context:?0000022ab8266500Unknown?Function:?00007ffffcba1750??Context:?0000022ab8268198Unknown?Function:?00007ffffcba1750??Context:?0000022ab826cb00Unknown?Function:?00007ffffcba1750??Context:?0000022ab8281578 -------------------------------------- Number?of?Timers:?0 -------------------------------------- Completion?Port?Thread:Total:?2?Free:?2?MaxFree:?128?CurrentLimit:?2?MaxLimit:?32767?MinLimit:?64可以很明顯的看到線程池隊列有 2831 個任務堆積，這就導致新進來的請求無法得到處理，所以就出現了掛死現象，接下來就來看看這些線程都干嘛去了，為啥效率那么低，可以用 ~*e !clrstack 調出所有線程棧，截圖如下：
掃了一遍后，發現有很多的 System.Net.HttpWebRequest.GetResponse() 方法，有經驗的朋友應該知道，這又是一個經典的同步http請求過慢導致的程序處理不及的掛死，有些朋友可能好奇，能不能把網址給我扒出來，可以是可以，用 !dso 命令即可。
000000D2FBD3B840?0000023269e85698?System.Text.UTF8Encoding 000000D2FBD3B850?00000236e9dd2cb8?System.String????application/x-www-form-urlencoded 000000D2FBD3B870?0000023269e85698?System.Text.UTF8Encoding 000000D2FBD3B9A8?00000231aa221a38?System.String????uSyncAppxxx 000000D2FBD3B9B8?00000231aa201a70?System.String????VToken={0}&Vorigin={1}&QueryJson={2} 000000D2FBD3B9C0?00000231aa202200?System.String????http://xxx.xxx.com/API/xxx/BusinessCardFolder/Connector/xxx/GetPageList我去，這url還是一個外網地址，🐂👃了，本身同步方式就慢，這地址更是雪上加霜哈。。。難怪不卡死😄
2. cpu爆高分析
從上面的 !tp 輸出中也看出來了，當前 cpu = 81% ，那為什么會這么高呢？根據經驗大概就是 lock鎖，GC觸發，死循環等情況，可以用排除法。
是 lock 鎖嗎？
可以用命令 !syncblk 看一下同步塊表。
0:000>?!syncblk Index?SyncBlock?MonitorHeld?Recursion?Owning?Thread?Info??SyncBlock?Owner212?0000023ef3cdd028????????????3?????????1?0000023ef40efa40?8d70?209???000002396ad93788?System.Object ----------------------------- Total???????????297 CCW?????????????3 RCW?????????????4 ComClassFactory?0 Free????????????139從輸出看，lock 鎖沒什么問題，接下來用 !mlocks 命令查看下其他類型的鎖，看看有沒有什么新發現。
0:000>?!mlocks Examining?SyncBlocks... Scanning?for?ReaderWriterLock(Slim)?instances... Scanning?for?holders?of?ReaderWriterLock?locks... Scanning?for?holders?of?ReaderWriterLockSlim?locks... Examining?CriticalSections...ClrThread??DbgThread??OsThread????LockType????Lock??????????????LockLevel ------------------------------------------------------------------------------ ... 0x49???????209????????0x8d70??????thinlock????000002396ad9ba90??(recursion:0) 0x49???????209????????0x8d70??????thinlock????000002396ad9baa8??(recursion:0) 0x49???????209????????0x8d70??????thinlock????000002396ad9bac0??(recursion:0) 0x49???????209????????0x8d70??????thinlock????000002396ad9bad8??(recursion:0) 0x49???????209????????0x8d70??????thinlock????000002396ad9baf0??(recursion:0) 0x49???????209????????0x8d70??????thinlock????000002396ad9bb08??(recursion:0) 0x49???????209????????0x8d70??????thinlock????000002396ad9bb20??(recursion:0) 0x49???????209????????0x8d70??????thinlock????000002396ad9bb38??(recursion:0) 0x49???????209????????0x8d70??????thinlock????000002396ad9bb50??(recursion:0) 0x49???????209????????0x8d70??????thinlock????000002396ad9bb68??(recursion:0) 0x49???????209????????0x8d70??????thinlock????000002396ad9bb80??(recursion:0) 0xe????????152????????0x8e68??????thinlock????0000023669f7e428??(recursion:0) 0x41???????208????????0x8fb4??????thinlock????00000235e9f6e8d0??(recursion:0) 0x17???????161????????0x9044??????thinlock????00000238ea94db68??(recursion:0) 0x16???????159????????0x911c??????thinlock????000002392a03ed40??(recursion:0) 0x47???????206????????0x9264??????thinlock????000002322af08e28??(recursion:0)我去，發現有大量的 thinlock，而且 DbgThread=209 線程居然有 1000 +，截圖如下：
有些朋友可能不知道什么叫 thinlock，簡單來說，它就是一種耗cpu的內旋鎖，類似 SpinLock，接下來隨便抽一個對象，查看它的 !gcroot 。
0:000>?!gcroot?000002396ad9ba48 Thread?2580:000000d2fb0bef10?00007ff806945ab3?System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext,?System.Threading.ContextCallback,?System.Object,?Boolean)rbp-80:?000000d2fb0bef50->??0000023769dd4008?System.Threading.Thread->??0000023269e776b8?System.Runtime.Remoting.Contexts.Context->??0000023269e773b8?System.AppDomain...->??0000023269ee1e00?System.Threading.TimerCallback->??0000023269ed2d30?System.Web.Caching.CacheExpires->??0000023269ed2c78?System.Web.Caching.CacheSingle->??0000023269ed2ce0?System.Collections.Hashtable->??000002372ab91d90?System.Collections.Hashtable+bucket[]->??00000239ab32fd10?System.Web.Caching.CacheEntry->??000002396ad93748?System.Collections.Concurrent.ConcurrentDictionary`2[[System.String,?mscorlib],[xxx].Application.Entity.BaseManage.UserRelationEntity,?xxx.Application.Entity]]->??00000239ab2a8248?System.Collections.Concurrent.ConcurrentDictionary`2+Tables[[System.String,?mscorlib],[xxx.Application.Entity.BaseManage.UserRelationEntity,?xxx.Application.Entity]]->??000002396ad96b80?System.Object[]->??000002396ad9ba48?System.Object從輸出信息看,這個 thinlock 來自于 ConcurrentDictionary 字典內部，接下來我們 dump 出這個字典，使用 !mdt 命令。
0:148>?!mdt?000002396ad93748 000002396ad93748?(System.Collections.Concurrent.ConcurrentDictionary`2[[System.String,?mscorlib],[xxx.Application.Entity.BaseManage.UserRelationEntity,?xxx.Application.Entity]])m_tables:00000239ab2a8248?(System.Collections.Concurrent.ConcurrentDictionary`2+Tables[[System.String,?mscorlib],[xxx.Application.Entity.BaseManage.UserRelationEntity,?xxx.Application.Entity]])m_comparer:NULL?(System.Collections.Generic.IEqualityComparer`1[[System.__Canon,?mscorlib]])m_growLockArray:true?(System.Boolean)m_keyRehashCount:0x0?(System.Int32)m_budget:0x213?(System.Int32)m_serializationArray:NULL?(System.Collections.Generic.KeyValuePair`2[[System.__Canon,?mscorlib],[System.__Canon,?mscorlib]][])m_serializationConcurrencyLevel:0x0?(System.Int32)m_serializationCapacity:0x0?(System.Int32) 0:148>?!mdt?00000239ab2a8248 00000239ab2a8248?(System.Collections.Concurrent.ConcurrentDictionary`2+Tables[[System.String,?mscorlib],[xxx.Application.Entity.BaseManage.UserRelationEntity,?xxx.Application.Entity]])m_buckets:0000023e9a2477e8?(System.Collections.Concurrent.ConcurrentDictionary`2+Node[[System.String,?mscorlib],[xxx.Application.Entity.BaseManage.UserRelationEntity,?xxx.Application.Entity]][],?Elements:?543997)m_locks:000002396ad96b80?(System.Object[],?Elements:?1024)m_countPerLock:00000239aa8472c8?(System.Int32[],?Elements:?1024)m_comparer:0000023269e782b8?(System.Collections.Generic.GenericEqualityComparer`1[[System.String,?mscorlib]])從上面信息看，這個字典有 54.3 w 條記錄，為啥這么大，而且還有 1024 個 lock，有點意思，我們扒一下源碼看看。
從源碼看，內部確實有一個 lock[] 數組，那到底是什么操作引發了遍歷 locks[]，要想尋找答案，可以在所有線程棧上尋找 ConcurrentDictionary 關鍵詞。
OS?Thread?Id:?0x2844?(163)Child?SP???????????????IP?Call?Site 000000d2fb83abb8?00007ff80a229df8?[GCFrame:?000000d2fb83abb8]? 000000d2fb83aca0?00007ff80a229df8?[GCFrame:?000000d2fb83aca0]? 000000d2fb83acd8?00007ff80a229df8?[HelperMethodFrame:?000000d2fb83acd8]?System.Threading.Monitor.Enter(System.Object) 000000d2fb83add0?00007ff80693ea56?System.Collections.Concurrent.ConcurrentDictionary`2[[System.__Canon,?mscorlib],[System.__Canon,?mscorlib]].AcquireLocks(Int32,?Int32,?Int32?ByRef) 000000d2fb83ae20?00007ff806918ef2?System.Collections.Concurrent.ConcurrentDictionary`2[[System.__Canon,?mscorlib],[System.__Canon,?mscorlib]].AcquireAllLocks(Int32?ByRef) 000000d2fb83ae60?00007ff8069153f9?System.Collections.Concurrent.ConcurrentDictionary`2[[System.__Canon,?mscorlib],[System.__Canon,?mscorlib]].GetValues() 000000d2fb83aee0?00007ff7ae17d8ec?xxx.Util.DataHelper.ToEnumerable[[System.__Canon,?mscorlib],[System.__Canon,?mscorlib]](System.Collections.Concurrent.ConcurrentDictionary`2<System.__Canon,System.__Canon>) 000000d2fb83af20?00007ff7ad125241?xxx.Application.Code.CacheHelper.GetCaches[[System.__Canon,?mscorlib],[System.__Canon,?mscorlib]](System.String) 000000d2fb83afa0?00007ff7ad12513b?xxx.Application.Code.CacheHelper.GetCaches[[System.__Canon,?mscorlib]](System.String) 000000d2fb83b000?00007ff7b10199e5?xxx.Application.Cache.CacheHelper.GetUserRelations()從線程棧上看，發現了有近20處如上的代碼，可以看出程序在調用 GetCaches 方法的時候觸發了 ConcurrentDictionary 的lock鎖從而卡住，接下來我們看一下 xxx.Application.Cache.CacheHelper.GetUserRelations() 源碼到底做了什么？
public?static?IEnumerable<UserRelationEntity>?GetUserRelations() {return?xxx.Application.Code.CacheHelper.GetCaches<UserRelationEntity>("xxx.BaseManage-UserRelation"); }protected?static?IEnumerable<T>?GetCaches<T>(string?cacheKeyName) {return?GetCaches<T,?string>(cacheKeyName); }private?static?IEnumerable<T>?GetCaches<T,?TKey>(string?cacheKeyName) {return?GetConcurrentDictionaryCache<T,?TKey>(cacheKeyName)?.ToEnumerable(); }public?static?IEnumerable<T>?ToEnumerable<TKey,?T>(this?ConcurrentDictionary<TKey,?T>?dics) {return?dics.Values; }從源碼邏輯看，程序每次調用緩存最終都會調用 dics.Values , 我很好奇它的框架邏輯是什么樣的？截圖如下：
大家有沒有發現，每次 dict.Values 時都要執行 1024 次 Monitor.Enter(locks[i], ref lockTaken);， 也就是 1024 次的內旋鎖，這就是cpu高的一個關鍵因素。
3. 內存爆高原因
最后一個問題是內存為啥會爆高？細心的朋友應該會發現剛才那個 GetValues 中有一個奇怪的邏輯 ，我再貼一下代碼：
private?ReadOnlyCollection<TValue>?GetValues() {int?locksAcquired?=?0;try{AcquireAllLocks(ref?locksAcquired);int?countInternal?=?GetCountInternal();if?(countInternal?<?0){throw?new?OutOfMemoryException();}List<TValue>?list?=?new?List<TValue>(countInternal);for?(int?i?=?0;?i?<?m_tables.m_buckets.Length;?i++){for?(Node?node?=?m_tables.m_buckets[i];?node?!=?null;?node?=?node.m_next){list.Add(node.m_value);}}return?new?ReadOnlyCollection<TValue>(list);}finally{ReleaseLocks(0,?locksAcquired);} }有沒有發現，每一次 GetValues 時都會生成一個 54.3w 大小的新List，請注意這個 list 是新生成的，不是 ConcurrentDictionary 上的引用，這就很坑了，每調用一次，LOH上就會來一個這么大的List，你說內存暴增不暴增？？？
三：總結
總的來說，這苦逼的三高有下面兩個因素造成。
使用了同步的 HttpRequest 方式并使用了外網url導致程序掛死。
優化措施：使用異步方式
巨坑的 ConcurrentDictionary.Values 導致 內存，cpu 爆高。
我想很多朋友都沒想到: ConcurrentDictionary.Values 有這么大的一個坑，這就讓我聯想起了線程不安全的 Dictionary.Values 是怎么做的？
public?ValueCollection?Values {[__DynamicallyInvokable]get{if?(values?==?null){values?=?new?ValueCollection(this);}return?values;} }public?sealed?class?ValueCollection {public?ValueCollection(Dictionary<TKey,?TValue>?dictionary){if?(dictionary?==?null){ThrowHelper.ThrowArgumentNullException(ExceptionArgument.dictionary);}this.dictionary?=?dictionary;} }可以很明顯的看到它并沒有生成新的list，所以優化措施如下：
拒絕使用 ConcurrentDictionary.Values，采用 lock + Dictionary 。
如果硬要用 ConcurrentDictionary ，請將 Query 條件送下去，而不是使用 Values 做全量拉取再查詢，減少內存無畏占用。
最后上一個小彩蛋，將分析結果給了這位朋友之后，朋友想讓我上門分析，第一次遇到。。。太猝不及防啦🤣🤣🤣
END
工作中的你，是否已遇到 ...?
1. CPU爆高
2. 內存暴漲
3. 資源泄漏
4. 崩潰死鎖
5. 程序呆滯
等緊急事件，全公司都指望著你能解決...? 危難時刻才能展現你的技術價值，作為專注于.NET高級調試的技術博主，歡迎微信搜索: 一線碼農聊技術，免費協助你分析Dump文件，希望我能將你的踩坑經驗分享給更多的人。
總結
以上是生活随笔為你收集整理的记一次 .NET 某上市工业智造 CPU+内存+挂死 三高分析的全部內容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： 十个现象，识别程序员的“水份”
- 下一篇： 设计模式:状态模式