记一次 .NET 某电商交易平台Web站 CPU爆高分析
一:背景
1. 講故事
已經連續寫了幾篇關于內存暴漲的真實案例,有點麻木了,這篇換個口味,分享一個 CPU爆高 的案例,前段時間有位朋友在 wx 上找到我,說他的一個老項目經常收到 CPU > 90% 的告警信息,挺尷尬的。
既然找到我,那就用 windbg 分析唄,還能怎么辦。
二:windbg 分析
1. 勘探現場
既然說 CPU > 90%,那我就來驗證一下是否真的如此?
0:359>?!tp CPU?utilization:?100% Worker?Thread:?Total:?514?Running:?514?Idle:?0?MaxLimit:?2400?MinLimit:?32 Work?Request?in?Queue:?1Unknown?Function:?00007ff874d623fc??Context:?0000003261e06e40 -------------------------------------- Number?of?Timers:?2 -------------------------------------- Completion?Port?Thread:Total:?2?Free:?2?MaxFree:?48?CurrentLimit:?2?MaxLimit:?2400?MinLimit:?32從卦象看,真壯觀,CPU直接被打滿,線程池里 514 個線程也正在滿負荷奔跑,那到底都奔跑個啥呢?首先我得懷疑一下這些線程是不是被什么鎖給定住了。
2. 查看同步塊表
觀察鎖情況,優先查看同步塊表,畢竟大家都喜歡用 lock 玩多線程同步,可以用 !syncblk 命令查看。
0:359>?!syncblk Index?SyncBlock?MonitorHeld?Recursion?Owning?Thread?Info??SyncBlock?Owner53?000000324cafdf68??????????498?????????0?0000000000000000?????none????0000002e1a2949b0?System.Object ----------------------------- Total???????????1025 CCW?????????????3 RCW?????????????4 ComClassFactory?0 Free????????????620我去,這卦看起來很奇怪, MonitorHeld=498 是什么鬼???教科書上都說: owner + 1 , waiter + 2,所以你肉眼看到的總會是一個奇數,那偶數又是個啥意思?查了下神奇的 StackOverflow,大概總結成如下兩種情況:
內存損壞
這種情況比中彩還難,我也堅信不會走這種天羅運。。。
lock convoy (鎖護送)
前段時間我分享了一篇真實案例:記一次 .NET 某旅行社Web站 CPU爆高分析 ,它就是因為 lock convoy 造成的 CPU 爆高,果然世界真小,又遇到了。。。為了方便大家理解,我還是把那張圖貼上吧。
看完這張圖你應該就明白了,一個線程在時間片內頻繁的爭搶鎖和上下文切換,所以就很容易的出現一個持有鎖的線程剛退出,那些等待鎖的線程此時還沒有一個真正的持有鎖,剛好抓到的dump就是這么一個時間差,換句話說,當前的 498 全部是 waiter 線程的計數,也就是 249 個 waiter 線程,接下來就可以去驗證了,把所有線程的線程棧調出來,再檢索下 Monitor.Enter 關鍵詞。
從圖中可以看出當前有 220 個線程正卡在 Monitor.Enter 處,貌似丟了29個,不管了,反正大量線程卡住就對了,從堆棧上看貌似是在 xxx.Global.PreProcess方法中設置上下文后卡住了,為了滿足好奇心,我就把問題代碼給導出來。
3. 查看問題代碼
還是用老命令 !ip2md + !savemodule 。
0:359>?!ip2md?00007ff81ae98854 MethodDesc:???00007ff819649fa0 Method?Name:??xxx.Global.PreProcess(xxx.JsonRequest,?System.Object) Class:????????00007ff81966bdf8 MethodTable:??00007ff81964a078 mdToken:??????0000000006000051 Module:???????00007ff819649768 IsJitted:?????yes CodeAddr:?????00007ff81ae98430 Transparency:?Critical 0:359>?!savemodule?00007ff819649768?E:\dumps\PreProcess.dll 3?ps?in?file p?0?-?VA=2000,?VASize=b6dc,?FileAddr=200,?FileSize=b800 p?1?-?VA=e000,?VASize=3d0,?FileAddr=ba00,?FileSize=400 p?2?-?VA=10000,?VASize=c,?FileAddr=be00,?FileSize=200然后用 ILSpy 打開問題代碼,截圖如下:
尼瑪,果然每個 DataContext.SetContextItem() 方法中都有一個 lock 鎖,完美命中 lock convoy。
4. 真的就這樣結束了嗎?
本來準備匯報了,但想著500多個線程棧都調出來了,閑著也是閑著,干脆掃掃看吧,結果我去,意外發現有 134 個線程卡在 ReaderWriterLockSlim.TryEnterReadLockCore 處,如下圖所示:
從名字上可以看出,這是一個優化版的讀寫鎖:ReaderWriterLockSlim, 真的很好奇,再次導出問題。
internal?class?LocalMemoryCache?:?ICache {private?string?CACHE_LOCKER_PREFIX?=?"xx_xx_";private?static?readonly?NamedReaderWriterLocker?_namedRwlocker?=?new?NamedReaderWriterLocker();public?T?GetWithCache<T>(string?cacheKey,?Func<T>?getter,?int?cacheTimeSecond,?bool?absoluteExpiration?=?true)?where?T?:?class{T?val?=?null;ReaderWriterLockSlim?@lock?=?_namedRwlocker.GetLock(cacheKey);try{@lock.EnterReadLock();val?=?(MemoryCache.Default.Get(cacheKey)?as?T);if?(val?!=?null){return?val;}}finally{@lock.ExitReadLock();}try{@lock.EnterWriteLock();val?=?(MemoryCache.Default.Get(cacheKey)?as?T);if?(val?!=?null){return?val;}val?=?getter();CacheItemPolicy?cacheItemPolicy?=?new?CacheItemPolicy();if?(absoluteExpiration){cacheItemPolicy.AbsoluteExpiration?=?new?DateTimeOffset(DateTime.Now.AddSeconds(cacheTimeSecond));}else{cacheItemPolicy.SlidingExpiration?=?TimeSpan.FromSeconds(cacheTimeSecond);}if?(val?!=?null){MemoryCache.Default.Set(cacheKey,?val,?cacheItemPolicy);}return?val;}finally{@lock.ExitWriteLock();}}看了下上面的代碼大概想實現一個對 MemoryCache 的 GetOrAdd 操作,而且貌似為了安全起見,每一個 cachekey 都配了一把 ReaderWriterLockSlim,這邏輯就有點奇葩了,畢竟 MemoryCache 本身就帶了實現此邏輯的線程安全方法,比如:
public?class?MemoryCache?:?ObjectCache,?IEnumerable,?IDisposable {public?override?object?AddOrGetExisting(string?key,?object?value,?DateTimeOffset?absoluteExpiration,?string?regionName?=?null){if?(regionName?!=?null){throw?new?NotSupportedException(R.RegionName_not_supported);}CacheItemPolicy?cacheItemPolicy?=?new?CacheItemPolicy();cacheItemPolicy.AbsoluteExpiration?=?absoluteExpiration;return?AddOrGetExistingInternal(key,?value,?cacheItemPolicy);} }5. 用 ReaderWriterLockSlim 有什么問題嗎?
哈哈,肯定有很多朋友這么問?????????????,確實,這有什么問題呢?首先看一下 _namedRwlocker 集合中目前到底有多少個 ReaderWriterLockSlim ? 想驗證很簡單,上托管堆搜一下即可。
0:359>?!dumpheap?-type?System.Threading.ReaderWriterLockSlim?-stat Statistics:MT????Count????TotalSize?Class?Name 00007ff8741631e8????70234??????6742464?System.Threading.ReaderWriterLockSlim可以看到當前托管堆有 7w+ 的 ReaderWriterLockSlim,這又能怎么樣呢???不要忘啦, ReaderWriterLockSlim 之所以帶一個 Slim ,是因為它可以實現一段時間內的用戶態 自旋,那 自旋 就得吃一點CPU,如果再放大幾百倍?CPU能不被抬起來嗎?
三:總結
總的來說,這個 Dump 所反應出來的 CPU打滿 有兩個原因。
lock convoy 造成的頻繁爭搶和上下文切換給了 CPU 一頓暴擊。
ReaderWriterLockSlim 的百倍 用戶態自旋 又給了 CPU 一頓暴擊。
知道原因后,應對方案也就簡單了。
批量操作,降低串行化的 lock 個數,不要玩鎖內卷。
去掉 ReaderWriterLockSlim,使用 MemoryCache 自帶的線程安全方法。
總結
以上是生活随笔為你收集整理的记一次 .NET 某电商交易平台Web站 CPU爆高分析的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: 【Paddle 经验分享】利用Paddl
- 下一篇: ML.NET Cookbook:(5)如