網站High CPU分析

  網站升級後，說有High CPU的問題。mstsc上去後，看了一下，果然如此，w3wp.exe的cpu幾乎一直是滿的，我的遠端桌面操作也很慢。下載下來windbg，裝好，抓了兩個dump。首先!runaway一下，

0:022> !runaway
 User Mode Time
  Thread       Time
  22:8cc       0 days 0:17:15.238
  23:4d8       0 days 0:15:20.936
  15:898       0 days 0:09:15.316
  24:c64       0 days 0:05:07.587
這是前4個線程，一共佔用了47分鐘左右，我們再看一下time的時間：

0:022> .time
Debug session time: Sun Mar  9 15:07:52.000 2008 (GMT+8)
System Uptime: 1 days 2:04:59.903
Process Uptime: 0 days 0:55:38.000
  Kernel time: 0 days 0:00:07.000
  User time: 0 days 0:48:41.000

cool，.time的時間和!runaway的幾乎一致，再看看!threadpool的數字：

0:022> !threadpool
CPU utilization 100%
Worker Thread: Total: 5 Running: 5 Idle: 0 MaxLimit: 200 MinLimit: 2
Work Request in Queue: 15
Unknown Function: 6a2aa6fb  Context: 0190c5b8
AsyncTimerCallbackCompletion TimerInfo@01969b30
AsyncTimerCallbackCompletion TimerInfo@01969428
Unknown Function: 6a2aa6fb  Context: 0190ccb8
AsyncTimerCallbackCompletion TimerInfo@019698a8
AsyncTimerCallbackCompletion TimerInfo@01969c98
AsyncTimerCallbackCompletion TimerInfo@019f5778
AsyncTimerCallbackCompletion TimerInfo@01918658
AsyncTimerCallbackCompletion TimerInfo@01969788
Unknown Function: 6a2aa6fb  Context: 0190cb38
AsyncTimerCallbackCompletion TimerInfo@019695d8
Unknown Function: 6a2aa6fb  Context: 0190caf8
AsyncTimerCallbackCompletion TimerInfo@01969740
Unknown Function: 6a2aa6fb  Context: 0190c178
Unknown Function: 6a2aa6fb  Context: 0190cbf8
--------------------------------------
Number of Timers: 9
--------------------------------------
Completion Port Thread:Total: 2 Free: 2 MaxFree: 4 CurrentLimit: 2 MaxLimit: 200 MinLimit: 2

這些資訊基本夠了，罪魁禍首就是!runaway跑的那幾個線程，我們隨便抓兩個來看看：

0:022> kb
ChildEBP RetAddr  Args to Child             
00005205 7a4c72c0 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.RegexCharClass.CharInClassRecursive(Char, System.String, Int32)+0x20
00005205 7a4b16e5 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.RegexInterpreter.Go()+0xc40
00005205 7a4b15c3 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.RegexRunner.Scan(System.Text.RegularExpressions.Regex, System.String, Int32, Int32, Int32, Int32, Boolean)+0xa5
00005205 7a4b14af 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.Regex.Run(Boolean, Int32, System.String, Int32, Int32, Int32)+0x103
ffffffff 7a4dc313 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.Regex.Match(System.String, Int32)+0x1f
ffffffff 7a4d1c39 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.RegexReplacement.Replace(System.Text.RegularExpressions.Regex, System.String, Int32, Int32)+0x47
0606f8ac 7a4d1b53 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.Regex.Replace(System.String, System.String, Int32, Int32)+0x99
05d8ed04 0ff965c7 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.Regex.Replace(System.String, System.String)+0x2f
05d8ed04 0ff96530 00000000 00000000 00000000 3rdparty_Framework!3rdparty.Framework.Text.HtmlHelper.RemoveHtmlComments(System.String)+0x67
00000000 0ff96477 00000000 00000000 00000000 3rdparty_Framework!3rdparty.Framework.Text.HtmlHelper.RemoveHtmlAndComments(System.String)+0x38
10c3e8a8 0ff96142 00000000 00000000 00000000 3rdparty_Framework!3rdparty.Framework.Components.AggregatedPost.set_Description(System.String)+0x2f
10c3e8a8 0ff95d8e 00000000 00000000 00000000 3rdparty_Framework!3rdparty.Framework.Data.DataHelper.LoadAggreatedPost(System.Data.IDataReader)+0x1e2
10c3e910 0ff95c02 00000000 00000000 00000000 3rdparty_Framework!3rdparty.Framework.Data.DatabaseObjectProvider.GetAggregatedPosts(Int32, Int32, Int32)+0x126
10c3e958 0ff9e4eb 00000000 00000000 00000000 3rdparty_Framework!3rdparty.Framework.Data.Cacher.GetPagedAggregatedPosts(Int32, Int32, Int32, 3rdparty.Framework.CacheDuration, Boolean)+0x14a
10c3e9b0 0ff9e364 00000000 00000000 00000000 3rdparty_Blog_Web!3rdparty.Blog.Web.WebForm1.BindData()+0x16b
10c3ec04 66f12980 00000000 00000000 00000000 3rdparty_Blog_Web!3rdparty.Blog.Web.WebForm1.Page_Load(System.Object, System.EventArgs)+0x44
10c3ec04 6628eff2 00000000 00000000 00000000 System_Web_RegularExpressions_ni!System.Web.Util.CalliHelper.EventArgFunctionCaller(IntPtr, System.Object, System.Object, System.EventArgs)+0x10
10c3ec04 6613cb24 00000000 00000000 00000000 System_Web_ni!System.Web.Util.CalliEventHandlerDelegateProxy.Callback(System.Object, System.EventArgs)+0x22
10c3ec04 6613cb70 00000000 00000000 00000000 System_Web_ni!System.Web.UI.Control.OnLoad(System.EventArgs)+0x64
10c3ec04 6614e14d 00000000 00000000 00000000 System_Web_ni!System.Web.UI.Control.LoadRecursive()+0x30

再看看其他線程的：

0:015> kb
ChildEBP RetAddr  Args to Child             
0000515e 7a4b16e5 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.RegexInterpreter.Go()+0x152b
0000515e 7a4b15c3 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.RegexRunner.Scan(System.Text.RegularExpressions.Regex, System.String, Int32, Int32, Int32, Int32, Boolean)+0xa5
0000515e 7a4b14af 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.Regex.Run(Boolean, Int32, System.String, Int32, Int32, Int32)+0x103
ffffffff 7a4dc313 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.Regex.Match(System.String, Int32)+0x1f
ffffffff 7a4d1c39 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.RegexReplacement.Replace(System.Text.RegularExpressions.Regex, System.String, Int32, Int32)+0x47
05f79678 7a4d1b53 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.Regex.Replace(System.String, System.String, Int32, Int32)+0x99
05db3568 0ff965c7 00000000 00000000 00000000 System_ni!System.Text.RegularExpressions.Regex.Replace(System.String, System.String)+0x2f
05db3568 0ff96530 00000000 00000000 00000000 3rdparty_Framework!3rdparty.Framework.Text.HtmlHelper.RemoveHtmlComments(System.String)+0x67
00000000 0ff96477 00000000 00000000 00000000 3rdparty_Framework!3rdparty.Framework.Text.HtmlHelper.RemoveHtmlAndComments(System.String)+0x38
0140f0d8 0ff96142 00000000 00000000 00000000 3rdparty_Framework!3rdparty.Framework.Components.AggregatedPost.set_Description(System.String)+0x2f
0140f0d8 0ff95d8e 00000000 00000000 00000000 3rdparty_Framework!3rdparty.Framework.Data.DataHelper.LoadAggreatedPost(System.Data.IDataReader)+0x1e2
0140f140 0ff95c02 00000000 00000000 00000000 3rdparty_Framework!3rdparty.Framework.Data.DatabaseObjectProvider.GetAggregatedPosts(Int32, Int32, Int32)+0x126
0140f188 0ff9e4eb 00000000 00000000 00000000 3rdparty_Framework!3rdparty.Framework.Data.Cacher.GetPagedAggregatedPosts(Int32, Int32, Int32, 3rdparty.Framework.CacheDuration, Boolean)+0x14a
0140f1e0 0ff9e364 00000000 00000000 00000000 3rdparty_Blog_Web!3rdparty.Blog.Web.WebForm1.BindData()+0x16b
0140f434 66f12980 00000000 00000000 00000000 3rdparty_Blog_Web!3rdparty.Blog.Web.WebForm1.Page_Load(System.Object, System.EventArgs)+0x44
0140f434 6628eff2 00000000 00000000 00000000 System_Web_RegularExpressions_ni!System.Web.Util.CalliHelper.EventArgFunctionCaller(IntPtr, System.Object, System.Object, System.EventArgs)+0x10
0140f434 6613cb24 00000000 00000000 00000000 System_Web_ni!System.Web.Util.CalliEventHandlerDelegateProxy.Callback(System.Object, System.EventArgs)+0x22
0140f434 6613cb70 00000000 00000000 00000000 System_Web_ni!System.Web.UI.Control.OnLoad(System.EventArgs)+0x64
0140f434 6614e14d 00000000 00000000 00000000 System_Web_ni!System.Web.UI.Control.LoadRecursive()+0x30
0140f434 6614d8e3 00000000 00000000 00000000 System_Web_ni!System.Web.UI.Page.ProcessRequestMain(Boolean, Boolean)+0x59d

其他兩個線程和這兩個類似。

偶感覺是在太幸運了，居然碰到這麼一個simple的high cpu，哈哈！那看一下，為什麼Regex.Replace會慢？運行一下!clrstack -a命令：

0:015> !clrstack -a
OS Thread Id: 0x898 (15)
ESP       EIP   

====================其他太長，省略……=============================

0140f034 7a4d1b53 System.Text.RegularExpressions.Regex.Replace(System.String, System.String)
    PARAMETERS:
        this = <no data>
        input = <no data>
        replacement = <no data>

0140f044 0ff965c7 Joycode.Framework.Text.HtmlHelper.RemoveHtmlComments(System.String)
    PARAMETERS:
        text = 0x05da9298
    LOCALS:
        <CLR reg> = 0x05db3568
        <CLR reg> = 0x00000000
        0x0140f044 = 0x00000000

====================其他太長，省略……=============================

哦，那個字串的地址是0x05da9298，看看大小，是41K

0:015> !objsize 0x05da9298
sizeof(05da9298) =        41,680 (      0xa2d0) bytes (System.String)

如果do這個字串的話，我們能看到它是一個html文本。因為runaway和.time和threadpool的資料太明顯，so，斷定問題就在於replace的字串太大或者頻度太高造成的。

後來經過確認，RemoveHtmlComments代碼中的Regex.Replace沒有用，so，直接comment掉了，問題解決。

額外看一下別的東西：

Address	MT	Priority	Create Time	Expires	Last Updated	Key Class Name
01b1c6cc	6639d580	Normal	03/09/2008 06:12:14	12/31/9999 23:59:59 0	0	dmachine/webroot/2/app_code System.Web.CachedPathData
01b1f470	6639d580	Normal	03/09/2008 06:12:14	12/31/9999 23:59:59	0	dmachine/webroot/2/global.asax System.Web.CachedPathData
01b3b3b0	6639d580	Normal	03/09/2008 06:12:15	12/31/9999 23:59:59	03/09/2008 07:07:35	dmachine/webroot/2/systemmessages System.Web.CachedPathData

這是aspnetcache的很少一部分的內容，值得注意的是，有很多cache的內容，到期時間是9999年。實際上，我們有很大理由可以判斷，“天長日久”，w3wp會因為Out Of Memory而導致recycled問題，或者是訪問量驟增並持續一段時間，會導致網站短期內崩掉。

再看一下heap：

0:015> !heapstat
Heap     Gen0         Gen1         Gen2         LOH
Heap0    7291624      255092       5071228      13381296   
Heap1    7178448      440428       4637748      14825768   
Total    14470072     695520       9708976      28207064   

Free space:                                                 Percentage
Heap0    84           12           6568         2011792     SOH:  0% LOH: 15%
Heap1    2588         12           392          7699728     SOH:  0% LOH: 51%
Total    2672         24           6960         9711520    

大對象是最大的，，幾乎等於gen0+gen1+gen2的總和。我們看看整體情況先：

 0:015> .foreach(myobj {!dumpheap -short -min 85000}) {!objsize myobj}
sizeof(09c07bf0) =      689,900 (     0xa86ec) bytes (System.Byte[])
sizeof(09cb02e0) =      616,976 (     0x96a10) bytes (System.Byte[])
sizeof(09e2f2a8) =      616,976 (     0x96a10) bytes (System.Byte[])
====================其他太長，省略……=============================
sizeof(0c89cf50) =      616,976 (     0x96a10) bytes (System.Byte[])
sizeof(09d7c320) =      131,084 (     0x2000c) bytes (System.Int32[])
====================其他太長，省略……=============================
sizeof(0bec8f60) =    1,114,124 (    0x11000c) bytes (System.Int32[])
sizeof(0c092a68) =    1,114,124 (    0x11000c) bytes (System.Int32[])
sizeof(09b8cb40) =      105,512 (     0x19c28) bytes ()
sizeof(09bc6780) =      263,280 (     0x40470) bytes ()
====================其他太長，省略……=============================
sizeof(0c42f080) =    4,644,560 (    0x46ded0) bytes ()
sizeof(09b26468) =      262,164 (     0x40014) bytes (System.String)
====================其他太長，省略……=============================
sizeof(0bda0f00) =      262,164 (     0x40014) bytes (System.String)
sizeof(0bfd8f70) =      262,164 (     0x40014) bytes (System.String)

byte數組：

0:015> !gcroot 0c398670
Note: Roots found on stacks may be false positives. Run "!help gcroot" for
more info.
Scan Thread 7 OSThread c60
Scan Thread 13 OSThread aec
Scan Thread 14 OSThread c68
Scan Thread 15 OSThread 898
ESP:140f088:Root:  05da5d54(System.Data.SqlClient.SqlDataReader)->
  05da5a18(System.Data.SqlClient.SqlConnection)->
  01d3a928(System.Data.SqlClient.SqlInternalConnectionTds)->
  05b84ccc(System.Data.ProviderBase.DbConnectionPool)->
  05b84f9c(System.Collections.Generic.List`1[[System.Data.ProviderBase.DbConnectionInternal, System.Data]])->
  05b84fb4(System.Object[])->
  05e03e00(System.Data.SqlClient.SqlInternalConnectionTds)->
  05e03e9c(System.Data.SqlClient.TdsParser)->
  05e03f3c(System.Data.SqlClient.TdsParserStateObject)->
  0c398670(System.Byte[])
ESP:140f0e8:Root:  05da5d54(System.Data.SqlClient.SqlDataReader)->
  05da5a18(System.Data.SqlClient.SqlConnection)->
  01d3a928(System.Data.SqlClient.SqlInternalConnectionTds)->
  05b84ccc(System.Data.ProviderBase.DbConnectionPool)->
  05b84f9c(System.Collections.Generic.List`1[[System.Data.ProviderBase.DbConnectionInternal, System.Data]])->
  05b84fb4(System.Object[])->
  05e03e00(System.Data.SqlClient.SqlInternalConnectionTds)->
  05e03e9c(System.Data.SqlClient.TdsParser)->
  05e03f3c(System.Data.SqlClient.TdsParserStateObject)->
  0c398670(System.Byte[])

其他的bye數組類似，都是在執行SqlDataReader的操作。（為啥這樣，這個callstack看不到）

看int32數組：

0:015> !gcroot 09fd4e60
Note: Roots found on stacks may be false positives. Run "!help gcroot" for
more info.
Scan Thread 7 OSThread c60
====================其他太長，省略……=============================
Scan Thread 24 OSThread c64
ecx:Root:  01e51c1c(System.Text.RegularExpressions.RegexInterpreter)->
  09fd4e60(System.Int32[])
esi:Root:  01e51c1c(System.Text.RegularExpressions.RegexInterpreter)->
  09fd4e60(System.Int32[])
ESP:114ae598:Root:  01e51c1c(System.Text.RegularExpressions.RegexInterpreter)->
  09fd4e60(System.Int32[])
ESP:114ae5ac:Root:  01e51c1c(System.Text.RegularExpressions.RegexInterpreter)->
  09fd4e60(System.Int32[])
Scan Thread 26 OSThread 9ac
Scan Thread 27 OSThread 80c

這個是上面分析的Regex。

字串的資訊，就是上面看到的，都是html reply。針對這幾種類型，我們做一個總結（在所有大對象中）

byte數組：4M，這個是sqldatareader讀出來的資料

int32數組：5.8M，這個是因為regex和下面的string導致的

string：8.5M

另外：
0:015> !finddebugmodules
Loading all modules.
Searching for modules built in debug mode...

App_GlobalResources.-mywaxaw.dll not built release
App_Code.fqhaeca6.dll not built release
3rdparty.Framework.DLL not built release
App_global.asax.0y1c1i6p.dll not built release
3rdparty.Blog.Web.DLL not built release
freetextbox.DLL not built release
3rdparty.BlogML.DLL not built release
3rdparty.Extensibility.DLL not built release
3rdparty.Installation.DLL not built release
3rdparty.Plugins.Core.DLL not built release
3rdparty.Plugins.Examples.DLL not built release
3rdparty.Scripting.DLL not built release
3rdparty.Web.Controls.DLL not built release
App_Web_lab8my1c.dll not built release
App_Theme_Home.Clever.__mjadjg.dll not built release
App_Web_xppxn64l.dll not built release
App_Web_yxlgarwj.dll not built release
App_Web_a8wjdvdv.dll not built release
App_Web_ijqvv7ky.dll not built release
App_Web_xxkqxoen.dll not built release
App_Web_b25tsu-i.dll not built release
App_Web_kcb_q9mh.dll not built release
App_Theme_theme.elitecircle.jmea1orn.dll not built release
App_Web_site.master.9fb3aa03.6svjtsyu.dll not built release
App_GlobalResources.-mywaxaw.resources.dll not built release
App_Theme_theme.default.rggbez76.dll not built release
App_Web_post.aspx.9fb3aa03.ocnogniv.dll not built release
App_Web_k_ivm-xy.dll not built release
App_Web_category.aspx.9fb3aa03.lq_3jsov.dll not built release
App_Web_r8dwq35a.dll not built release
App_Web_archivemonth.aspx.9fb3aa03.jkc9sbgz.dll not built release
App_Web_gallery.aspx.9fb3aa03.vc-q4rsf.dll not built release
App_Web_contact.aspx.9fb3aa03.ayhi_kzk.dll not built release
App_Web_vocni5-f.dll not built release
App_Web_zgfpt_vo.dll not built release

Done Seaching

上述所有module都是debug模式的，這裡需要我們修改一下web.config，設定debug=false以及batch compilation為true，這樣也能一定程度上提高performance。

沒啥結論，就這麼結束了。