Windbg线上问题分析：生产环境应用高CPU问题分析

目录

一、Windbg用途

二、Windbg安装配置

1. 下载链接

 2.安装及配置

三、Windbg基础知识及概念

1.调试符

 2.SOS调试扩展

3.Windbg常用命令

四、实战1：线上环境Cpu 90%问题分析

1.线上问题现象：

 2.问题分析

3.Windbg分析Windows Cpu超过90%阈值

---

一、Windbg用途

Windows Debugger，简称WinDbg 。

Windows平台下，强大的用户态和内核态调试工具。相比较于Visual Studio，它是一个轻量级的调试工具，所谓轻量级指的是它的安装文件大小较小，但是其调试功能，却比VS更为强大。

用途：

我们可以通过WinDbg调试以下具体问题：

        …

二、Windbg安装配置

1. 下载链接

https://raw.githubusercontent.com/EasyDarwin/Tools/master/Windbg_x86_x64/dbg_amd64.msi

备注：windbg有64位和32位之分，该链接为64位安装包。我们各个环境均为64位，因此推荐大家安装64位运行程序

 2.安装及配置

下载完毕安装包后，一直点击下一步，直至安装完毕即可。

安装完毕后，启动Windbg。

点击左上角的菜单：File--》Symbol File Path，

在弹出的输入框内输入如下文本，用于配置调试符号路径：
SRV*C:\Debug_Symbol\Symbols32* http://msdl.microsoft.com/download/symbols

三、Windbg基础知识及概念

1.调试符

我们都知道，程序根据配置不同，可以build成release和debug两个版本。一般发布出去的是release版本，相比debug版本，release版本文件小，执行快，但相对的，其携带的信息也更少。所以开发人员在遇见问题时，都会build一个debug版本去重现场景，然后通过调试器去发现root cause，进而解决问题，而其原因就是debug版本，连接器在生成*.exe和*.dll时，还会生成带有关于程序详细符号信息pdb文件(Program Debug Database)。

符号表包含很多用于debug的内容，包括详细的类型信息，函数信息(函数名称以及入口地址)，源代码行数，堆栈大小，优化信息，堆栈的信息......

符号概述（微软官方）：符号文件 - Azure Artifacts | Microsoft Learn

为什么调试时我们需要符号表？

 2.SOS调试扩展

SOS 调试扩展 (SOS.dll) 通过提供有关内部公共语言运行时 (CLR) 环境的信息，帮助你在 Windows 调试器 (WinDbg.exe) 中调试托管程序

SOS.dll 自动随 .NET Framework 一起安装。

SOS 调试扩展允许你查看有关在 CLR 内运行的代码的信息。 例如，可以使用 SOS 调试扩展显示有关托管堆的信息、查找堆损坏情况、显示运行时所使用的内部数据类型以及查看有关在运行时内运行的所有托管代码的信息。

备注：我们日常使用windbg最多的方式是分析线上生产环境dump文件。如果要使用其他计算机（服务器）上创建的转储文件，需要加载相应的SOS.DLL版本例如出行服务器001上生成的dump文件，需要使用该服务器上的sos.dll

官方文档： SOS.dll（SOS 调试扩展） - .NET Framework | Microsoft Learn

3.Windbg常用命令

动手不如动嘴，小伙伴们，让我们行动起来吧。

.loadby sos clr                                  加载Clr，用于windbg分析

.load C:\Users\SOS.dll                     自定义路径加载sos方式

.unload C:\Users\SOS.dll                 卸载sos文件，为了加载对应dump的sos做准备

.chain                                               查看sos加载路径

lm                                                     显示进程中加载的代码模块列表

lmf                                                    列出已加载的模块及完整路径

lmt                                                    列出已加载的模块和最后修改的时间戳

 !runaway                                         显示每个线程占用的时间

!threads                                            查看所有托管线程

!threadpool                                       线程信息，用于查找哪些线程吃cpu高等

!dumpheap                                       查看堆对象使用（遍历所有的堆对象，耗时较长）

!dumpheap –min size                      查看堆内存使用，忽略小于size字节大小的对象

!dumpheap –type type                    查看所有类型为type的对象的内存使用

!dso                                                 查看当前堆栈的对象

!syncblk                                           查看托管的锁（syncblk结构）

四、实战1：线上环境Cpu 90%问题分析

1.线上问题现象：

2021-11-07发生生产环境严重预警，预警信息：Windows CPU使用率超过阈值90%。

 通过Grafana Cpu监控面板发现cpu稳步上升

 监控Host线程数以及TPM，发现线程数以及TPM均不高

 

 2.问题分析

 CPU升高的原因有很多，我们经常会遇到的有以下情况

a)应用的负载高，CPU受业务请求的增加和增高

b)GC回收使用了过高的CPU资源

c)某个线程执行的代码在某种情况下陷入了死循环

d)锁争用太激烈，某资源上的锁释放后，等待的线程去抢锁引起的

e)线程太多，上下文切换太频繁引起的

..........

通过Grafana监控，我们首先排除a)、e)两种情况，剩下b)、c)、d)这三种情况，我们怎么去排除以及定位具体原因呢？

上面说了这么多Windbg，是时候派上用场了。

3.Windbg分析Windows Cpu超过90%阈值

一切的前提：生产环境抓取Dump文件。

创建dump文件方式：任务管理器->选中进程，右键->创建转储文件

a)打开我们的分析利器：Windbg

File->Open Crash Dump

 b）加载sos文件

执行如下命令：.loadby sos clr

c)查看线程总数

执行如下命令：

 !threadpool 

返回结果如下：

CPU utilization: 100%

Worker Thread: Total: 29 Running: 4 Idle: 25 MaxLimit: 32767 MinLimit: 4

Work Request in Queue: 0

--------------------------------------

Number of Timers: 1

--------------------------------------

Completion Port Thread:Total: 2 Free: 2 MaxFree: 8 CurrentLimit: 2 MaxLimit: 1000 MinLimit: 4

发现线程数并不高，也验证了Grafana监控面板中数据的正确性。

d)查看是否存在死锁问题

执行如下命令：

 !syncblk

返回结果如下：

Index SyncBlock MonitorHeld Recursion Owning Thread Info  SyncBlock Owner

-----------------------------

Total           3380

CCW             1

RCW             1

ComClassFactory 0

Free            3185

备注：

SyncBlock 结构是一个容器，用于存放无需为每个对象创建的额外信息。 它可以存放 COM 互操作数据、哈希代码和用于线程安全操作的锁定信息

通过返回结果，我们得知无死锁现象存在，因此排除锁争用太激烈这种情况。

e)查看所有托管线程

执行命令：!runaway

返回结果如下：

 User Mode Time

  Thread       Time

   45:ec4      1 days 16:10:37.656

   46:37dc     0 days 18:35:29.828

   47:c7c      0 days 1:51:16.390

   52:678c     0 days 0:19:05.046

    3:2d60     0 days 0:12:56.609

    2:3058     0 days 0:12:41.906

    5:2ce8     0 days 0:12:15.703

    4:34a8     0 days 0:11:41.812

观察返回结果，发现45、46、47号线程占用Cpu时间最长。

为什么这三个线程会占用这么久的CPU时间呢？

下面我们去这三个线程的内部，具体看看发生了什么。

f)查看45号线程堆栈

执行如下命令：

~45s

!clrstack

命令输入及返回结果如下图：

 g)使用f步骤命令依次查看46与47号线程

h)分析步骤f)与步骤g)的堆栈

我们发现，三个线程都在处理ProcessReceive。那么，这个方法到底做了什么呢？

到了该步骤，就需要我们去查看源码了。

 i)分析源码

源码解释：该方法是socket数据包接收后的解析部分。

发现该方法存在两处while循环，我们首先要怀疑：是不是死循环导致的线程空转不能退出导致的cpu爬升呢？

最终我们分析发现：

由于socket的粘包和分包机制，消息体可能存在多个消息体合并发送到服务端，并存在半包的可能性。当存在半包（后半个消息体）的时候，最后一次while循环，x值为-1，y为大于0的一个值。

再次进入while循环，substring方法会抛出异常。

代码的catch吞掉了这个异常（catch中为空，不进行任何处理），

于是会再次while（true）外层循环，再从头开始一次消息体解析，再次异常。

最终陷入死循环。

好了，到底，一切真相大白。

这也提醒我们，自己在写while这种循环体的时候，是否对跳出的边界梳理清楚。