捉虫笔记（六）-谁把系统卡住了？

06-谁把系统卡住了？

1、现象

QA反馈，在软件退出的时候，会把整个系统卡住，将近40s。我第一反应这么离谱，我们的软件有这么大的“魅力”，将老大哥抖三抖。

我立马重现现场，果然如此。虽然没有QA卡住40s这么高，但是确实整个系统卡住了有4s。

2、分析过程

我在想软件在退出的时候，做了什么操作将系统的资源消耗殆尽，导致整个系统高热。

所谓的系统资源，无非这几种：cpu，memory，disk。

我手上没有源码，但是我有pdb文件，所以跑个profiler，抓住罪魁祸首不是难事。

2.1、CPU利用率分析

打开windows自带的profiler WPR(Windows Performance recorder)，先将操作重新来一遍，录制数据，再利用WPA(Windows Performance Analyzer)进行性能分析。

接下来再看看进程此时的利用率，图中颜色较深的部分就是当前选中的进程，可以看出此时的CPU并不高，至少没有看到尖峰时刻。
在这里插入图片描述

在分析CPU利用的时候发现一个特列现象，请看这张图，在下面的这张图中RoboCopy的CPU利用率很高，导致我开心了几分钟，以为是找到了凶手。

但是当我采集几分数据并同时在QA系统采集了一次数据，对照发现这是个例现象，并不是真正的原因。
在这里插入图片描述

我在CPU这里辗转几个小时后，没有发现任何可疑之处。目标开始转向memory利用率。

2.2、memory使用率

从图中可以看出，整个系统的memory已经接近64G极限。

可以简单看出有可能是memory到了极限导致的。

但是仔细分析发现证据不是那么的有力。

第一个红色框中是进程存活期间cpu利用率，第二个是存活期间的memory。

我们看在红色框中的就是当时进程从开始到退出的内存数据。在进程还未起来之前整个系统的内存也已经捉襟见肘了，虽然在退出的时候有个波动（下面红色的2中），但是我觉得这个波动引起系统卡顿4s以上很牵强，没有说服力，而且这个波动持续时间见远远小于4s。
在这里插入图片描述

2.3、disk利用率

接下来看下disk的利用率，因为我知道的进程是2号disk上。所以只看2号disk的信息，发现这个利用率也很低。转了很久也未发现不对劲的地方。
在这里插入图片描述

接连几个的小时分析，都没有头绪，但是我知道肯定有蛛丝马迹我没有注意到。

2.4、再分析CPU利用率

我在想导致系统卡顿，肯定是资源出现了问题。

选中profiler中CPU选项卡中的一栏，按照cpu利用率分类显示。

我的系统是16个核，暂时的数据如此，但是这乱糟糟的没法看。其实我最想看的就是整个系统的CPU利用率是多少。

因为我猜测虽然退出的进程利用率不高，但是它可能是压死骆驼的最后一根稻草。
在这里插入图片描述

既然这个软件不能看到总体的CPU利用率，有个工具可以sysinternals process explorer 。

在红色框中可以看到CPU总体利用率。
在这里插入图片描述

我重新走了一遍流程，却发现一个很重要的线索。CPU的总体利用率并没有尖峰，但是我却意外的瞥见一个意外的进程WerFault.exe。

2.5、进程异常

熟悉windows系统都知道，在软件出错的时候往往会出现一个WerFault.exe进程报告错误的信息。类似下面的画面。
在这里插入图片描述

我的注意力立马被它吸引住了。难道是它让系统卡住了？

我接着对它进行了cpu，memory，disk进行了分析，也未发现有价值的信息。

但是我又多了个疑问，这个进程持续了几秒钟就退出了。为什么没有弹出UI。

我把Windbg拉起来，挂上去看看到底是哪里错误了。

拿出我写的小软件，启动进程自动挂载上去。
在这里插入图片描述

在软件退出的时确实有异常，但是从堆栈来看只知道和D3D有关。

 # Child-SP          RetAddr               Call Site
00 0000002d`ea5ff5a0 00007ffd`3529c1ef     software!software::D3D11Device<1,1>::Buffer
...
13 000000d1`f3fffa50 00007ffe`1771cc91     KERNEL32!BaseThreadInitThunk+0x14
14 000000d1`f3fffa80 00000000`00000000     ntdll!RtlUserThreadStart+0x21