Basic Windbg - 3.High CPU的分析及诊断方法

看代码先:
Code

这部分要介绍的内容是,我们在生产环境下,发现aspnet_wp.exe或者w3wp.exe的CPU在“某段时间”内居高不下,或者你自己的某个windows service,“某段时间”内占用CPU居高不下。这里我们简称为High CPU。
对于High CPU,相对而言很简单。抓dump就好了,执行adplus -hang -pn highcpu.exe -o c:\dumps。对于实际生产环境,一般的,你要这么做:adplus -hang -pn w3wp.exe -o c:\dumps

抓到了dump,先不要急,等2-3分钟,再抓一次(假设这个时候你进程的CPU还是很高),等2-3分钟,再抓一次。一般,我们抓到三个就够本了。
打开windbg,按照顺序,分别打开这三个dump文件。
加载sos:.load clr20\sos.dll
然后敲一个新命令:!runaway,第一个dump的结果如下
0:000> !runaway
 User Mode Time
  Thread       Time
   0:12a8      0 days 0:00:00.967
   2:148c      0 days 0:00:00.000
   1:1528      0 days 0:00:00.000


看不出来什么,继续看第二个的
0:000> !runaway
 User Mode Time
  Thread       Time
   0:12a8      0 days 0:00:05.678
   2:148c      0 days 0:00:00.000
   1:1528      0 days 0:00:00.000


有点意思了,继续看第三个的
0:000> !runaway
 User Mode Time
  Thread       Time
   0:12a8      0 days 0:00:10.795
   2:148c      0 days 0:00:00.000
   1:1528      0 days 0:00:00.000

看到这里,基本差不多了,我们发现,thread 0执行的时间持续在增长,从最初的0秒到现在的10秒。从目前的情况看,high cpu基本上是thread 0的代码造成的。那么,我们用前面介绍的命令!clrstack看一下:
0:000> !clrstack
OS Thread Id: 0x12a8 (0)
ESP       EIP    
0026edb8 774e0f34 [NDirectMethodFrameStandaloneCleanup: 0026edb8] System.IO.__ConsoleStream.WriteFile(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte*, Int32, Int32 ByRef, IntPtr)
0026edd4 7936b388 System.IO.__ConsoleStream.WriteFileNative(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte[], Int32, Int32, Int32, Int32 ByRef)
0026ee00 7936b2f4 System.IO.__ConsoleStream.Write(Byte[], Int32, Int32)
0026ee20 7936ab1c System.IO.StreamWriter.Flush(Boolean, Boolean)
0026ee38 793a7d8c System.IO.StreamWriter.Write(System.String)
0026ee50 79499046 System.IO.TextWriter+SyncTextWriter.Write(System.String)
0026ee5c 793ea4f6 System.Console.Write(System.String)
0026ee68 003e010f HighCPU.Program.Main(System.String[])
0026f0a8 79e7c74b [GCFrame: 0026f0a8]


这是第一个dump的,从中我们能看到,是在调用Console.Write
接着看第二个dump的,类似,我们发现如下代码:
0026ee5c 793ea4f6 System.Console.Write(System.String)
0026ee68 003e010f HighCPU.Program.Main(System.String[])


再看第三个dump,嗯,这个有点特殊。
0:000> !clrstack
OS Thread Id: 0x12a8 (0)
ESP       EIP    
0026ee20 774e0f34 [NDirectMethodFrameSlim: 0026ee20] Microsoft.Win32.Win32Native.SetConsoleCursorPosition(IntPtr, COORD)
0026ee34 793e8acb System.Console.SetCursorPosition(Int32, Int32)
0026ee68 003e00d5 HighCPU.Program.Main(System.String[])
0026f0a8 79e7c74b [GCFrame: 0026f0a8]


那么,此时我们可以通过后面介绍的dumpmodule命令把代码dump出来,然后用reflector反编译找到相关代码。当然,如果客户愿意,他们直接提供源代码,那就更好了。

如果仔细比较上面三个!runaway的结果,你会发现时间是0,5,10秒。实际上我基本上就是按照这个时间进度来抓的dump。在生产环境下,大家还是每隔2、3分钟抓一次为好。
这个cpu high稍微简单一下。复杂的情况下,我们会发现几十号或者几百号threads,那么抓dump下来后,比较三个dump每个!runaway的前10个结果(基本差不多这个数字),找到重复的threads,然后看code,就能发现问题了。
posted @ 2008-01-11 19:09 鞠强 阅读(...) 评论(...) 编辑 收藏

hello

world