前文： windbg调试一个CPU100%的.net进程
windbg调试一个CPU100%的.net进程（二）—— What is mscorlib.ni.dll

某日因一大波僵尸（韭菜）的大量访问，某服务发生服务不可用故障，同时CPU使用率触发报警。

调查结论是：导致CPU使用率高的原因是锁冲突，性能计数器显示每秒发生锁冲突超过800次。产生锁冲突的是Log4net的UdpAppender。该服务写ELK使用了UdpAppender和log4net.Ext.Json插件，log4net.Ext.Json插件内部使用了System.Web.Script.Serialization.JavaScriptSerializer，序列化性能差，对插件的使用错误产生严重的锁冲突。

通过windbg分析各线程用时可以确定一些问题线程。估计有问题的线程总计67个，占总线程127中52%。

选择17、27、29、28等这些问题线程查看堆栈，发现堆栈顶部都出现了服务内部记录ELK日志的代码。LogManager.LogManagerLib.WriteElkLog(System.String, System.String, log4net.Core.Level))

堆栈顶部同时包含一个Monitor.Enter的获取锁的调用。符合性能监视器发现的锁冲突情况。这样可以基本确认log4net内部锁导致这里的锁冲突。

查看log4net代码。

可以看到DoAppend方法内部有一个锁，之后调用Append方法，然后调用RenderLoggingEvent方法格式化输出日志。

此处RenderLoggingEvent使用的m_layout配置为log4net.Layout.SerializedLayout, log4net.Ext.Json。

于是在此判断log4net.Ext.Json插件序列化日志时用时过多，导致锁定较长，产生了频繁的锁冲突。

该dump文件中，获取了锁的线程在序列化结束后退出锁之前触发了垃圾回收，GG。

技不如人，甘拜下风。