記一次某網站生產環境CPU忽高忽低故障解決過程

感謝

感謝【一級碼農】 的幫助,之前也讀了大佬的好多文章,一直在學習中,也沒有實際操作過。
這次的過程也是在大佬的指點下完成的。

現象描述

從周六上午開始,陸續收到伺服器CPU高的報警簡訊,到下午已經累計三十多條報警了,看來確實得分析一下原因了。
打開雲監控,與實際情況一致,CPU居高不下
image.png

通過進程,很快鎖定是哪個應用,是一個car系統造成的
image.png
car系統的版本是.net 4.0
image.png

分析過程

通過以下命令,抓包,命令解釋,當CPU超過50%時,持續三秒,抓兩個包。進程ID是6100。進程ID在任務管理器中可以看到。

procdump -ma -c 50 -s 3 -n 2 6100

遇到如下錯誤
image.png
出現以上錯誤是因為沒有用管理員運行CMD,重新用管理員打開即可。
image.png
很快抓包完成。從伺服器down到本地。

# 載入sos和clr文件
0:016> .load C:\Windows\Microsoft.NET\Framework\v4.0.30319\sos.dll
0:016> .load C:\Windows\Microsoft.NET\Framework\v4.0.30319\clr.dll

0:062> !runaway
 User Mode Time
  Thread       Time
  16:dc4       0 days 0:13:12.593
  15:2be4      0 days 0:13:06.390
  17:2404      0 days 0:13:06.328
  18:bb4       0 days 0:12:45.953
  39:3294      0 days 0:04:10.500
  44:320       0 days 0:04:07.281
  38:3b24      0 days 0:04:06.156
  43:176c      0 days 0:04:00.218
  46:1118      0 days 0:03:55.359
  50:2a3c      0 days 0:03:54.921
  40:1aac      0 days 0:03:50.531
  51:2fb4      0 days 0:03:49.421
  47:2508      0 days 0:03:48.718

!runaway發現前幾個執行緒時間很長,那麼他們在幹什麼呢?
切到 16 號執行緒~16s

0:016> !clrstack
PDB symbol for clr.dll not loaded
Failed to load data access DLL, 0x80004005
Verify that 1) you have a recent build of the debugger (6.2.14 or newer)
            2) the file mscordacwks.dll that matches your version of clr.dll is 
                in the version directory or on the symbol path
            3) or, if you are debugging a dump file, verify that the file 
                mscordacwks_<arch>_<arch>_<version>.dll is on your symbol path.
            4) you are debugging on supported cross platform architecture as 
                the dump file. For example, an ARM dump file must be debugged
                on an X86 or an ARM machine; an AMD64 dump file must be
                debugged on an AMD64 machine.

You can also run the debugger command .cordll to control the debugger's
load of mscordacwks.dll.  .cordll -ve -u -l will do a verbose reload.
If that succeeds, the SOS command should work on retry.

If you are debugging a minidump, you need to make sure that your executable
path is pointing to clr.dll as well.

上面不是提示sos clr文件不對嗎,在伺服器上分析是沒有報這個錯的,所以我從伺服器上弄了兩個回來

.load D:\soft\WinDbg+procdump\procdump\car\sos.dll
.load D:\soft\WinDbg+procdump\procdump\car\clr.dll

0:018> .load D:\soft\WinDbg+procdump\procdump\car\sos.dll
0:018> .load D:\soft\WinDbg+procdump\procdump\car\clr.dll
0:018> !clrstack
PDB symbol for clr.dll not loaded
OS Thread Id: 0xbb4 (18)
Unable to walk the managed stack. The current thread is likely not a 
managed thread. You can run !threads to get a list of managed threads in
the process
Failed to start stack walk: 80070057

OK,現在不提示配置問題了。繼續分析

0:016> !clrstack
OS Thread Id: 0xdc4 (16)
Unable to walk the managed stack. The current thread is likely not a 
managed thread. You can run !threads to get a list of managed threads in
the process
Failed to start stack walk: 80070057
0:016> ~15s
eax=00000000 ebx=00000000 ecx=00000000 edx=00000000 esi=00000000 edi=0000053c
eip=76f2c0bc esp=1af3fbfc ebp=1af3fc6c iopl=0         nv up ei pl nz na pe nc
cs=0023  ss=002b  ds=002b  es=002b  fs=0053  gs=002b             efl=00000206
ntdll!NtWaitForSingleObject+0xc:
76f2c0bc c20c00          ret     0Ch

前四個執行緒,都提示not a managed thread
image.png
請教了一下【一級碼農】大佬,這個方向可能是錯誤的。那我們就只能換一個方向。
這裡大佬已經告訴我是拖管執行緒的問題,如果是我們首次分析,可能還需要先判斷是拖管還是非拖管的問題。這個後面再慢慢消化加上去。
我們這裡走一個捷徑,直接查拖管執行緒,有時候你也可以假裝碰碰運氣,說不定就能找到原因了呢。

~*e !clrstack 發現觸發了GC回收
image.png

image.png

!dumpstack 顯示當前調用棧上的所有託管對象的資訊,
image.png

發現這個Volcker.Autotrader.ProductPropertieData.GetAll()方法出現多次,明顯有多個執行緒卡在這裡了。那這個方法是幹啥的呢,
查看一下源碼就知道了。
當然,如果有時候你手裡沒有源碼,或者伺服器運行的和本地程式碼差異比較大,那就導出源程式碼

0:053> !ip2md 1c15f4bd
MethodDesc:   1b9ec174
Method Name:  Volcker.Autotrader.ProductPropertieData.GetAll()
Class:        1bd668a4
MethodTable:  1b9ec19c
mdToken:      06000088
Module:       1b9ebbd4
IsJitted:     yes
CodeAddr:     1c15f420
Transparency: Critical
0:053> !savemodule 1b9ebbd4 D:\dumps\car-cpu\GetAll.dll
3 sections in file
section 0 - VA=2000, VASize=1714c, FileAddr=200, FileSize=17200
section 1 - VA=1a000, VASize=3e8, FileAddr=17400, FileSize=400
section 2 - VA=1c000, VASize=c, FileAddr=17800, FileSize=200

需要提前創建好目錄 D:\dumps\car-cpu,找到上面的方法
image.png
這一行程式碼是幹啥的呢,解釋一下,其實是個通用的將資料庫錶轉換為實體類的方法。

        /// <summary>
        /// 根據IDataReader對屬性進行賦值
        /// </summary>
        /// <param name="reader">
        new public void LoadDataReader(IDataReader reader)
        {
            LoadDataReader(MethodBase.GetCurrentMethod(), this, reader);
        }
        
        /// <summary>
        /// 根據DataReader為對象屬性賦值
        /// </summary>
        /// <param name="method">所屬類MethodBase對象
        /// <param name="obj">
        /// <param name="reader">設置其屬性 (Property) 值的對象
        /// <returns></returns>
        virtual public void LoadDataReader(MethodBase method, Object obj,IDataReader reader)
        {
            Hashtable cols = new Hashtable();
            for (var i = 0; i < reader.FieldCount; i++)
            {
                cols.Add(reader.GetName(i).ToLower(), reader.GetValue(i));	//裝入數據到hashtable中
            }
            Hashtable h = GetFieldProperties(method, FieldType.DBField);	//獲取屬性的Hasttable
            foreach (var o in h.Keys)
            {
                PropertyInfo p = (PropertyInfo)h[o];
                Object v = null;

                if (cols.Contains(o))
                {
                    v = cols[o];
                }               

                if (v != null)
                {
                    SetPropertieValue(ref obj, ref p, ref v);
                }
            }
        }

這裡用了一個反射,通過上面的分析得到,問題出在這一行
Hashtable h = GetFieldProperties(method, FieldType.DBField); //獲取屬性的Hasttable
可能是這個類或者方法的屬性太多吧,或者其他原因造成的。
可能一開始寫這個反射方法用法沒有錯,但是防不住後面有人在類中或者方法中加了其他的東東,造成反射有問題了。
我以前也寫過類似的方法,沒有這個智慧,但也從來沒出過問題。
有時候,太智慧了也沒有啥必要,
最簡單的程式碼效率最高,搞這麼複雜有必要嗎?
不說這個了,解決問題先
由於程式碼歷史太悠久,相關細節完全不清楚,所以也不敢改動太大
目前的辦法就是加快取,這個其實是個字典表,理論上變化不會很大,所以加了24小時的快取,24小時請求一次。
改一下程式碼,更新一下看看。

效果很明顯啊,再觀察幾天看看。
image.png

總結

上面的分析過程基本上比較詳細了,但有些步驟可能沒有啥邏輯,原因就是靠經驗,或者運氣。經歷的越多,可能猜一下就大概知道原因在哪
再次感謝【一線碼農】的幫助,下面是大佬的總結
image.png

參考文章

一線碼農的github
教你配置windows上的windbg,linux上的lldb,打入clr內部這一篇就夠了

Tags: