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

Posted dotNET跨平台

tags:

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

一:背景

1. 讲故事

前几天有位朋友wx求助,它的程序CPU经常飙满,没找到原因,希望帮忙看一下。

这些天连续接到几个cpu爆高的dump,都看烦了????????????,希望后面再来几个其他方面的dump,从沟通上看,这位朋友表现的好惨,可能实际更惨,那既然找到我了,我就尽最大能力帮他找到幕后真凶,话不多说,上 windbg。

二:windbg 分析

1. 查看托管线程

因为线程都是靠cpu养着,所以从线程上入手也是一个很好的思路,要想查看程序的所有托管线程,可以使用 !t 命令。


0:000> !t
ThreadCount:      38
UnstartedThread:  0
BackgroundThread: 34
PendingThread:    0
DeadThread:       3
Hosted Runtime:   no
                                                                                                        Lock  
       ID OSID ThreadOBJ           State GC Mode     GC Alloc Context                  Domain           Count Apt Exception
   0    1 105c 000000000067f600    2a020 Preemptive  0000000000000000:0000000000000000 0000000000671ec0 0     MTA 
   2    2 13d0 00000000192c4f40    2b220 Preemptive  0000000000000000:0000000000000000 0000000000671ec0 0     MTA (Finalizer) 
...
XXXX   15    0 000000001bc64970  8039820 Preemptive  0000000000000000:0000000000000000 0000000000671ec0 0     MTA (Threadpool Completion Port) 
  24   23 1380 000000001bc660e0  8029220 Preemptive  0000000000000000:0000000000000000 0000000000671ec0 0     MTA (Threadpool Completion Port) 
XXXX   53    0 000000001bc63200  8039820 Preemptive  0000000000000000:0000000000000000 0000000000671ec0 0     MTA (Threadpool Completion Port) 
XXXX   27 10dc 000000001bd0dbf0  1029220 Preemptive  0000000002CB40F8:0000000002CB4108 0000000000671ec0 1     MTA (GC) (Threadpool Worker) 

在卦象上看:程序有38个线程,死了3个,我去,有一个亮点,最后一行出现了一个熟悉的 MTA (GC) 字样,这什么意思呢?这表示当前线程触发了GC,但奇怪的是,这个触发GC的线程死了,你肯定要问怎么看出来的,看行头的 XXXX,先不管了,死马当活马医,调出线程的所有托管和非托管栈,看看有没有 WaitUntilGCCompletetry_allocate_more_space 字样。

2. 查看线程栈

要想查看所有线程的线程栈,可以使用 ~*e !dumpstack 命令。

  • 搜索 WaitUntilGCComplete 关键字。

从图中看,嘿嘿,真的有18个线程在等待,而且还看到了 System.String.Concat ,是不是和我上上篇发的 his cpu爆高是一个套路?????????????

  • 搜索 try_allocate_more_space 关键字。

我去,竟然没有 try_allocate_more_space 关键词,这就和 his 不是一个套路了,???????????? 有可能这个dump踩的不是特别好的时机,有可能程序正处于某些怪异行为中。

看样子这段路走到头了,不过还是那句话,线程是靠cpu养着的,那就硬着头皮看看各个线程都在做什么吧,为了让结果更清晰一点,换一个命令 ~*e !clrstack

从图中可以看出当前有 25 个线程正卡在 FindEntry(System.__Canon) 处,而且从调用堆栈上看,貌似是 aliyun 封装的dll,为什么有这么多的线程卡在这里呢?这就给人一个很大的问号?接下来我就把阿里云的这段代码给导出来看看到底发生了什么。

3. 查看问题代码

要想导出问题代码,还是用经典的 !ip2md + !savemodule 组合命令。


0:000> !ip2md 000007fe9a1a0641
MethodDesc:   000007fe9a5678e0
Method Name:  Aliyun.Acs.Core.Utils.CacheTimeHelper.AddLastClearTimePerProduct(System.String, System.String, System.DateTime)
Class:        000007fe9a595a08
MethodTable:  000007fe9a567900
mdToken:      00000000060000a6
Module:       000007fe9a561f58
IsJitted:     yes
CodeAddr:     000007fe9a1a0610
Transparency: Critical
0:000> !savemodule 000007fe9a561f58 E:\\dumps\\AddLastClearTimePerProduct.dll
3 ps in file
p 0 - VA=2000, VASize=14148, FileAddr=200, FileSize=14200
p 1 - VA=18000, VASize=3fc, FileAddr=14400, FileSize=400
p 2 - VA=1a000, VASize=c, FileAddr=14800, FileSize=200

然后用 ILSpy 反编译一下这个dll,因为是阿里云的代码,我就可以放心大胆的放出来啦。


// Aliyun.Acs.Core.Utils.CacheTimeHelper
using System;
using System.Collections.Generic;

public class CacheTimeHelper
{
 private static Dictionary<string, DateTime> lastClearTimePerProduct = new Dictionary<string, DateTime>();

 private const int ENDPOINT_CACHE_TIME = 3600;

 public static bool CheckCacheIsExpire(string product, string regionId)
 {
  string key = product + "_" + regionId;
  DateTime dateTime;
  if (lastClearTimePerProduct.ContainsKey(key))
  {
   dateTime = lastClearTimePerProduct[key];
  }
  else
  {
   dateTime = DateTime.Now;
   lastClearTimePerProduct.Add(key, dateTime);
  }
  if (3600.0 < (DateTime.Now - dateTime).TotalSeconds)
  {
   return true;
  }
  return false;
 }

 public static void AddLastClearTimePerProduct(string product, string regionId, DateTime lastClearTime)
 {
  string key = product + "_" + regionId;
  if (lastClearTimePerProduct.ContainsKey(key))
  {
   lastClearTimePerProduct.Remove(key);
  }
  lastClearTimePerProduct.Add(key, lastClearTime);
 }
}


可以看出,上面这段代码在 if (lastClearTimePerProduct.ContainsKey(key)) 处走不下去了,如果往下追,可参考 Dictionary 的源码。


public class Dictionary<TKey, TValue> 
{
    // System.Collections.Generic.Dictionary<TKey,TValue>
    public bool ContainsKey(TKey key)
    {
        return FindEntry(key) >= 0;
    }
}

到这里,有没有看出这个 CacheTimeHelper 有什么问题吗?对,竟然在多线程环境下用的是非线程安全的 Dictionary<string, DateTime>,这就很有问题了。

4. 用 Dictionary 到底会有什么问题

在多线程环境下用 Dictionary 肯定会导致数据错乱,这个毫无疑问,而且还会遇到一些 迭代时异常,但如果说这个误用会导致 CPU 爆高,在我的视野范围内还没看到过。。。为了确保起见,到 bing 上搜搜这样的 天涯沦落人

嘿嘿,还真的有这样的案例:High CPU in .NET app using a static Generic.Dictionary (

https://www.tessferrandez.com/blog/2009/12/21/high-cpu-in-net-app-using-a-static-generic-dictionary.html

),再截个图。

从文章描述看,简直是一摸一样????????????,这也就断定在多线程环境下操作 Dictionary ,可能会导致 FindEntry(key) 时出现死循环,然后 25 个死循环一起把cpu抬起来了,补充一下当前爆满的CPU利用率。。。


0:000> !tp
CPU utilization: 100%
Worker Thread: Total: 27 Running: 27 Idle: 0 MaxLimit: 32767 MinLimit: 4
Work Request in Queue: 0
--------------------------------------
Number of Timers: 1
--------------------------------------
Completion Port Thread:Total: 4 Free: 3 MaxFree: 8 CurrentLimit: 3 MaxLimit: 1000 MinLimit: 4

三:总结

既然是阿里云的sdk出的bug,这问题就麻烦了。。。改也改不得,然后告诉朋友去提工单解决。

本以为事情就这样结束了,但我想一想,几年前用的阿里云其他 sdk 也遇到了类似CPU爆高的问题,后来通过升级sdk就搞定了,这次也赌赌看,先看一下程序集信息。


[assembly: CompilationRelaxations(8)]
[assembly: RuntimeCompatibility(WrapNonExceptionThrows = true)]
[assembly: Debuggable(DebuggableAttribute.DebuggingModes.IgnoreSymbolStoreSequencePoints)]
[assembly: TargetFramework(".NETStandard,Version=v2.0", FrameworkDisplayName = "")]
[assembly: AssemblyCompany("Alibaba Cloud")]
[assembly: AssemblyConfiguration("Release")]
[assembly: AssemblyCopyright("©2009-2018 Alibaba Cloud")]
[assembly: AssemblyDescription("Alibaba Cloud SDK for C#")]
[assembly: AssemblyFileVersion("1.1.12.0")]
[assembly: AssemblyInformationalVersion("1.1.12")]
[assembly: AssemblyProduct("aliyun-net-sdk-core")]
[assembly: AssemblyTitle("aliyun-net-sdk-core")]
[assembly: AssemblyVersion("1.1.12.0")]

可以看到朋友当前用的是 1.1.12.0 版本,那就把 aliyun-net-sdk-core 升级到最新再看看这个 CacheTimeHelper 有没有被修复 ?

果然不出所料,在新版本中给修复好了,所以经验告诉我,用阿里云的sdk,要记得经常升级,不然各种大坑等着你。。。????????????

END

工作中的你,是否已遇到 ... 

1. CPU爆高

2. 内存暴涨

3. 资源泄漏

4. 崩溃死锁

5. 程序呆滞

等紧急事件,全公司都指望着你能解决...  危难时刻才能展现你的技术价值,作为专注于.NET高级调试的技术博主,欢迎微信搜索: 一线码农聊技术,免费协助你分析Dump文件,希望我能将你的踩坑经验分享给更多的人。

以上是关于记一次 .NET 车联网云端服务 CPU爆高分析的主要内容,如果未能解决你的问题,请参考以下文章

记一次 .NET 某智能交通后台服务 CPU爆高分析

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

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

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

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

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