捉蟲記（二）GC導(dǎo)致的hang
本來第二篇早就該寫的，都準備寫一個while(true)導(dǎo)致高CPU的問題，但是那個dump不知道跑到哪里了，害得我這段時間一直在找，這次的現(xiàn)象是，我正準備出去泡個茶，突然業(yè)務(wù)經(jīng)理嗷嗷直叫（終于找到一個Bug，能不興奮么），一邊喊著處理不行了，一邊喊著趕緊重新啟動，我沒有吱聲，默默打開了性能計數(shù)器，看到處理程序的緩存的確是慢慢在增長（這表示有積壓了），而處理速度降到非常低了，幾秒鐘處理一個（平時情況下哥的程序每秒鐘處理1000個Socket業(yè)務(wù)包是 沒有問題的），說到這里建議大家在自己的程序中也加入一些自定義性能計數(shù)器，這東西太好用，當(dāng)你把系統(tǒng)的一些值（比如說CPU的UserTime，還有Disk的DQL等）和你自己程序的一些值（比如說程序的緩存數(shù)，處理的并行進程數(shù)等）以文件方式記錄下來的時候，做個Excel圖表，這樣你就能對整個系統(tǒng)的性能有了一個很直觀的認識。
1． 首先對程序有個大概的了解。
內(nèi)存1.2G，程序已經(jīng)運行好幾天了。
2． 既然是程序處理速度變慢，那么應(yīng)該看看CPU，線程池的消耗情況等
看看線程如何
***個命令!runaway(如果你是Web程序，那么這個命令對你講非常有用，但是這個From程序中，很多模塊用了那種該死的While(true)，基本上這個命令我們得不到什么東西)
讓我們看看線程池是什么樣子吧（!tp這個命令可以看到線程池的情況）：
Wowowo…，看這個cpu很高啊。
3． 我們看看我們的處理線程在看什么吧（!thread能看到所有的線程）。
。。。。。。
哦，注意那個32號， GC Disabled，到這里我們大概猜測到是GC將處理線程阻塞掉了。
4．為了進一步驗證我們的猜測，我們看看線程們到底在干什么吧（~*e !clrstack這個命令將打印所有線程棧，別著急，慢慢看，這個可以copy一下，貼到一個比較容易查看的編輯器里慢慢看）。為了看起來方便，我把打印結(jié)果copy出來用notepad++來看看,下面這個截圖，我做過處理，不然太多了，看不過來的。
5．我的處理函數(shù)是SchemeEntity.ProcessIMSIContext，并且開了十個線程處理（都是從線程池申請，最多同時允許十個線程處理，如果超過是個線程都沒有處理完畢，那么分發(fā)線程將等待，新來的請求將在緩存隊列中，就是上面所說的那個正在慢慢增長的的緩存），從這個可以看出，十個處理線程都在處理，那么我們看看他們都在干嘛，隨機挑選兩個37，38號看看吧。
6．哦，他們都在Monitor.Enter了，我們重點看一下32，切換過去吧（切換線程 ~線程號s）
7．哦哦~，看到了么，38，37都在等待，但是32在GC，我們看看32的堆棧吧，果然在GC。（kv顯示非托管棧）
看看托管的吧（!clrstack），哦哦~List.set_Capacity(32) ，這幾乎可以肯定是List在做copy的動作，List將申請自己現(xiàn)在長度的兩倍的內(nèi)存，應(yīng)該是這個長度非常非常長，現(xiàn)有托管堆內(nèi)存不大夠，所以引起長時間的GC了。
8．我們直接去看看這行代碼到底在干嘛吧，看到藍色噴霧了吧，那個地方可以對應(yīng)到代碼的行數(shù)（我的截屏上只有D:\I 這個樣子），屏幕太小了，我沒法直接貼出來。但是上面顯示是第64行。
我們可以看到iMsiDayCountDic是一個ConcurrentDictionary，但是用.Keys.Contains這個用法，額，我們可以想到， Key這個應(yīng)該是一個ICollection，然后再上面調(diào)用Contains應(yīng)該是新生成一個List<ulong>，然后把Dict里面的key全部copy到這個List<ulong>中，當(dāng)Dict里面的數(shù)據(jù)非常多的時候，在生成List<ulong>的過程中，List<ulong>需要每次不斷申請自身長度的2倍，于是慢慢就GC了，整個處理被阻塞了，其實Dict有另外的方法了
我們修改成這個樣子，就OK了。
原文鏈接：http://www.cnblogs.com/StevenChennet/archive/2012/08/14/2638079.html
【編輯推薦】
