星空科学探索频道: 记一次 .NET 某旅行社Web站 CPU爆高分析

2021年5月17日星期一

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

一：背景

1. 讲故事

前几天有位朋友wx求助，它的程序内存经常飙升，cpu 偶尔飙升，没找到原因，希望帮忙看一下。

可惜发过来的 dump 只有区区2G，能在这里面找到内存泄漏那真有两把刷子。。。😂😂😂，所以我还是希望他的程序内存涨到 5G+ 的时候再给我看看，既然内存看不了，那就看看这个偶尔飙升的CPU是个啥情况？老办法，上windbg说话。

二： windbg 分析

1. CPU 到底是多少

要想查看这个快照生成时机器的cpu使用率，可以使用 !tp 命令。

0:033> !tpCPU utilization: 93%Worker Thread: Total: 800 Running: 800 Idle: 0 MaxLimit: 800 MinLimit: 320Work Request in Queue: 3203 Unknown Function: 000007fefb551500 Context: 000000002a198480 Unknown Function: 000007fefb551500 Context: 0000000028a70780 Unknown Function: 000007fefb551500 Context: 000000002a182610 Unknown Function: 000007fefb551500 Context: 00000000262a2700 ...

本以为一个简单的命令，结果屏幕上呼啦啦的一堆。。。有点意外，从上面的卦象看：当前CPU利用率是 93%，没毛病，确实是CPU飙升，比较惊讶的是，线程池上限800个线程全部被打满，太悲壮了。。。可更悲壮的是线程池队列中还有 3203 个待处理的任务，可以猜测程序不仅高CPU，还有挂死现象。。。

接下来的问题是：这800个壮士到底怎么啦，程序现在正是用人之际，要想找出答案，还是按照我的惯性思维，查看同步块表。

2. 线程同步块表

要想查看同步块表，可以使用 !synblk 命令。

0:033> !syncblkIndex SyncBlock MonitorHeld Recursion Owning Thread Info SyncBlock Owner 188 0000000010defc28   1   1 000000001e8fb400 9f4 715 00000003ff1e3d80 System.Web.HttpApplicationStateLock126159 000000001e424e28   1   1 0000000023425e00 1f14 695 0000000301210038 ASP.global_asax126173 00000000281acaf8   1   1 0000000024b8ea70 24ec 785 00000000ff8c5e10 ASP.global_asax126289 00000000247a4068   1   1 0000000027ee93c0 808 413 0000000306aca288 ASP.global_asax126368 0000000027180dd8   1   1 0000000028005cb0 1e7c 650 00000002008d6280 ASP.global_asax126489 0000000027211dd8   1   1 0000000026862420 ec4 220 000000030611a290 ASP.global_asax126788 00000000247924b8   1   1 0000000021871ff0 2784 529 00000004039901a8 ASP.global_asax126843 00000000285b8d28   1   1 000000001cbd6710 2170 456 00000004007ec748 ASP.global_asax126934 0000000021b212b8   1   1 0000000026ca7590 16cc 472 000000030090e810 ASP.global_asax127251 0000000024769188   1   1 000000002831eaf0 2b68 648 0000000207051038 ASP.global_asax...-----------------------------Total   141781CCW    2RCW    4ComClassFactory 0Free   140270

我去，又是呼啦啦的一堆，从上面的卦象可以看出两点信息：

MonitorHeld: 1

表示当前有一个线程正在持有锁。

ASP.global_asax , System.Web.HttpApplicationStateLock

表示当前线程持有的对象。

不过综合来看有点奇怪，除了第一个线程持有 HttpApplicationStateLock，后面所有的线程持有的 ASP.global_asax 对象都有不同的内存地址:0000000301210038,00000000ff8c5e10，感觉lock的对象不是线程共享式的 static，更像是一个 instance，蛮有意思的，接下来抽两个线程看看它的线程栈，比如这里的：715,695。

3. 查看线程栈

要想查看线程栈，可以用 !clrstack 命令。

从这两个线程栈上看，分别是卡在 xxx.MvcApplication.Session_Start 方法中的 System.Threading.Monitor.Enter(System.Object) 和 System.Threading.Monitor.ObjWait ，总的来说这里的 Session_Start 方法肯定是有问题的，所以得想办法把源码导出来看一看。

4. 查看问题代码

要想导出 Session_Start 方法，使用组合命令 !ip2md + !savemodule 即可。

||2:2:1781> !ip2md 000007fe99c6f0c5MethodDesc: 000007fe990fe080Method Name: xxx.xxx.xxx.MvcApplication.Session_Start(System.Object, System.EventArgs)Class:  000007fe991ae0c0MethodTable: 000007fe990fe238mdToken:  0000000006000119Module:  000007fe990fd750IsJitted:  yesCodeAddr:  000007fe99c6e1f0Transparency: Critical||2:2:1781> !savemodule 000007fe990fd750 E:\dumps\Session_Start.dll3 sections in filesection 0 - VA=2000, VASize=17538, FileAddr=200, FileSize=17600section 1 - VA=1a000, VASize=3ac, FileAddr=17800, FileSize=400section 2 - VA=1c000, VASize=c, FileAddr=17c00, FileSize=200

然后借助 ILSpy 反编译工具查看，由于比较敏感，我就多模糊一点，请大家见谅！

看完上面的代码，我其实有一点不解，既然是往 Application 中赋值，为啥不提取到 Application_Start 中呢？我猜测开发人员也是无所谓，怎么方便怎么来，接下来看一下 Application 的源码。

public sealed class HttpApplicationState : NameObjectCollectionBase{ private HttpApplicationStateLock _lock = new HttpApplicationStateLock(); public void Set(string name, object value) {  _lock.AcquireWrite();  try  {   BaseSet(name, value);  }  finally  {   _lock.ReleaseWrite();  } }}internal class HttpApplicationStateLock : ReadWriteObjectLock{ internal override void AcquireWrite() {  int currentThreadId = SafeNativeMethods.GetCurrentThreadId();  if (_threadId == currentThreadId)  {   _recursionCount++;   return;  }  base.AcquireWrite();  _threadId = currentThreadId;  _recursionCount = 1; } internal override void ReleaseWrite() {  int currentThreadId = SafeNativeMethods.GetCurrentThreadId();  if (_threadId == currentThreadId && --_recursionCount == 0)  {   _threadId = 0;   base.ReleaseWrite();  } }}internal class ReadWriteObjectLock{ internal virtual void AcquireWrite() {  lock (this)  {   while (_lock != 0)   {    try    {     Monitor.Wait(this);    }    catch (ThreadInterruptedException)    {    }   }   _lock = -1;  } } internal virtual void ReleaseWrite() {  lock (this)  {   _lock = 0;   Monitor.PulseAll(this);  } }}

代码有点长，但总的来说这里的代码不简单，Application 通过 lock 自己封装了一个 读写锁，不简单归不简单，但这里有什么问题呢 ? 就算写错了地方貌似也不会造成 cpu 爆高吧？

其实这里涉及到了一个概念：那就是 lock convoys （锁护送）

5. lock convoys （锁护送）

关于什么是 lock convoys ，我找了一篇解释很好的文章: 锁护送，这里我截一张图，大家仔细品品。

这也是 无锁编程 一直在抨击的现象。

三：总结

我看了下这个 Session_Start 方法中，大概有 105 个 Application[xxx]，也就意味着有 105 个 lock 等着当前线程去闯关。。。而此时有近800个线程已进入到此方法中，合计一下不少于 8W个锁等着这些线程去闯，在配上被迫的海量cpu时间片切换，唤醒再休眠，休眠再唤醒，大家相互交错一起把 cpu 给抬起来了。

解决方法很简单，尽最大努力降低这些 串行lock 的个数，能降到一个甚至没有就更好了 😄😄😄。

对 Application 的赋值全部提取到 Application_Start 中，毕竟程序启用时无人竞争。
尽量将 单行赋值 改成 批量赋值。

更多高质量干货：参见我的 GitHub: dotnetfly

原文转载：http://www.shaoqun.com/a/747786.html

跨境电商：https://www.ikjzd.com/

dhl：https://www.ikjzd.com/w/516

yiqu：https://www.ikjzd.com/w/210

一：背景1.讲故事前几天有位朋友wx求助，它的程序内存经常飙升，cpu偶尔飙升，没找到原因，希望帮忙看一下。可惜发过来的dump只有区区2G，能在这里面找到内存泄漏那真有两把刷子。。。😂😂😂，所以我还是希望他的程序内存涨到5G+的时候再给我看看，既然内存看不了，那就看看这个偶尔飙升的CPU是个啥情况？老办法，上windbg说话。二：windbg分析1.CPU到底是多少要想查看这个快照生成时机
铭宣海淘：https://www.ikjzd.com/w/1551
雨果网：https://www.ikjzd.com/w/1307
鸥鹭：https://www.ikjzd.com/w/2568
亚马逊，是江湖也请多一点人情味吧！：https://www.ikjzd.com/home/100807
最近CPC效果是有多差，看这十招能不能帮上你！：https://www.ikjzd.com/tl/8379
有流量就躺赚不会运营就陪跑独立站一件代发还能做吗？：https://www.ikjzd.com/home/132891

星空科学探索频道