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 鞠强 阅读(2115) 评论(14)  编辑 收藏 网摘

  回复  引用    
#1楼2008-01-11 19:46 | 信息谷[未注册用户]
这不是鞠老大吗 呵呵
  回复  引用  查看    
#2楼2008-01-11 20:00 | overred      
不错
  回复  引用  查看    
#3楼2008-01-11 21:32 | Jeffrey Zhao      
鞠老大,我14号去你那里拿书啊!
  回复  引用  查看    
#4楼[楼主]2008-01-11 22:19 | 鞠强      
jeffrey,我明天后天都在公司,你去找我吧!其他时间,我在外面做项目,很难回去的。
  回复  引用  查看    
#5楼2008-01-11 23:11 | Jeffrey Zhao      
@鞠强
哦……那么具体地址能不能再Email我一下呢?

  回复  引用  查看    
#6楼2008-01-11 23:29 | 二毛五      
windbg 很强,很直接
  回复  引用  查看    
#7楼2008-01-12 00:46 | flyingchen      
书我买了,我要签名。哈哈
  回复  引用  查看    
#8楼2008-01-12 10:23 | overred      
我每次怀着激动的心情打开老赵的博客
都被郁闷的卡死
只好在这诉苦了。。。。。555

windbging

  回复  引用  查看    
#9楼2008-01-12 13:18 | Jeffrey Zhao      
@overred
你用的是什么浏览器啊?我测试过各种主流浏览器,都没有问题啊。

  回复  引用  查看    
#10楼2008-01-12 16:07 | overred      
ie6
不过卡死大约3分钟就好了
是那个msn搞得

  回复  引用  查看    
#11楼2008-01-12 20:33 | BirdsHover      
受教了
  回复  引用  查看    
#12楼2008-01-14 13:37 | 维生素C.NET      
谢谢
  回复  引用  查看    
#13楼2008-02-02 14:09 | 蛙蛙池塘      
我觉得!runaway出来前几名不一定就是占CPU高的线程,只是执行时间长的线程吧,用!threadpool能看出一些CPU利用率的信息吧。
另外请楼主再详细讲下如何分析CPU高的问题。谢谢。

  回复  引用    
#14楼2008-05-29 14:56 | northsky330[未注册用户]
时阿,windbg察看程序异常引起的CPU高还行,如果我的网站每个线程占用的CPU比较平均,CPU总体高,这样debug就不好查了吧。Profile比较好吧。

最近做了个网站,优化后事务响应时间快了,大多数在(0.003sec)左右,但是CPU还是高(85个请求/sec,CPU占用率:22.5% 要求CPU在15%左右),怎样才能定位到哪些操作占用的CPU高?




发表评论

昵称: [登录] [注册]

主页:

邮箱:(仅博主可见)

评论内容:

  登录  注册

[使用Ctrl+Enter键快速提交评论]

0 1035689




相关文章:

相关链接: