一, 引子
对于互联网公司, 线上 CPU 飙升的问题很常见(例如某个活动开始, 流量突然飙升时), 按照本文的步骤排查, 基本 1 分钟即可搞定! 特此整理排查方法一篇, 供大家参考讨论提高.
二, 问题复现
线上系统突然运行缓慢, CPU 飙升, 甚至到 100%, 以及 Full GC 次数过多, 接着就是各种报警: 例如接口超时报警等. 此时急需快速线上排查问题.
三, 问题排查
不管什么问题, 既然是 CPU 飙升, 肯定是查一下耗 CPU 的线程, 然后看看 GC.
3.1 核心排查步骤
1. 执行 "top" 命令: 查看所有进程占系统 CPU 的排序. 极大可能排第一个的就是咱们的 java 进程(COMMAND 列).PID 那一列就是进程号.
2. 执行 "top -Hp 进程号" 命令: 查看 java 进程下的所有线程占 CPU 的情况.
3. 执行 "printf"%x\n 10"命令 : 后续查看线程堆栈信息展示的都是十六进制, 为了找到咱们的线程堆栈信息, 咱们需要把线程号转成 16 进制. 例如, printf"%x\n 10-》打印: a, 那么在 jstack 中线程号就是 0xa.
4. 执行 "jstack 进程号 | grep 线程 ID" 查找某进程下 -》线程 ID(jstack 堆栈信息中的 nid)=0xa 的线程堆栈信息. 如果 ""VM Thread" os_prio=0 tid=0x00007f871806e000 nid=0xa runnable", 第一个双引号圈起来的就是线程名, 如果是"VM Thread" 这就是虚拟机 GC 回收线程了
5. 执行 "jstat -gcutil 进程号 统计间隔毫秒 统计次数 (缺省代表一致统计)", 查看某进程 GC 持续变化情况, 如果发现返回中 FGC 很大且一直增大 -》确认 Full GC! 也可以使用 "jmap -heap 进程 ID" 查看一下进程的堆内从是不是要溢出了, 特别是老年代内从使用情况一般是达到阈值(具体看垃圾回收器和启动时配置的阈值) 就会进程 Full GC.
6. 执行 "jmap -dump:format=b,file=filename 进程 ID", 导出某进程下内存 heap 输出到文件中. 可以通过 eclipse 的 mat 工具查看内存中有哪些对象比较多, 飞机票: Eclipse Memory Analyzer(MAT), 内存泄漏插件, 安装使用一条龙;
3.2 原因分析
1. 内存消耗过大, 导致 Full GC 次数过多
执行步骤 1-5:
多个线程的 CPU 都超过了 100%, 通过 jstack 命令可以看到这些线程主要是垃圾回收线程 -》上一节步骤 2
通过 jstat 命令监控 GC 情况, 可以看到 Full GC 次数非常多, 并且次数在不断增加.--》上一节步骤 5
确定是 Full GC, 接下来找到具体原因:
生成大量的对象, 导致内存溢出 -》执行步骤 6, 查看具体内存对象占用情况.
内存占用不高, 但是 Full GC 次数还是比较多, 此时可能是代码中手动调用 System.gc()导致 GC 次数过多, 这可以通过添加 -XX:+DisableExplicitGC 来禁用 JVM 对显示 GC 的响应.
2. 代码中有大量消耗 CPU 的操作, 导致 CPU 过高, 系统运行缓慢;
执行步骤 1-4: 在步骤 4jstack, 可直接定位到代码行. 例如某些复杂算法, 甚至算法 BUG, 无限循环递归等等.
3. 由于锁使用不当, 导致死锁.
执行步骤 1-4: 如果有死锁, 会直接提示. 关键字: deadlock. 步骤四, 会打印出业务死锁的位置.
造成死锁的原因: 最典型的就是 2 个线程互相等待对方持有的锁.
4. 随机出现大量线程访问接口缓慢.
代码某个位置有阻塞性的操作, 导致该功能调用整体比较耗时, 但出现是比较随机的; 平时消耗的 CPU 不多, 而且占用的内存也不高.
思路:
首先找到该接口, 通过压测工具不断加大访问力度, 大量线程将阻塞于该阻塞点.
执行步骤 1-4:
"http-nio-8080-exec-4" #31 daemon prio=5 os_prio=31 tid=0x00007fd08d0fa000 nid=0x6403 waiting on condition [0x00007000033db000]
java.lang.Thread.State: TIMED_WAITING (sleeping)-》期限等待
- at java.lang.Thread.sleep(Native Method)
- at java.lang.Thread.sleep(Thread.java:340)
- at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
at com.*.user.controller.UserController.detail(UserController.java:18)-》业务代码阻塞点
如上图, 找到业务代码阻塞点, 这里业务代码使用了 TimeUnit.sleep()方法, 使线程进入了 TIMED_WAITING(期限等待)状态. 关于线程状态, 不理解的飞机票: Thread 类源码剖析
5. 某个线程由于某种原因而进入 WAITING 状态, 此时该功能整体不可用, 但是无法复现;
执行步骤 1-4:jstack 多查询几次, 每次间隔 30 秒, 对比一直停留在 parking 导致的 WAITING 状态的线程. 例如 CountDownLatch 倒计时器, 使得相关想成等待 ->AQS(AbstractQueuedSynchronizer AQS 框架源码剖析)->LockSupport.park().
"Thread-0" #11 prio=5 os_prio=31 tid=0x00007f9de08c7000 nid=0x5603 waiting on condition [0x0000700001f89000]
java.lang.Thread.State: WAITING (parking) ->无期限等待
- at sun.misc.Unsafe.park(Native Method)
- at java.util.concurrent.locks.LockSupport.park(LockSupport.java:304)
at com.*.SyncTask.lambda$main$0(SyncTask.java:8)-》业务代码阻塞点
- at com.*.SyncTask$$Lambda$1/1791741888.run(Unknown Source)
- at java.lang.Thread.run(Thread.java:748)
四, 总结
按照 3.1 节的 6 个步骤走下来, 基本都能找到问题所在.
==== 参考 ====
https://mp.weixin.qq.com/s/g8KJhOtiBHWb6wNFrCcLVg
来源: https://www.cnblogs.com/dennyzhangdd/p/11585971.html