記一次 .NET 某旅行社Web站 CPU爆高分析

一線碼農發表於2021-05-17

一:背景

1. 講故事

前幾天有位朋友wx求助,它的程式記憶體經常飆升,cpu 偶爾飆升,沒找到原因,希望幫忙看一下。

可惜發過來的 dump 只有區區2G,能在這裡面找到記憶體洩漏那真有兩把刷子。。。???,所以我還是希望他的程式記憶體漲到 5G+ 的時候再給我看看,既然記憶體看不了,那就看看這個偶爾飆升的CPU是個啥情況?老辦法,上windbg說話。

二: windbg 分析

1. CPU 到底是多少

要想檢視這個快照生成時機器的cpu使用率,可以使用 !tp 命令。


0:033> !tp
CPU utilization: 93%
Worker Thread: Total: 800 Running: 800 Idle: 0 MaxLimit: 800 MinLimit: 320
Work Request in Queue: 3203
    Unknown Function: 000007fefb551500  Context: 000000002a198480
    Unknown Function: 000007fefb551500  Context: 0000000028a70780
    Unknown Function: 000007fefb551500  Context: 000000002a182610
    Unknown Function: 000007fefb551500  Context: 00000000262a2700
    ...

本以為一個簡單的命令,結果螢幕上呼啦啦的一堆。。。 有點意外,從上面的卦象看:當前CPU利用率是 93%,沒毛病,確實是CPU飆升,比較驚訝的是,執行緒池上限800個執行緒全部被打滿,太悲壯了。。。可更悲壯的是執行緒池佇列中還有 3203 個待處理的任務,可以猜測程式不僅高CPU,還有掛死現象。。。

接下來的問題是:這800個壯士到底怎麼啦,程式現在正是用人之際,要想找出答案,還是按照我的慣性思維,檢視同步塊表。

2. 執行緒同步塊表

要想檢視同步塊表,可以使用 !synblk 命令。


0:033> !syncblk
Index SyncBlock MonitorHeld Recursion Owning Thread Info  SyncBlock Owner
  188 0000000010defc28            1         1 000000001e8fb400 9f4 715   00000003ff1e3d80 System.Web.HttpApplicationStateLock
126159 000000001e424e28            1         1 0000000023425e00 1f14 695   0000000301210038 ASP.global_asax
126173 00000000281acaf8            1         1 0000000024b8ea70 24ec 785   00000000ff8c5e10 ASP.global_asax
126289 00000000247a4068            1         1 0000000027ee93c0 808 413   0000000306aca288 ASP.global_asax
126368 0000000027180dd8            1         1 0000000028005cb0 1e7c 650   00000002008d6280 ASP.global_asax
126489 0000000027211dd8            1         1 0000000026862420 ec4 220   000000030611a290 ASP.global_asax
126788 00000000247924b8            1         1 0000000021871ff0 2784 529   00000004039901a8 ASP.global_asax
126843 00000000285b8d28            1         1 000000001cbd6710 2170 456   00000004007ec748 ASP.global_asax
126934 0000000021b212b8            1         1 0000000026ca7590 16cc 472   000000030090e810 ASP.global_asax
127251 0000000024769188            1         1 000000002831eaf0 2b68 648   0000000207051038 ASP.global_asax
...

-----------------------------
Total           141781
CCW             2
RCW             4
ComClassFactory 0
Free            140270

我去,又是呼啦啦的一堆,從上面的卦象可以看出兩點資訊:

  • MonitorHeld: 1

表示當前有一個執行緒正在持有鎖。

  • ASP.global_asax , System.Web.HttpApplicationStateLock

表示當前執行緒持有的物件。

不過綜合來看有點奇怪,除了第一個執行緒持有 HttpApplicationStateLock,後面所有的執行緒持有的 ASP.global_asax 物件都有不同的記憶體地址:0000000301210038,00000000ff8c5e10,感覺lock的物件不是執行緒共享式的 static,更像是一個 instance,蠻有意思的,接下來抽兩個執行緒看看它的執行緒棧,比如這裡的:715,695

3. 檢視執行緒棧

要想檢視執行緒棧,可以用 !clrstack 命令。


從這兩個執行緒棧上看,分別是卡在 xxx.MvcApplication.Session_Start 方法中的 System.Threading.Monitor.Enter(System.Object)System.Threading.Monitor.ObjWait ,總的來說這裡的 Session_Start 方法肯定是有問題的,所以得想辦法把原始碼匯出來看一看。

4. 檢視問題程式碼

要想匯出 Session_Start 方法,使用組合命令 !ip2md + !savemodule 即可。


||2:2:1781> !ip2md 000007fe99c6f0c5
MethodDesc:   000007fe990fe080
Method Name:  xxx.xxx.xxx.MvcApplication.Session_Start(System.Object, System.EventArgs)
Class:        000007fe991ae0c0
MethodTable:  000007fe990fe238
mdToken:      0000000006000119
Module:       000007fe990fd750
IsJitted:     yes
CodeAddr:     000007fe99c6e1f0
Transparency: Critical
||2:2:1781> !savemodule 000007fe990fd750 E:\dumps\Session_Start.dll
3 sections in file
section 0 - VA=2000, VASize=17538, FileAddr=200, FileSize=17600
section 1 - VA=1a000, VASize=3ac, FileAddr=17800, FileSize=400
section 2 - VA=1c000, VASize=c, FileAddr=17c00, FileSize=200

然後藉助 ILSpy 反編譯工具檢視,由於比較敏感,我就多模糊一點,請大家見諒!

看完上面的程式碼,我其實有一點不解,既然是往 Application 中賦值,為啥不提取到 Application_Start 中呢? 我猜測開發人員也是無所謂,怎麼方便怎麼來,接下來看一下 Application 的原始碼。


public sealed class HttpApplicationState : NameObjectCollectionBase
{
    private HttpApplicationStateLock _lock = new HttpApplicationStateLock();

    public void Set(string name, object value)
    {
        _lock.AcquireWrite();
        try
        {
            BaseSet(name, value);
        }
        finally
        {
            _lock.ReleaseWrite();
        }
    }
}

internal class HttpApplicationStateLock : ReadWriteObjectLock
{
    internal override void AcquireWrite()
    {
        int currentThreadId = SafeNativeMethods.GetCurrentThreadId();
        if (_threadId == currentThreadId)
        {
            _recursionCount++;
            return;
        }
        base.AcquireWrite();
        _threadId = currentThreadId;
        _recursionCount = 1;
    }

    internal override void ReleaseWrite()
    {
        int currentThreadId = SafeNativeMethods.GetCurrentThreadId();
        if (_threadId == currentThreadId && --_recursionCount == 0)
        {
            _threadId = 0;
            base.ReleaseWrite();
        }
    }
}

internal class ReadWriteObjectLock
{
    internal virtual void AcquireWrite()
    {
        lock (this)
        {
            while (_lock != 0)
            {
                try
                {
                    Monitor.Wait(this);
                }
                catch (ThreadInterruptedException)
                {
                }
            }
            _lock = -1;
        }
    }
    internal virtual void ReleaseWrite()
    {
        lock (this)
        {
            _lock = 0;
            Monitor.PulseAll(this);
        }
    }
}

程式碼有點長,但總的來說這裡的程式碼不簡單,Application 通過 lock 自己封裝了一個 讀寫鎖,不簡單歸不簡單,但這裡有什麼問題呢 ? 就算寫錯了地方貌似也不會造成 cpu 爆高吧?

其實這裡涉及到了一個概念:那就是 lock convoys (鎖護送)

5. lock convoys (鎖護送)

關於什麼是 lock convoys ,我找了一篇解釋很好的文章: 鎖護送 ,這裡我截一張圖,大家仔細品品。

這也是 無鎖程式設計 一直在抨擊的現象。

三:總結

我看了下這個 Session_Start 方法中,大概有 105 個 Application[xxx],也就意味著有 105 個 lock 等著當前執行緒去闖關。。。 而此時有近800個執行緒已進入到此方法中,合計一下不少於 8W個鎖等著這些執行緒去闖,在配上被迫的海量cpu時間片切換,喚醒再休眠,休眠再喚醒,大家相互交錯一起把 cpu 給抬起來了。

解決方法很簡單,盡最大努力降低這些 序列lock 的個數,能降到一個甚至沒有就更好了 ???。

  • 對 Application 的賦值全部提取到 Application_Start 中,畢竟程式啟用時無人競爭。

  • 儘量將 單行賦值 改成 批量賦值

更多高質量乾貨:參見我的 GitHub: dotnetfly

圖片名稱

相關文章