记一次 .NET 某汽贸店 CPU 爆高分析

Posted

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了记一次 .NET 某汽贸店 CPU 爆高分析相关的知识,希望对你有一定的参考价值。

一:背景

1. 讲故事

上周有位朋友在 github 上向我求助,说线程都被卡住了,让我帮忙看下,截图如下:

时隔两年 终于有人在上面提 Issue 了,看样子这块以后可以作为求助专区来使用,既然来求助,必须得免费帮忙解决,从朋友这边拿到 dump 之后,接下来就可以分析了。

二:WinDbg 分析

1. 为什么有大量线程卡住

在朋友的文案描述中可以看到有一段 !syncblk 输出,格式有点乱,再用这个命令跑一下看看。


0:000> !syncblk
Index SyncBlock MonitorHeld Recursion Owning Thread Info  SyncBlock Owner
49755 0000000013b666b8          602         0 0000000000000000     none    00000001bfc5f0b0 System.ComponentModel.PropertyDescriptorCollection
-----------------------------
Total           207053
CCW             22
RCW             4
ComClassFactory 0
Free            0

从卦中看,貌似不是一个 dump,不过都有如下几个疑点。

1) MonitorHeld 为什么是偶数?

熟悉同步块表的朋友都知道,持有+1,等待+2,而这个居然是一个偶数,也就表明那个 +1 的线程已经退出了临界区,同时等待线程此时还没有进来,正处在这么一个时间差内。

2) 持有线程信息 为什么不显示?

正因为持有线程已经退出临界区,所以看不到持有线程信息,往细处说就是 AwareLock 类下的 m_HoldingThread 字段被抹掉了,同时用 AwareLock::LockState::InterlockedUnlock 函数解锁了 LockState 中的掩码,前者在 0000000013b666b8+0x8 的位置,后者在 0000000013b666b8+0x4 的位置。


0:000> dp 0000000013b666b8
00000000`13b666b8  00000000`0000025a 00000000`00000000

以多年的治疗经验来看,这是经典的 lock convoy 现象,这个病还会因为高频的上下文切换导致 cpu 爆高。

2. CPU真的爆高吗?

要验证 cpu 是否爆高,可以用 !tp 命令验证。


0:000> !tp
CPU utilization: 100%
Worker Thread: Total: 336 Running: 336 Idle: 0 MaxLimit: 32767 MinLimit: 16
Work Request in Queue: 915
    Unknown Function: 000007fef97715cc  Context: 0000000026d95968
    Unknown Function: 000007fef97715cc  Context: 0000000026d98b78
    Unknown Function: 000007fef97715cc  Context: 0000000026d9bd88
    ...
    Unknown Function: 000007fef97715cc  Context: 000000002aab0368
    Unknown Function: 000007fef97715cc  Context: 000000001d62ed00
--------------------------------------
Number of Timers: 0
--------------------------------------
Completion Port Thread:Total: 1 Free: 1 MaxFree: 32 CurrentLimit: 1 MaxLimit: 1000 MinLimit: 16

从卦中看,果然是 cpu 爆高,而且还堆积了 915 个待处理的任务,既然有堆积,那就说明下游处理不及,接下来用 ~*e !clrstack 观察下所有的线程,整理后如下:


0:000> ~*e !clrstack

OS Thread Id: 0x4228 (404)
        Child SP               IP Call Site
000000002417b8d8 00000000771b9e3a [HelperMethodFrame: 000000002417b8d8] System.Threading.Monitor.Enter(System.Object)
000000002417b9d0 000007fe9a6c2bd9 System.ComponentModel.PropertyDescriptorCollection.Find(System.String, Boolean)
000000002417ba40 000007fe9a6c26fc System.Data.XSDSchema.SetProperties(System.Object, System.Xml.XmlAttribute[])
000000002417bab0 000007fe9a6c7b0f System.Data.XSDSchema.HandleElementColumn(System.Xml.Schema.XmlSchemaElement, System.Data.DataTable, Boolean)
000000002417bba0 000007fe9a6c71fa System.Data.XSDSchema.HandleParticle(System.Xml.Schema.XmlSchemaParticle, System.Data.DataTable, System.Collections.ArrayList, Boolean)
000000002417bc70 000007fe9a6c6bf5 System.Data.XSDSchema.HandleComplexType(System.Xml.Schema.XmlSchemaComplexType, System.Data.DataTable, System.Collections.ArrayList, Boolean)
000000002417bcf0 000007fe9a6c3edf System.Data.XSDSchema.InstantiateTable(System.Xml.Schema.XmlSchemaElement, System.Xml.Schema.XmlSchemaComplexType, Boolean)
000000002417bde0 000007fe9a6c383a System.Data.XSDSchema.HandleTable(System.Xml.Schema.XmlSchemaElement)
000000002417be60 000007fe9a6bf0d8 System.Data.XSDSchema.LoadSchema(System.Xml.Schema.XmlSchemaSet, System.Data.DataSet)
000000002417bee0 000007fe9a698c25 System.Data.DataSet.ReadXmlSchema(System.Xml.XmlReader, Boolean)
000000002417bf80 000007fe9a915b45 System.Data.DataTable.DeserializeDataTable(System.Runtime.Serialization.SerializationInfo, System.Runtime.Serialization.StreamingContext, Boolean, System.Data.SerializationFormat)
000000002417bfe0 000007fe9a915981 System.Data.DataTable..ctor(System.Runtime.Serialization.SerializationInfo, System.Runtime.Serialization.StreamingContext)
...
000000002417ce40 000007fe9a781af3 xxx.Cache.Utils.MemcachedProvider.GetDataTable(System.String)
...
000000002417d5a0 000007fe9a7743a9 System.Web.Mvc.ControllerActionInvoker.InvokeAction(System.Web.Mvc.ControllerContext, System.String)
000000002417d600 000007fe9a773110 System.Web.Mvc.Controller.ExecuteCore()
...
000000002417e380 000007fe9a8d5aae DomainNeutralILStubClass.IL_STUB_PInvoke(IntPtr, System.Web.RequestNotificationStatus ByRef)
000000002417e440 000007fe9a8c0231 System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr, IntPtr, IntPtr, Int32)
000000002417e5f0 000007fe9a8bf854 System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr, IntPtr, IntPtr, Int32)

从卦中信息看,当时有一个 http 请求,然后在 MemCached 中获取一条数据再将获取到的数据转成 DataTable 的过程中被锁等待。

接下来检索下 GetDataTable 方法高达 336 处,也就表示当前有 336 个线程在抢这个锁,高频的进入和退出导致的 CPU 爆高。

3. 问题代码在哪里

仔细观察代码会发现将 Byte[] 转成 DataTable 内部的逻辑不简单,会大量使用反射,然后在反射中又会大量的使用锁,接下来仔细观察调用栈,最终定位到了上层 GetxxxSite() 函数调用,简化后的代码如下:


public static DataTable GetxxxSite()

    string text = HttpContext.Current.Request.Url.ToStr();
    string xxxDomain = GetxxxDomain();

    DataTable dataTable = CacheHelper.GetDataTable("xxxSite_" + xxxDomain, -1, 0);

    if (dataTable.HasRecord())
    
        return dataTable;
    

    dataTable = GetxxxSiteInfo(xxxDomain);

    if (dataTable.HasRecord())
    
        _xxxSite = dataTable;
        CacheHelper.AddCache("xxxSite_" + xxxDomain, dataTable, -1, 0);
    
    return dataTable;


有朋友可能有疑问,这代码怎么可能会出现 lock convoy 呢? 你可以这么想一想,本来 CacheHelper.GetDataTable 函数只需 10ms 就能执行完,但需要执行 100 次 lock,然而在这 10ms 之内,又来了一个请求,也需要 100 次 lock,因为反序列成 DataTable 底层是共享的 lock,导致上一次 100 的lock 和这次 100 的 lock 要进行锁竞争,导致大家的执行时间由 10ms 延长到了 15ms。

可气的是,这 15ms 之间又来了100个线程,导致 100*100 =10000 个锁竞争,执行时间由原来的 15ms 延长到了 1min,以此类推,最终导致本该 10ms 执行的函数,结果要几分钟才能执行完。

知道了原理之后,缓解措施就简单了。

  1. 在 CacheHelper.GetDataTable 加串行锁

这个只能治标,也是最简单的方式,可以将原来的 平方锁 降成 线性锁,来缓解锁竞争,CPU爆高的问题也就迎刃而解。

  1. 不要转成 DataTable

本质的问题是转成 DataTable 的过程中有大量的锁,如果直接转成 List 自然就绕过去了,在现代编程中也是极力推荐的。

三:总结

这次 CPU 爆高事故,主要就是将 byte[] 转成 DataTable 的过程中出现的 lock convoy 现象,治标治本的方案也说了,希望给后来人少踩一些坑吧。

记一次 .NET 某医院HIS系统 CPU爆高分析

一:背景

1. 讲故事

前几天有位朋友加 wx 抱怨他的程序在高峰期总是莫名其妙的cpu爆高,求助如何分析?



和这位朋友沟通下来,据说这问题困扰了他们几年

以上是关于记一次 .NET 某汽贸店 CPU 爆高分析的主要内容,如果未能解决你的问题,请参考以下文章

记一次 .NET 车联网云端服务 CPU爆高分析

记一次 .NET 某智慧物流 WCS系统 CPU 爆高分析

记一次 .NET 某医院HIS系统 CPU爆高分析

记一次 .NET 某市附属医院 Web程序 偶发性CPU爆高分析

记一次 .NET 某旅行社Web站 CPU爆高分析

记一次 .NET 某电子病历 CPU 爆高分析