背景
公司里的某負責保存用戶檔案的子系統有時會忽然cpu很高，過了大約5分鐘后又恢復正常水平，領導協調讓我幫看一下 (我心里是: 不熟悉這個子系統里面的代碼，我盡力哈??)
其實確實是這樣的，如果熟悉出問題的系統的代碼，會對診斷問題起到很大的幫助，否則就需要更多的利用對底層的理解了，
分析
打聽后知道了這個子系統用.net core寫的，可以運行在windows和linux docker上，且這次的cpu高的問題，他們在windows運行也可復現，于是，我讓他們在windows上運行，發現cpu高的時候dump一下，(然后windbg就可以準備下地干活了??)
在用windbg看了大部分threadpool worker執行緒的情況后，我發現大部分執行緒都運行到這樣類似的call stack上:
先大概看一下這個PeopleManagementService.Program+c__DisplayClass2_0.b__0(PeopleManagementService.User)在做什么，用IL反編譯工具可以看到:
再結合call stack，感覺背景關系正在從某集合里查找東西呢？（一個題外話，上面那個c__DisplayClass2_0.b__0名字挺奇怪，其實這是C# compiler在build我們的C#代碼到IL時幫著生成的一些code，對于目前這個，就對應我們C#程式員寫出的lambda )
找東西會把cpu明顯提高么？去看看PrintUserLastEnteredTimeDetail()在干什么吧，(其實子系統team的同事人很好，所以這次我直接找他要對應的代碼得了??) 簡化代碼：
看起來是在一個叫users的List中按條件查找東西，看看這個list的size, 用!do試一下：
1 0:027> !DumpObj /d 0000019a8000d938 2 Name: System.Collections.Generic.List`1[[PeopleManagementService.User, PeopleManagementService]] 3 MethodTable: 00007ff96c313e88 4 EEClass: 00007ff96c2df530 5 Tracked Type: false 6 Size: 32(0x20) bytes 7 File: C:\Program Files\dotnet\shared\Microsoft.NETCore.App\6.0.14\System.Private.CoreLib.dll 8 Fields: 9 MT Field Offset Type VT Attr Value Name 10 00007ff96c2fd618 4002099 8 System.__Canon[] 0 instance 0000019a90bc12a0 _items 11 00007ff96c2a94b0 400209a 10 System.Int32 1 instance 524288 _size 12 00007ff96c2a94b0 400209b 14 System.Int32 1 instance 524288 _version 13 00007ff96c2fd618 400209c 8 System.__Canon[] 0 static dynamic statics NYI s_emptyArraysize大約524288，500K的items在list里面，然后多個執行緒在一起進行這樣的查找，所以cpu提高了，
后記
在告知同事這個原因前，我還有意無意地查了一下那個保存big list的Dictionary，用!gcroot:
然后!do看一下：
1 !do 0000019A8000D818 2 Name: System.Collections.Generic.Dictionary`2+Entry[[System.String, System.Private.CoreLib],[System.Collections.Generic.List`1[[PeopleManagementService.User, PeopleManagementService]], System.Private.CoreLib]][] 3 MethodTable: 00007ff96c322808 4 EEClass: 00007ff96c322770 5 Tracked Type: false 6 Size: 96(0x60) bytes 7 Array: Rank 1, Number of elements 3, Type VALUETYPE一個保存著那么大list的Dictionary, 其實只有<=3的key value pairs，再看看它的keys是啥，我們用windbg的memory view直接看記憶體中的"瓤"吧：
64位的行程運行環境，clr array的第一個item在0000019A8000D818 + 8(mt ptr size) + 4(length field) + 4 (padding)，所以看標紅的那兩個地址，
1 0:027> !DumpObj /d 0000019a8000cce8 2 Name: System.String 3 MethodTable: 00007ff96c2bd708 4 EEClass: 00007ff96c299d60 5 Tracked Type: false 6 Size: 30(0x1e) bytes 7 File: C:\Program Files\dotnet\shared\Microsoft.NETCore.App\6.0.14\System.Private.CoreLib.dll 8 String: Male
1 0:027> !DumpObj /d 0000019a8000cd08 2 Name: System.String 3 MethodTable: 00007ff96c2bd708 4 EEClass: 00007ff96c299d60 5 Tracked Type: false 6 Size: 34(0x22) bytes 7 File: C:\Program Files\dotnet\shared\Microsoft.NETCore.App\6.0.14\System.Private.CoreLib.dll 8 String: Female
原來Dictionary按性別分類保存了所有的用戶資訊，
我把這些資訊告訴同事，他第一反應是沒有想到這個運行的結果，按照他的代碼，他預期是按性別和用戶名一起來當key，然后放到Dictionary，這樣查詢起來至少時間復雜度不應這么高，于是我和那個同事打開相關的生成key的代碼：
1 private static string GetUserKey(Gender gender, string userName) => string.Join(userName, gender);大家發現沒？想當然的用String.Join來連接2個object，卻沒注意其實String.Join的定義是這樣，注意第一個引數可是separator啊:
這么錯誤的使用，就相當于把user name作為separator，而后面的集合引數其實就傳了一個性別，所以生成的key就總是同一個，本想做成user cache的Dictionary的資料最終退化為兩個很大的lists?? 然后多個執行緒一起在這兩個大大的list上以O(n)的時間復雜度查找東西，cpu就高起來了……
總結
看來大家不能這么隨隨便便的寫C#代碼啊，雖然.net sdk會為C#程式員提供便利和安全性，但自己也不該想當然的無腦coding哈，最后同事的臉比較紅哈??轉載請註明出處，本文鏈接：https://www.uj5u.com/net/546007.html
標籤：.NET Core