本文主要是介绍记一次 .NET 某医院HIS系统 CPU爆高分析，希望对大家解决编程问题提供一定的参考价值，需要的开发者们随着小编来一起学习吧！
一：背景
1. 讲故事
前几天有位朋友加 wx 抱怨他的程序在高峰期总是莫名其妙的cpu爆高，求助如何分析？
和这位朋友沟通下来，据说这问题困扰了他们几年????，还请了微软的工程师过来解决，无疾而终，应该还是没找对微软的大佬。。。
关于程序CPU爆高的问题，老读者应该知道我都写了好几篇了，基本上归为两类：
GC 触发
大量 lock 锁
少部分就是各种莫名其妙的问题了，无法一一列举 ????????????，既然朋友找到我了，我得想办法给他解决，话不多聊，上 windbg。
二：windbg 分析
1. 查看同步块表
遇到这种问题，首查 同步块表 已经是我的惯性思维了，命令很简单 !syncblk 。
0:000> !syncblk
Index SyncBlock MonitorHeld Recursion Owning Thread Info SyncBlock Owner
-----------------------------
Total 20779
CCW 16
RCW 21
ComClassFactory 0
Free 16490我去，扑了一个空，同步块表中啥也没有。。。既然和锁没关系，那就看看线程吧，毕竟线程就是靠 CPU 养着的。
2. 查看线程
要想查看系统中的 托管线程 ，可以使用 !t 命令, 线程比较多，稍微简化一下。
0:000> !t
ThreadCount: 135
UnstartedThread: 0
BackgroundThread: 132
PendingThread: 0
DeadThread: 1
Hosted Runtime: noLock ID OSID ThreadOBJ State GC Mode GC Alloc Context Domain Count Apt Exception34 1 25d4 000001ea28702130 28220 Preemptive 0000000000000000:0000000000000000 000001ea286ee080 0 Ukn 74 2 3ed0 000001ea286fa940 2b220 Preemptive 0000000000000000:0000000000000000 000001ea286ee080 0 MTA (Finalizer) 76 3 4a70 000001f4447d7810 102a220 Preemptive 0000000000000000:0000000000000000 000001ea286ee080 0 MTA (Threadpool Worker) 77 4 326c 000001f4447dbe60 21220 Preemptive 0000000000000000:0000000000000000 000001ea286ee080 0 Ukn 78 6 2dac 000001f4447d9750 1020220 Preemptive 0000000000000000:0000000000000000 000001ea286ee080 0 Ukn (Threadpool Worker) 79 7 1468 000001f444a2d6f0 21220 Preemptive 0000000000000000:0000000000000000 000001ea286ee080 1 Ukn (GC) 80 8 f0 000001f444a2cf20 21220 Preemptive 0000000000000000:0000000000000000 000001ea286ee080 0 Ukn 81 9 3118 000001f444a2f630 21220 Preemptive 0000000000000000:0000000000000000 000001ea286ee080 0 Ukn 先卖个关子，可有朋友看出这些线程有什么异样？？？对，线程 79 的最后一列有一个 Ukn (GC) 标记，我想你肯定好奇，这说明什么？由于底层GC的模式有些变更，但不管怎么说，它在一定程度上告诉你，你的程序触发了GC，为了进一步验证，可以用 !t -special 看下 79 号线程到底属于什么类别以及更加详细的信息。
0:000> !t -special
ThreadCount: 135
UnstartedThread: 0
BackgroundThread: 132
PendingThread: 0
DeadThread: 1
Hosted Runtime: noLock ID OSID ThreadOBJ State GC Mode GC Alloc Context Domain Count Apt Exception34 1 25d4 000001ea28702130 28220 Preemptive 0000000000000000:0000000000000000 000001ea286ee080 0 Ukn 79 7 1468 000001f444a2d6f0 21220 Preemptive 0000000000000000:0000000000000000 000001ea286ee080 1 Ukn (GC) OSID Special thread type
41 38d8 DbgHelper
42 1c88 GC
74 3ed0 Finalizer
75 402c ProfilingAPIAttach
76 4a70 Timer
79 1468 GC SuspendEE 从最后一行输出中可以看到， 79就是GC线程，后面还有一个奇怪的 SuspendEE 标记，你又好奇了，这又啥意思？
SuspendEE=Suspend CLR Execution Engine (EE)
也就是说，79号线程把 CLR执行引擎 给冻结了，目的很简单，就是为了方便其他31个GC线程打理当前的 托管堆，不过这老哥机器真????????，32core，也不知道哪家医院这么给力，补充一下，用 !cpuid 验证。
0:000> !cpuid
CP F/M/S Manufacturer MHz0 6,62,4 <unavailable> 26001 6,62,4 <unavailable> 26002 6,62,4 <unavailable> 26003 6,62,4 <unavailable> 2600xxx
31 6,62,4 <unavailable> 2600既然预判到了是 GC 触发，下一步就可以把所有线程的托管和非托管堆栈全部调出来。
3. 查看各个线程栈
要想查看各个线程的托管和非托管栈很简单, 使用 !eestack 即可，然后可以检索关键词 WaitUntilGCComplete 来判断有多少线程在等待GC处理完毕。
从图中可以看出，当前有 40 个线程被阻塞了，真好，问题越来越清晰了，接下来再分析到底是哪个线程做了什么不该做的事，导致 GC 触发，同样也可以搜 try_allocate_more_space 来判断哪些线程正在分配空间。
我去，可以很明显的看出当前 170 和 187 号线程正在分配大对象 gc_heap::allocate_large_object 触发了 GC，本身大对象堆是一个令人生畏的东西，对它的回收清扫都是非常耗CPU资源的，这也和朋友说到的 1分钟左右CPU就下降了 的情况比较吻合。
4. 寻找祸首
现在关注点就在这两个线程上了，我看了下这两个线程栈都是同一处方法，所以这里就挑一个 187 线程来分析吧，可以用 !clrstack 看下它的托管栈。
0:187> !clrstack
OS Thread Id: 0x1ef0 (187)Child SP IP Call Site
00000054ce631e30 00007ffc4021bde2 System.String.FillStringChecked(System.String, Int32, System.String)
00000054ce631e70 00007ffc402222a8 System.String.ConcatArray(System.String[], Int32)
00000054ce631ed0 00007ffc40223528 System.String.Concat(System.String[])
00000054ce631f40 00007ffbe6dbdafb BLL.xxx.xxx.GetRowString(System.String, Boolean, Boolean, System.String, System.String, System.String, System.String, System.String, System.String, Int32, System.String, System.String, System.String, System.String, System.String, System.String, Int32, Int32, System.String, System.Nullable`1, System.Nullable`1, System.String, System.Nullable`1, System.Nullable`1, System.Nullable`1, System.Nullable`1, System.String, System.String, System.String, System.String, System.String ByRef)
00000054ce65cf40 00007ffbe6ab3187 BLL.xxx.xxx.ExpZB(System.String, Boolean, Boolean, System.String, System.String, System.String, System.String, Int32, System.String, System.String, System.String, Int32, System.String, System.String, System.String, System.String, System.String, System.String, Int32, Int32, System.String, System.Nullable`1, System.Nullable`1, System.String, System.Nullable`1, System.Nullable`1, System.Nullable`1, System.Nullable`1, System.String, System.String, System.String, System.String)从堆栈上看，貌似是使用了 System.String.Concat 拼接 string 所致，好家伙，string 拼接这么多年不知道被人抨击了多少次，还是有很多的人踩坑????????????，为了进一步验证，可以使用 !clrstack -p + !da -details xxx 看看这个 System.String[] 到底是什么，简化如下：
0:187> !clrstack -p
OS Thread Id: 0x1ef0 (187)
00000054ce631e70 00007ffc402222a8 System.String.ConcatArray(System.String[], Int32)PARAMETERS:values (<CLR reg>) = 0x000001ea69e8d2f8totalLength = <no data>
0:187> !da -details 0x000001ea69e8d2f8
Name: System.String[]
Size: 128(0x80) bytes
Array: Rank 1, Number of elements 13, Type CLASS
Element Methodtable: 00007ffc403d6948
[0] 000001f2391a83f0Name: System.StringMethodTable: 00007ffc403d6948EEClass: 00007ffc3fcd50e0Size: 445950(0x6cdfe) bytesFile: C:\Windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dllString: xxxxx从输出信息中可以看到，String[] 里面有 13 个元素，其中最大的一个 string 是 445950 bytes = 445k，大于大对象的85k界定，所以这里的 Concat 就是症结所在，同样 170 线程也是如此，接下来我还得要解决的一个问题是：为什么会有如此大的字符串产生，代码里面到底做了什么？？？要想寻找答案，还得从dump中导出源码一探究竟。
5. 查看问题代码
要想分析问题代码，可以通过 !ip2md + !savemodule 导出 BLL.xxx.xxx.GetRowString 方法。
0:187> !ip2md 00007ffbe6dbdafb
MethodDesc: 00007ffbe5342118
Method Name: BLL.xxx.xxx.GetRowString(System.String, Boolean, Boolean, System.String, System.String, System.String, System.String, System.String, System.String, Int32, System.String, System.String, System.String, System.String, System.String, System.String, Int32, Int32, System.String, System.Nullable`1<Int32>, System.Nullable`1<Int32>, System.String, System.Nullable`1<Single>, System.Nullable`1<Single>, System.Nullable`1<Single>, System.Nullable`1<Single>, System.String, System.String, System.String, System.String, System.String ByRef)
Class: 00007ffbe52fe328
MethodTable: 00007ffbe53421d8
mdToken: 0000000006000096
Module: 00007ffbe471a890
0:187> !savemodule 00007ffbe471a890 E:\dumps\RowString.dll
3 ps in file
p 0 - VA=2000, VASize=f7fcc, FileAddr=200, FileSize=f8000
p 1 - VA=fa000, VASize=3bc, FileAddr=f8200, FileSize=400
p 2 - VA=fc000, VASize=c, FileAddr=f8600, FileSize=200然后祭出 ILSpy 反编译这段代码。
好家伙，这写法真????????，无数的字符串拼接，gen2 和 LOH堆 都来不及分配内存段了????????????，真的是害死 GC 了。。。
三：总结
其实这是一个教科书式的问题，也有教科书式的解决方法，而且我看了下这个方法有 600 多行的代码，基本上都是做string拼接的事，最后说一下解决方案。
重构该方法，尽量用 StringBuilder 替代 String ，将因这种 GC 触发的次数降到最低。
最后的小彩蛋，貌似这个分析结果和朋友的深度怀疑不约而同。。。
END
工作中的你，是否已遇到 ...
1. CPU爆高
2. 内存暴涨
3. 资源泄漏
4. 崩溃死锁
5. 程序呆滞
等紧急事件，全公司都指望着你能解决... 危难时刻才能展现你的技术价值，作为专注于.NET高级调试的技术博主，欢迎微信搜索: 一线码农聊技术，免费协助你分析Dump文件，希望我能将你的踩坑经验分享给更多的人。
这篇关于记一次 .NET 某医院HIS系统 CPU爆高分析的文章就介绍到这儿，希望我们推荐的文章对编程师们有所帮助！
