
查看监控GC的监控没有长时间的暂停redis的写入耗时监控确实时间很长dubbo接口线程池打满时自动打印了堆栈查看关键线程的堆栈redis的io线程业务线程设置了睡眠时间的线程没有在应该被唤醒时自动唤醒分析过程通过监控可以看到io线程似乎都在等待io睡眠线程也在正常睡眠但是为什么会突然停住一般常见的原因有GC,CPU打满。gc已经看过了没有长时间gc那么是否是因为短时间的cpu达到100%导致呢由于我们的监控是分钟级监控在监控上没有看到明显的变化不代表秒级的cpu很高于是让运维在机器上每秒抓取vmstat的数据可以看到在问题发生的时间段内数据有明显的变化。运行任务数只有1不可中断任务数为变成0cpu使用率是7明显低于正常状态的数据。线程切换次数也从正常20w变成只有几百。到这里已经非常奇怪了为什么任务都不执行了为什么卡主了当时考虑的方向有网络阻塞线程锁内存回收抖动于是又增加了内存脏页刷新数据的抓取ping网络的数据抓取可以看到问题时间内内存脏页也基本不变化了说明不是问题原因网络延迟在问题时间段没有任何变化网络没有问题锁的问题在线程堆栈文件中看过了基本没有锁存在刚才考虑的方向基本都不是问题最后想到那个在卡顿时间内一直在执行的任务是什么任务为什么它能执行于是让运维每秒抓取top命令中R状态的线程查看问题时间段内在执行的线程终于发现了24861这个线程查看这个线程的线程栈一开始看到这个线程的线程栈时非常诧异因为我们对外提供的是DUBBO接口没有http接口访问。但这个线程是http接口线程不应该有访问仔细查看堆栈发现是普罗米修斯拉取监控数据时的http请求普罗米修斯生成监控数据时会获取线程信息可能会导致线程暂停那么会不会是这个原因导致问题确认首先从上面的top命令截图中可以确认http请求线程开始执行的时间点就是问题开始的时间点http请求线程结束的时间点也是问题恢复的时间点。从时间上来看完全符合查看历史dubbo打印的线程堆栈搜索拉取线程的代码sun.management.ThreadImpl.getThreadInfo。发现每次堆栈中都有对应的代码堆栈。由此可以基本确认这个就是问题的根源后续又核对了几次问题发生时的情况最终确认了这个就是源头。并且线程数量越多该问题就越频繁。我们的应用有大概3000个线程因此频繁触发此问题问题发生总结首先由普罗米修斯通过http请求拉取监控数据获取数据时会触发获取线程信息。然后所有线程都会暂停由一个name为VM Thread的jvm线程执行执行时间会有几秒不等http请求结束后卡顿结束疑问是否有大佬解答一下获取线程信息时会导致部分线程停顿还是全部线程停顿获取线程信息是纯内存操作即使有3000个线程感觉也不需要6秒时间。为什么会如此耗时。不同线程进入安全点的时差导致的吗后记dump 线程堆栈时是通过VM Thread线程执行的所以不管有几个cpu也只能有一个cpu在运行上面问题vmstat日志里可以看到问题发生时间段内只有一个运行任务所以在大规格的机器上运行有许多线程的java应用这个问题的卡顿时间也越长dubbo框架的线程池打满时也会触发dump 线程堆栈或其他dump 线程堆栈操作因此可能会导致短时间的一个卡顿转化为一个长时间的卡顿问题优化关闭普罗米修斯的线程数据抓取通过优化应用的线程模型降低了线程数量后