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

导读：

　　看代码先：

　　

　　

　　

　　

　　Code 1

　　

　　using System; 2

　　

　　using System.Threading; 3

　　

　　4

　　

　　namespace HighCPU 5

　　

　　

　　

　　

　　

　　{ 6

　　

　　class Program 7

　　

　　

　　

　　

　　

　　{ 8

　　

　　static void Main(string[] args) 9

　　

　　

　　

　　

　　

　　{10

　　

　　Console.Clear();11

　　

　　Console.WriteLine("到命令行下，切换到windbg目录，执行adplus -hang -pn highcpu.exe -o c:\\dumps");12

　　

　　Console.WriteLine("如果要停止，按Ctrl+C结束程序");13

　　

　　Console.WriteLine("====================================================");14

　　

　　15

　　

　　while (true)16

　　

　　

　　

　　

　　

　　{17

　　

　　Console.SetCursorPosition(0, 3);18

　　

　　Console.Write(DateTime.Now.Ticks.ToString());19

　　

　　}

　　20

　　

　　}

　　21

　　

　　}

　　22

　　

　　}

　　23

　　

　　

　　这部分要介绍的内容是，我们在生产环境下，发现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，就能发现问题了。



本文转自

http://www.cnblogs.com/juqiang/archive/2008/01/11/1035689.html