一次.net cpu爆高分析-windbg sos基本命令使用及分析思路

前几日接前方反馈，线上升级后，IIS CPU爆高，已影响用户使用体验，遂指导现场运维赶紧dump一份内存。笔者现将分析过程分享如下，欢迎讨论指教。

windbg sos使用就不写了，网上已有大量教程。

运维发来截图，IIS CPU爆高。

windbg走起：
使用!tp

如下图CPU 96%，且还有8个等待cpu调度的任务，已出现任务堆积现象，说明此时CPU已相当繁忙。

16核心CPU基本全部爆满。

使用PerfView对dump进行火焰图分析如下，可见大量占用时间片较多的基本是Newtonsoft.Json。

CPU高，无外乎这几种可能：锁（死锁、以及.net中大量其他锁类型，如：SyncBlock、ReaderWriter等）、GC、以及死循环，下面将逐一进行排查。

1、查看同步块表如下：

从同步块表的卦象上看，正常，故可以排出存在由于线程同步导致的死锁引发的cpu爆高问题。

2、查看GC，如下：有线程此时处于GC状态

如上图可见，有线程处于GC。

再使用x clr!gc_heap::settings，在内存检索关键字，查看。

由于线上.net设置是服务器模式，故查看第二个。

根据结构gc_heap::settings与枚举gc_reason对照。

从上图上看，有GC处于2代回收，回收原因为4（大对象分配），从下图也统计也可看出，在有10个线程上存在大对象分配操作，导致GC触发。这也是导致CPU高的其中一个原因（后续分析）。

3、既然同步块表中无锁等待，使用!mlocks命令再次查看其它锁类型，如下：存在大量thinlock锁

统计存在1023个thinlock锁。
使用!gcroot随便抽一个查看lock对象引用根，如下图，基本上来自于System.Collections.Generic.Dictionary。

使用命令：~*e!dumpstack 查看所有线程栈，在栈上搜索该方法对象，存在23次调用，如下图：

在托管堆上搜索该对象统计，如下图：
使用命令：!dumpheap -live -min 8196 -type System.Collections.Generic.Dictionary

如上图可知，托管堆上有较多此类对象，还有较大的这类对象。

抽一个较大对象，查看其引用根，如下图：

由图可知，最终这类lock对象来自于System.Collections.Generic.Dictionary中的table操作，由json序列化引发。

使用命令!mdt展开查看table对象，如下，由图可知，这里存在1024个lock对象，以及3w+个元素。

其引用来自json序列化，与前面火焰图分析一致。

反编译如下：

如上图在json序列化中，用到的table确实被上锁。

在前面分析我们提到有GC进行回收操作，且为大对象分配，接下来分析下大对象操作。

1、使用命令!dumpheap -stat查看所有托管堆状态，如下图：

从此卦象来看，首榜为string对象。

2、再使用!dumpheap -live -min 8196 -mt 来查看String方法表中>8196的对象信息，.net将>8196的对象定义为大对象，如下图，还不少：

3、随便挑一个较大的使用!do来查看对象信息

从笔者选取的几个来看基本上是json字符串，几百KB到1MB+不等。

综合上述分析：

大量较大的String对象使用json对象进行序列化与反序列化操作，其中使用到System.Collections.Generic.Dictionary中的table操作，table操作中为线程安全考虑使用lock锁，String大对象序列化成json对象，遍历Dictionary中的talbe，大量锁遍历，从而引发大对象分配，GC回收，导致此次CPU爆高。
从案发至今，现场共发回给笔者3份dump，其分析结论均指向序列化与反序列化问题，以及大对象导致的GC回收问题。

反馈：
笔者将分析反馈研发后于2024.3.21优化后当日中午紧急升级；
下午接前方反馈经监控cpu已回落至30%左右；
3.22上午监控平均也在30%左右。

此次故障解决！对于在多线程下System.Collections.Generic.Dictionary这个在网上已有不少踩坑的网友们。

看雪ID：cmdxhz

https://bbs.kanxue.com/user-home-116953.htm

*本文为看雪论坛优秀文章，由 cmdxhz 原创，转载请注明来自看雪社区

# 

原文始发于微信公众号（看雪学苑）：一次.net cpu爆高分析-windbg sos基本命令使用及分析思路