記一次 .NET游戲站程序的 CPU 爆高分析
一：背景
1. 講故事
上個月有個老朋友找到我，說他的站點(diǎn)晚高峰 CPU 會突然爆高，發(fā)了兩份 dump 文件過來，如下圖：
又是經(jīng)典的 CPU 爆高問題，到目前為止，對這種我還是有一些經(jīng)驗可循的。
- 抓 2-3 個 dump
第一個：有利于算兩份 dump 中的線程時間差，從而推算最耗時線程。
第二個：有時候你抓的dump剛好線程都處理完了，cpu 還未真實回落，所以分析這種dump意義不大，我是吃了不少虧??????。
- 優(yōu)先推測是否為 GC 搗鬼
現(xiàn)在的碼農(nóng)都精怪精怪的，基本不會傻傻的寫出個死循環(huán)，絕大部分都是遇到某種 資源密集型 或 計算密集型 場景下導(dǎo)致非托管的 GC 出了問題。
好了，有了這個先入為主的思路，接下來就可以用 windbg 去占卜了。
二：windbg 分析
1. GC 搗鬼分析
GC 搗鬼的本質(zhì)是 GC 出現(xiàn)了回收壓力，尤其是對 大對象堆 的分配和釋放，大家應(yīng)該知道 大對象堆 采用的是鏈?zhǔn)焦芾矸?，不到萬不得已 GC 都不敢回收它，所以在它上面的分配和釋放都是一種 CPU密集型 操作，不信你可以去 StackOverflow 上搜搜 LOH 和 HighCPU 的關(guān)聯(lián)關(guān)系??????。
2. 使用 x 命令搜索
在 windbg 中有一個快捷命令 x ，可用于在非托管堆上檢索指定關(guān)鍵詞，檢索之前先看看這個 dump 是什么 Framework 版本，決定用什么關(guān)鍵詞。
- 0:050> lmv
- start end module name
- 00b80000 00b88000 w3wp (pdb symbols) c:\mysymbols\w3wp.pdb\0CED8B2D5CB84AEB91307A0CE6BF528A1\w3wp.pdb
- Loaded symbol image file: w3wp.exe
- Image path: C:\Windows\SysWOW64\inetsrv\w3wp.exe
- Image name: w3wp.exe
- 71510000 71cc0000 clr (pdb symbols) c:\mysymbols\clr.pdb\9B2B2A02EC2D43899F87AC20F11B82DF2\clr.pdb
- Loaded symbol image file: clr.dll
- Image path: C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll
- Image name: clr.dll
- Browse all global symbols functions data
- Timestamp: Thu Sep 3 03:30:58 2020 (5F4FF2F2)
- CheckSum: 007AC92B
- ImageSize: 007B0000
- File version: 4.8.4261.0
- Product version: 4.0.30319.0
從 File version 上可以看出當(dāng)前是基于 Net Framework 4.8 的，好了，用 x clr!SVR::gc_heap::trigger* 看看有沒有觸發(fā) gc 的操作。
- 0:050> x clr!SVR::gc_heap::trigger*
- 71930401 clr!SVR::gc_heap::trigger_ephemeral_gc (protected: int __thiscall SVR::gc_heap::trigger_ephemeral_gc(enum gc_reason))
- 71665cf9 clr!SVR::gc_heap::trigger_gc_for_alloc (protected: void __thiscall SVR::gc_heap::trigger_gc_for_alloc(int,enum gc_reason,struct SVR::GCDebugSpinLock *,bool,enum SVR::msl_take_state))
- 71930a08 clr!SVR::gc_heap::trigger_full_compact_gc (protected: int __thiscall SVR::gc_heap::trigger_full_compact_gc(enum gc_reason,enum oom_reason *,bool))
從輸出信息看，gc 果然在高速運(yùn)轉(zhuǎn)，開心哈，接下來看一下是哪一個線程觸發(fā)了gc，可以用 !eestack 把所有線程的托管和非托管堆棧打出來。
從圖中可以看到當(dāng)前 50 號線程的 GetUserLoginGameMapIds() 方法進(jìn)行的大對象分配 try_allocate_more_space 觸發(fā)了 clr!SVR::gc_heap::trigger_gc_for_alloc GC回收操作，最后 GC 通過 clr!SVR::GCHeap::GarbageCollectGeneration 進(jìn)行回收，既然在回收，必然有很多線程正在卡死。
接下來再看看有幾個線程正在共同努力調(diào)用 GetUserLoginGameMapIds() 方法。
到這里基本就能確定是 gc 搗的鬼。接下來的興趣點(diǎn)就是 GetUserLoginGameMapIds() 到底在干嘛?
3. 分析 GetUserLoginGameMapIds() 方法
接下來把方法的源碼導(dǎo)出來，使用 !name2ee 找到其所屬 module，然后通過 !savemodule 導(dǎo)出該 module 的源碼。
- 0:050> !name2ee *!xxx.GetUserLoginGameMapIds
- Module: 1c870580
- Assembly: xxx.dll
- Token: 0600000b
- MethodDesc: 1c877504
- Name: xxx.GetUserLoginGameMapIds(xxx.GetUserLoginGameMapIdsDomainInput)
- JITTED Code Address: 1d5a2030
- 0:050> !savemodule 1c870580 E:\dumps\6.dll
- 3 sections in file
- section 0 - VA=2000, VASize=112b8, FileAddr=200, FileSize=11400
- section 1 - VA=14000, VASize=3c8, FileAddr=11600, FileSize=400
- section 2 - VA=16000, VASize=c, FileAddr=11a00, FileSize=200
打開導(dǎo)出的 6.dll，為了最大保護(hù)隱私，我就把字段名隱藏一下， GetUserLoginGameMapIds() 大體邏輯如下。
- public GetUserLoginGameMapIdsDomainOutput GetUserLoginGameMapIds(GetUserLoginGameMapIdsDomainInput input)
- {
- List<int> xxxQueryable = this._xxxRepository.Getxxx();
- List<UserLoginGameEntity> list = this._userLoginGameRepository.Where((UserLoginGameEntity u) => u.xxx == input.xxx, null, "").ToList<UserLoginGameEntity>();
- List<int> userLoginGameMapIds = (from u in list select u.xxx).ToList<int>();
- IEnumerable<GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput> source = (from mc in (from mc in this._mapCategoryRepository.AsQueryable().ToList<MapCategoryEntity>()
- where userLoginGameMapIds.Any((int mid) => mid == mc.xxx) && mapIdsQueryable.Any((int xxx) => xxx == mc.xxx)
- select mc).ToList<MapCategoryEntity>()
- join u in list on mc.xxx equals u.xxx
- select new GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput
- {
- xxx = mc.xxx,
- xxx = ((u != null) ? new DateTime?(u.xxx) : null).GetValueOrDefault(DateTime.Now)
- } into d
- group d by d.MapId).Select(delegate(IGrouping<int, GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput> g)
- {
- GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput getUserLoginGameMapIdsDataDomainOutput = new GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput();
- getUserLoginGameMapIdsDataDomainOutput.xxx = g.Key;
- getUserLoginGameMapIdsDataDomainOutput.xxx = g.Max((GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput v) => v.xxxx);
- return getUserLoginGameMapIdsDataDomainOutput;
- });
- return new GetUserLoginGameMapIdsDomainOutput
- {
- Data = source.ToList<GetUserLoginGameMapIdsDomainOutput.GetUserLoginGameMapIdsDataDomainOutput>()
- };
- }
看的出來，這是一段EF讀取DB的復(fù)雜寫法，朋友說這段代碼涉及到了多張表的關(guān)聯(lián)操作，算是一個 資源密集型 的方法。
4. 到底持有什么大對象?
方法邏輯看完了，接下來看下 GetUserLoginGameMapIds() 方法到底分配了什么大對象觸發(fā)了GC，可以探究下 50 線程的調(diào)用棧，使用 !clrstack -a 調(diào)出所有的 參數(shù) + 局部 變量。
- 0:050> !clrstack -a
- OS Thread Id: 0x11a0 (50)
- Child SP IP Call Site
- 2501d350 7743c0bc [HelperMethodFrame: 2501d350]
- 2501d3dc 704fbab5 System.Collections.Generic.List`1[[System.__Canon, mscorlib]].set_Capacity(Int32)
- PARAMETERS:
- this (<CLR reg>) = 0x08053f6c
- value = <no data>
- LOCALS:
- <no data>
- 2501d3ec 704fba62 System.Collections.Generic.List`1[[System.__Canon, mscorlib]].EnsureCapacity(Int32)
- PARAMETERS:
- this = <no data>
- min = <no data>
- LOCALS:
- <no data>
- 2501d3f8 70516799 System.Collections.Generic.List`1[[System.__Canon, mscorlib]].Add(System.__Canon)
- PARAMETERS:
- this (<CLR reg>) = 0x08053f6c
- item (<CLR reg>) = 0x2d7b07bc
- LOCALS:
- <no data>
從調(diào)用棧上看，由于 EF 的讀取邏輯需要向 List 中添加一條記錄剛好觸發(fā)了List的擴(kuò)容機(jī)制，就是因為這個擴(kuò)容導(dǎo)致了GC大對象分配。
那怎么看呢? 很簡單，先把 this (
- 0:050> !do 0x08053f6c
- Name: System.Collections.Generic.List`1[[xxx.MapCategoryEntity, xxx.Entities]]
- MethodTable: 1e81eed0
- EEClass: 70219c7c
- 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
- 701546bc 40018a0 4 System.__Canon[] 0 instance 168792c0 _items
- 701142a8 40018a1 c System.Int32 1 instance 32768 _size
- 701142a8 40018a2 10 System.Int32 1 instance 32768 _version
- 70112734 40018a3 8 System.Object 0 instance 00000000 _syncRoot
- 701546bc 40018a4 4 System.__Canon[] 0 static <no information>
上面的 _size = 32768 看到了嗎?剛好是 2的15次方，由于再次新增必須要擴(kuò)容，List 在底層需分配一個 System.__Canon[65536] 的數(shù)組來存儲老內(nèi)容，這個數(shù)組肯定大于 85000byte 這個大對象的界定值啦。
如果有興趣，你可以看下 List 的擴(kuò)容機(jī)制。
- // System.Collections.Generic.List<T>
- private void EnsureCapacity(int min)
- {
- if (_items.Length < min)
- {
- int num = (_items.Length == 0) ? 4 : (_items.Length * 2);
- if ((uint)num > 2146435071u)
- {
- num = 2146435071;
- }
- if (num < min)
- {
- num = min;
- }
- Capacity = num;
- }
- }
- public int Capacity
- {
- get
- {
- return _items.Length;
- }
- set
- {
- if (value < _size)
- {
- ThrowHelper.ThrowArgumentOutOfRangeException(ExceptionArgument.value, ExceptionResource.ArgumentOutOfRange_SmallCapacity);
- }
- if (value == _items.Length)
- {
- return;
- }
- if (value > 0)
- {
- T[] array = new T[value]; //這里申請了一個 int[65536] 大小的數(shù)組
- if (_size > 0)
- {
- Array.Copy(_items, 0, array, 0, _size);
- }
- _items = array;
- }
- else
- {
- _items = _emptyArray;
- }
- }
- }
三：總結(jié)
知道了前因后果之后，大概提三點(diǎn)優(yōu)化建議。
優(yōu)化 GetUserLoginGameMapIds() 方法中的邏輯，這是最好的辦法。
從 dump 上看也就 4核4G 的小機(jī)器，提升下機(jī)器配置，或許有點(diǎn)用。
- 0:017> !cpuid
- CP F/M/S Manufacturer MHz
- 0 6,63,2 GenuineIntel 2295
- 1 6,63,2 GenuineIntel 2295
- 2 6,63,2 GenuineIntel 2295
- 3 6,63,2 GenuineIntel 2295
- 0:017> !address -summary
- --- Protect Summary (for commit) - RgnCount ----------- Total Size -------- %ofBusy %ofTotal
- PAGE_READWRITE 878 1eccd000 ( 492.801 MB) 29.61% 12.03%
沒有特殊原因的話，用 64bit 來跑程序，打破 32bit 的 4G 空間限制，這樣也可以讓gc擁有更大的堆分配空間。
參考網(wǎng)址：https://docs.microsoft.com/zh-cn/dotnet/standard/garbage-collection/fundamentals
