应用程序高级调试-请求挂起分析

语言: CN / TW / HK

前言

新能源汽车市场渗透率屡创新高,新能源汽车电池的安全问题日益凸显,特来电充电安全防护系统采用了高可用,高并发,分布式微服务架构,给实时防护和App等提供实时服务。在测试环境中 服务 部署后运行正常,响应很快,后续测试过程中发现部分服务突然慢了,服务能返回数据,但响应时间明显变长,每次都需要等待10s以上,服务查询的数据量不大,请求量也不高,业务Sql直接在数据库中执行响应时间也很短。于是尝试抓取dump文件( 进程的内存镜像,文件中包含程序的执行状态 )进行分析原因。

一、问题分析的基本思路

    • 定位问题

    • 分析问题

    • 解决问题

本文分析的问题表面上看一个性能问题,实际是中间件异常导致服务超时的问题。问题定位时,需从不同的视角和维度去审视问题;分析问题时,识别线索顺藤摸瓜,找到问题的症结;对症下药解决问题,可能是环境配置问题,也可能是设计问题,修复后再进行验证。

二、问题具体分析过程

1、打开dump文件, 载入sos调试扩展,mex插件。

.loadby sos clr
.load mex

备注:mex插件可到 https://www.microsoft.com/en-us/download/details.aspx?id=53304下载,分析问题时,可根据自己的需要进行加载。

2、服务响应慢,优先考虑是否存在 线程阻塞 的情况,通过!syncblk命令查看。没有发现被阻塞的线程信息。

3、查看所有的Exception,通过!dae命令查看。发现存在多个Redis连接异常。该业务代码中有应用Redis的场景,因请求Redis异常,会自动降级查询关系型数据库中的数据。

4、查看所有的线程运行情况,通过!threads命令查看。  发现46号线程 存在Lock情况

5、查看所有线程堆栈, 通过~*e!clrstack命令查看。 46号线程的堆栈信息可看出,创建Redis连接,连接异常,重新连接的动作, 设置 Redis连接超时为5s,两次连接为10s,和服务的响应时长是呼应的。

6、 46 号线程堆栈上有异常,并且存在锁,通过 ~ 46s 命令切换到 46 号线程 ,通过 !dso命令 查看 46 号线程栈上的 所有对象的信息 。对象信息中存在 Redis 创建连接,连接失败异常,重新连接的动作描述信息,及对应对象地址。可根据对象地址查看对象的详细信息。

7、通过!do2 命令 查看Redis的连接信息,包含Redis连接地址、密码、端口和超时时间等。

8、通过!do2 查看连接Redis异常信息,   提示无法创建Socket连接,表明无法访问到Redis。

9、检查Redis运行窗口,发现Redis没有正常启动,Redis窗口处于hang住的状态,如下图所示:  

重启Redis,下图是正常运行的效果:

10、为什么会导致Redis启动失败呢?     

Console控制台的属性中有个【快速编辑模型模式】编辑选项被设置为勾选状态,启动过程中,点击页面中的位置,会进入快速编辑模式等待输入,因此没有启动完成,此时Redis为不可用状态。

11、如何避免问题再次发生?

Console控制台的属性中 快速编辑模型模式】编辑 选项 设置为不勾选的状态即可。

总结

以上是这个网关服务请求挂起问题的总结和具体过程。使用WindDbg调试工具,分析Dump文件,查看异常信息,线程堆栈,托管对象等操作,找到问题的根因并解决。把工具的使用方法和分析过程分享给大家,希望对大家有所帮助。