症状:
下班前,收到报警邮件。一个应用的两台服务器CPU 过高。打开监控一看CPU都100了。没找到原因之前,先抓好DUMP 然后重启应用程序池。
!threadpool 可以看到CPU 利用率
!runaway 查看运行的线程和运行时间
解决CPU 高的问题,应该从运行的线程上分析。分析它们都在干什么,哪个线程一直占用CPU运行时间
~threadid s 切换到运行时间最长的几个线程
k 显示当前线程的call stack
发现都是在GC线程(SVR::gc_heap::gc_thread_stub) ,难道是它们造成了CPU 高?
但已经运行了十几个小时,CPU是突然升高的。应该不是这几个线程的问题。
然后,我把所有线程都切换一下,查看线程的调用堆栈
发现很多线程都是再等待GC 完成(SVR::GCHeap::WaitUntilGCComplete)
应该是某个线程,正在触发GC函数——从网上找到的方法。
~* kb 得到所有的本地调用堆栈寻找线程中触发GC的函数
(mscorwks!SVR::GCHeap::GarbageCollectGeneration)
搜索后找到是102这个线程正在触发GC,调用System.String.InternalSubString(Int32, Int32, Boolean) 字符串截取的时候。需要收集大对象(clr!SVR::gc_heap::allocate_large_object,clr!SVR::gc_heap::allocate_more_space),分配更多的空间。显然因为字符串很大才会造成GC大对象。
!dumpstackobjects 打印当前线程保存的托管对象。
通过这个找到一些线索。如下图
这是根据国家查找的请求,将会返回很大的数据量。序列化将产生很大的字符串。
再查找代码,返回结果前会执行return xml.TrimEnd(' '); 难怪会调用InternalSubString 字符串截取的方法。这会第二次分配一个很大的空间来存储转换后的字符串。
另外查找其它线程后发现有八个线程都在调用同一个方法:
!clrstack –p 查看当前线程参数地址
!do 0x0000000120ec8fc8 查看某个地址对应的对象信息
经验证都是同样的请求,这样将造成频繁的GC,导致CPU 升高。
最后通过查看监控发现,这个接口的调用量有突然上升和CPU 升高的时间点是一致的。联系调用方确认下原因,他们的memcached 那段时间失效,造成每次都直接调用接口拉取数据。服务器的负载均衡不完美,大量请求都映射到同两台机器上,使得两台机器CPU 一百。