网站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
  
  
  这个是上面分析的正则表达式。
  
  字符串的信息，就是上面看到的，都是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。
  
  没啥结论，就这么结束了。