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

这篇具有很好参考价值的文章主要介绍了记一次 .NET 某汽贸店 CPU 爆高分析。希望对大家有所帮助。如果存在错误或未考虑完全的地方,请大家不吝赐教,您也可以点击"举报违法"按钮提交疑问。

一:背景

1. 讲故事

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

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

时隔两年 终于有人在上面提 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 的过程中被锁等待。

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

接下来检索下 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 现象,治标治本的方案也说了,希望给后来人少踩一些坑吧。文章来源地址https://www.toymoban.com/news/detail-454747.html

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

到了这里,关于记一次 .NET 某汽贸店 CPU 爆高分析的文章就介绍完了。如果您还想了解更多内容,请在右上角搜索TOY模板网以前的文章或继续浏览下面的相关文章,希望大家以后多多支持TOY模板网!

原文地址:https://www.cnblogs.com/huangxincheng/p/17420753.html

本文来自互联网用户投稿,该文观点仅代表作者本人,不代表本站立场。本站仅提供信息存储空间服务,不拥有所有权,不承担相关法律责任。如若转载,请注明出处: 如若内容造成侵权/违法违规/事实不符,请点击违法举报进行投诉反馈,一经查实,立即删除!

领支付宝红包 赞助服务器费用

相关文章

  • 记一次 某智能制造MES系统CPU 爆高分析

    前段时间有位朋友找到我,说他 docker 中的web服务深夜cpu被打满,让我帮忙看一下,很多朋友问docker中怎么抓dump,我一般都推荐使用 procdump 这款自动化工具,谁用谁知道,有了 dump 之后,接下来就是分析了。 有很多朋友问 linux 上的dump可以用 windbg 分析吗?这里统一回复下,

    2024年02月04日
    浏览(14)
  • 记一次 .NET 某工厂无人车调度系统 线程爆高分析

    前些天有位朋友找到我,说他程序中的线程数爆高,让我帮忙看下怎么回事,这种线程数爆高的情况找问题相对比较容易,就让朋友丢一个dump给我,看看便知。 别人说的话不一定是真,得自己拿数据出来说话,可以用 !t 命令观察一下便知。 从卦中信息看确实有 4600+ 的线程

    2024年02月06日
    浏览(16)
  • 记一次javaMetaspace导致CPU200%的排查

    insertMotionDataByWxCallBack方法并发多(其实也没多少,可能就3个?)就导致CPU200%了,本地没法复现。 看报错是:java.lang.OutOfMemoryError: Metaspace,刚开始的时候眼挫,忽略了后面的Metaspace,只看到了OutOfMemoryError,就各种找代码问题。 https://arthas.aliyun.com/doc/install-detail.html 然后发现

    2023年04月24日
    浏览(14)
  • 【记一次线上事故的排查思路】- CPU飙升问题排查

    由于项目排期较紧,临时从其他组调来三个开发资源帮我一起做项目,难免上线的时候大家的需求一块上线。 问题来了,上线三天后,线上CPU总是莫名奇妙的突然飙升,飙升后CPU并未降下来,而是一直处在高点。 由于是线上导致的问题,CPU超限后,会自动重启项目,未能保

    2024年01月23日
    浏览(14)
  • 记一次 .NET 某企业内部系统 崩溃分析

    前些天有位朋友找到我,说他的程序跑着跑着就崩溃了,让我看下怎么回事,其实没怎么回事,抓它的 crash dump 就好,具体怎么抓也是被问到的一个高频问题,这里再补一下链接: [.NET程序崩溃了怎么抓 Dump ? 我总结了三种方案] https://www.cnblogs.com/huangxincheng/p/14811953.html ,采用

    2024年02月10日
    浏览(15)
  • 记一次 .NET 某企业采购平台 崩溃分析

    前段时间有个朋友找到我,说他们的程序有偶发崩溃的情况,让我帮忙看下怎么回事,针对这种 crash 的程序,用 AEDebug 的方式抓取一个便知,有了 dump 之后接下来就可以分析了。 既然是程序的崩溃,我们可以像看蓝屏一下看dump文件,使用 !analyze -v 命令即可。 从上面的信息

    2024年02月11日
    浏览(10)
  • 记一次 .NET某防伪验证系统 崩溃分析

    昨晚给训练营里面的一位朋友分析了一个程序崩溃的故障,因为看小伙子昨天在群里问了一天也没搞定,干脆自己亲自上阵吧,抓取的dump也是我极力推荐的用 procdump 注册 AEDebug 的方式,省去了很多沟通成本。 windbg有一个非常强大的点就是当你双击打开后,会自动帮你切换到

    2024年03月28日
    浏览(14)
  • 记一次 .NET 某餐饮小程序 内存暴涨分析

    前些天有位朋友找到我,说他的程序内存异常高,用 vs诊断工具 加载时间又太久,让我帮忙看一下到底咋回事,截图如下: 确实,如果dump文件超过 10G 之后,市面上那些可视化工具分析起来会让你崩溃的,除了时间久之外这些工具大多也不是用懒加载的方式,比如 dotmemory

    2024年02月08日
    浏览(11)
  • 记一次 .NET某账本软件 非托管泄露分析

    中秋国庆长假结束,哈哈,在老家拍了很多的短视频,有兴趣的可以上B站观看:https://space.bilibili.com/409524162 ,今天继续给大家分享各种奇奇怪怪的.NET生产事故,希望能帮助大家在未来的编程之路上少踩坑。 话不多说,这篇看一个 .NET程序集泄露 导致的CLR私有堆泄露的案例,

    2024年02月08日
    浏览(7)
  • 记一次 .NET某报关系统 非托管泄露分析

    前段时间有位朋友找到我,说他的程序内存会出现暴涨,让我看下是怎么事情?而且还告诉我是在 Linux 环境下,说实话在Linux上分析.NET程序难度会很大,难度大的原因在于Linux上的各种开源工具主要是针对 C/C++, 和 .NET 一毛钱关系都没有,说到底微软在 Linux 上的调试领域支持

    2024年02月14日
    浏览(9)

觉得文章有用就打赏一下文章作者

支付宝扫一扫打赏

博客赞助

微信扫一扫打赏

请作者喝杯咖啡吧~博客赞助

支付宝扫一扫领取红包,优惠每天领

二维码1

领取红包

二维码2

领红包