Java 应用线上问题排查思路、工具小结

Java 应用线上问题排查思路、工具小结

❝

原文地址：Java 应用线上问题排查小结

原创不易，转载请注明出处。

❞

前言

本文总结了一些Java应用线上常见问题的定位步骤，分享的主要目的是想让对线上问题接触少的同窗有个预先认知，省得在遇到实际问题时手忙脚乱。毕竟做者本身也是从手忙脚乱时走过来的。

只不过这里先提示一下。在线上应急过程当中要记住，只有一个整体目标：「尽快恢复服务，消除影响」。 无论处于应急的哪一个阶段，咱们首先必须想到的是恢复问题，恢复问题不必定可以定位问题，也不必定有完美的解决方案，也许是经过经验判断，也许是预设开关等，但均可能让咱们达到快速恢复的目的，而后保留部分现场，再去定位问题、解决问题和复盘。

好，如今让咱们进入正题吧。

1、CPU 利用率高/飙升

❝

注：CPU使用率是衡量系统繁忙程度的重要指标。可是「CPU使用率的安全阈值是相对的，取决于你的系统的IO密集型仍是计算密集型」。通常计算密集型应用CPU使用率偏高load偏低，IO密集型相反。

❞

「常见缘由：」

• 频繁 gc
• 死循环、线程阻塞、io wait...etc

模拟

这里为了演示，用一个最简单的死循环来模拟CPU飙升的场景，下面是模拟代码，

在一个最简单的SpringBoot Web 项目中增长CpuReaper这个类，

/**  * 模拟 cpu 飙升场景  * @author Richard_yyf  */ @Component public class CpuReaper {   @PostConstruct  public void cpuReaper() {  int num = 0;  long start = System.currentTimeMillis() / 1000;  while (true) {  num = num + 1;  if (num == Integer.MAX_VALUE) {  System.out.println("reset");  num = 0;  }  if ((System.currentTimeMillis() / 1000) - start > 1000) {  return;  }  }  } } 复制代码

打包成jar以后，在服务器上运行。java -jar cpu-reaper.jar &

第一步：定位出问题的线程

方法 a: 传统的方法

1. top 定位CPU 最高的进程

   执行top命令，查看全部进程占系统CPU的排序，定位是哪一个进程搞的鬼。在本例中就是我们的java进程。PID那一列就是进程号。(对指示符含义不清楚的见【附录】)

   

2. top -Hp pid 定位使用 CPU 最高的线程

   

3. printf '0x%x' tid 线程 id 转化 16 进制

 > printf '0x%x' 12817
 > 0x3211 复制代码

4. jstack pid | grep tid 找到线程堆栈

 > jstack 12816 | grep 0x3211 -A 30
复制代码

方法 b: show-busy-java-threads

这个脚原本自于github上一个开源项目，项目提供了不少有用的脚本，show-busy-java-threads就是其中的一个。使用这个脚本，能够直接简化方法A中的繁琐步骤。以下，

> wget --no-check-certificate https://raw.github.com/oldratlee/useful-scripts/release-2.x/bin/show-busy-java-threads
> chmod +x show-busy-java-threads  > ./show-busy-java-threads 复制代码

show-busy-java-threads
# 从全部运行的Java进程中找出最消耗CPU的线程（缺省5个），打印出其线程栈  # 缺省会自动从全部的Java进程中找出最消耗CPU的线程，这样用更方便 # 固然你能够手动指定要分析的Java进程Id，以保证只会显示你关心的那个Java进程的信息 show-busy-java-threads -p <指定的Java进程Id>  show-busy-java-threads -c <要显示的线程栈数> 复制代码

方法 c: arthas thread

阿里开源的arthas如今已经几乎包揽了咱们线上排查问题的工做，提供了一个很完整的工具集。在这个场景中，也只须要一个thread -n命令便可。

> curl -O https://arthas.gitee.io/arthas-boot.jar # 下载
复制代码

❝

要注意的是，arthas的cpu占比，和前面两种cpu占比统计方式不一样。前面两种针对的是Java进程启动开始到如今的cpu占比状况，arthas这种是一段采样间隔内，当前JVM里各个线程所占用的cpu时间占总cpu时间的百分比。

具体见官网：https://alibaba.github.io/arthas/thread.html

❞

后续

经过第一步，找出有问题的代码以后，观察到线程栈以后。咱们「就要根据具体问题来具体分析」。这里举几个例子。

状况一：发现使用CPU最高的都是GC 线程。

GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007fd99001f800 nid=0x779 runnable GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007fd990021800 nid=0x77a runnable GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007fd990023000 nid=0x77b runnable GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007fd990025000 nid=0x77c runnabl 复制代码

gc 排查的内容较多，因此我决定在后面单独列一节讲述。

状况二：发现使用CPU最高的是业务线程

• io wait

  • 好比 此例中，就是由于磁盘空间不够致使的io阻塞
• 等待内核态锁，如 synchronized

  • jstack -l pid | grep BLOCKED 查看阻塞态线程堆栈
  • dump 线程栈，分析线程持锁状况。
  • arthas提供了 thread -b，能够找出当前阻塞其余线程的线程。针对 synchronized 状况

2、频繁 GC

1. 回顾GC流程

在了解下面内容以前，请先花点时间回顾一下GC的整个流程。

---

接前面的内容，这个状况下，咱们天然而然想到去查看gc 的具体状况。

• 方法a : 查看gc 日志
• 方法b : jstat -gcutil 进程号 统计间隔毫秒 统计次数（缺省表明一致统计
• 方法c : 若是所在公司有对应用进行监控的组件固然更方便（好比Prometheus + Grafana）

这里对开启 gc log 进行补充说明。一个经常被讨论的问题（惯性思惟）是在生产环境中GC日志是否应该开启。由于它所产生的开销一般都很是有限，所以个人答案是须要「开启」。但并不必定在启动JVM时就必须指定GC日志参数。

❝

HotSpot JVM有一类特别的参数叫作可管理的参数。对于这些参数，能够在运行时修改他们的值。咱们这里所讨论的全部参数以及以“PrintGC”开头的参数都是可管理的参数。这样在任什么时候候咱们均可以开启或是关闭GC日志。好比咱们可使用JDK自带的jinfo工具来设置这些参数，或者是经过JMX客户端调用HotSpotDiagnostic MXBean的setVMOption方法来设置这些参数。

这里再次大赞arthas❤️，它提供的vmoption命令能够直接查看，更新VM诊断相关的参数。

❞

获取到gc日志以后，能够上传到GC easy帮助分析，获得可视化的图表分析结果。

2. GC 缘由及定位

「prommotion failed」

从S区晋升的对象在老年代也放不下致使 FullGC（fgc 回收无效则抛 OOM）。

可能缘由：

• 「survivor 区过小，对象过早进入老年代」

  查看 SurvivorRatio 参数

• 「大对象分配，没有足够的内存」

  dump 堆，profiler/MAT 分析对象占用状况

• 「old 区存在大量对象」

  dump 堆，profiler/MAT 分析对象占用状况

你也能够从full GC 的效果来推断问题，正常状况下，一次full GC应该会回收大量内存，因此 「正常的堆内存曲线应该是呈锯齿形」。若是你发现full gc 以后堆内存几乎没有降低，那么能够推断： 「堆中有大量不能回收的对象且在不停膨胀，使堆的使用占比超过full GC的触发阈值，但又回收不掉，致使full GC一直执行。「换句话来讲，多是」内存泄露」了。

通常来讲，GC相关的异常推断都须要涉及到「内存分析」，使用jmap之类的工具dump出内存快照（或者 Arthas的heapdump）命令，而后使用MAT、JProfiler、JVisualVM等可视化内存分析工具。

至于内存分析以后的步骤，就须要小伙伴们根据具体问题具体分析啦。

3、线程池异常

Java 线程池以有界队列的线程池为例，当新任务提交时，若是运行的线程少于 corePoolSize，则建立新线程来处理请求。若是正在运行的线程数等于 corePoolSize 时，则新任务被添加到队列中，直到队列满。当队列满了后，会继续开辟新线程来处理任务，但不超过 maximumPoolSize。当任务队列满了而且已开辟了最大线程数，此时又来了新任务，ThreadPoolExecutor 会拒绝服务。

常见问题和缘由

这种线程池异常，通常有如下几种缘由：

1. 「下游服务 响应时间（RT）过长」

   这种状况有多是由于下游服务异常致使的，做为消费者咱们要设置合适的超时时间和熔断降级机制。

   另外针对这种状况，通常都要有对应的监控机制：好比日志监控、metrics监控告警等，不要等到目标用户感受到异常，从外部反映进来问题才去看日志查。

2. 「数据库慢 sql 或者数据库死锁」

查看日志关键词

3. 「Java 代码死锁」

   jstack –l pid | grep -i –E 'BLOCKED | deadlock'

上述前两种问题的排查办法，通常都是经过查看日志或者一些监控组件。

4、常见问题恢复

❝

这一部份内容参考自此篇文章

❞

5、Arthas

这里仍是想单独用一节安利一下Arthas这个工具。

Arthas 是阿里巴巴开源的Java 诊断工具，基于 Java Agent 方式，使用 Instrumentation 方式修改字节码方式进行 Java 应用诊断。

• dashboard ：系统实时数据面板, 可查看线程，内存，gc 等信息

• thread ：查看当前线程信息，查看线程的堆栈，如查看最繁忙的前 n 线程

• getstatic：获取静态属性值，如 getstatic className attrName 可用于查看线上开关真实值

• sc：查看 jvm 已加载类信息，可用于排查 jar 包冲突

• sm：查看 jvm 已加载类的方法信息

• jad：反编译 jvm 加载类信息,排查代码逻辑没执行缘由

• logger：查看logger信息，更新logger level

• watch：观测方法执行数据，包含出参、入参、异常等

• trace：方法内部调用时长，并输出每一个节点的耗时，用于性能分析

• tt：用于记录方法，并作回放

❝

以上内容节选自Arthas官方文档。

❞

另外，Arthas里的 还集成了 ognl 这个轻量级的表达式引擎，经过ognl，你能够用arthas 实现不少的“骚”操做。

其余的这里就很少说了，感兴趣的能够去看看arthas的官方文档、github issue。

6、涉及工具

再说下一些工具。

• Arthas（超级推荐❤️❤️）
• useful-scripts
• GC easy
• Smart Java thread dump analyzer - thread dump analysis in seconds
• PerfMa - Java虚拟机参数/线程dump/内存dump分析
• Linux 命令
• Java N 板斧
• MAT、JProfiler...等可视化内存分析工具

结语

我知道我这篇文章对于线上异常的概括并不全面，还有「网络（超时、TCP队列溢出...）」、堆外内存等不少的异常场景没有涉及。主要是由于本身接触不多，没有深入体会研究过，强行写出来免不得会差点意思，更怕的是误了别人😅。

还有想说的就是，Java 应用线上排查实际很是考究一我的基础是否扎实、解决问题能力是否过关。好比线程池运行机制、gc分析、Java 内存分析等等，若是基础不扎实，看了更多的是一头雾水。另外就是，多看看网上一些好的关于异常排查的经验文章，这样即便本身暂时遇不到，可是会在脑海里面慢慢总结出一套解决相似问题的结构框架，到时候真的遇到了，也就是举一反三的事情罢了。

❝

若是本文有帮助到你，但愿能点个赞，这是对个人最大动力🤝🤝🤗🤗。

❞

参考

• https://developer.aliyun.com/article/757655
• Arthas 3.2.0 文档
• 《分布式服务架构：原理、设计与实战》

附录

top 命令显示的指示符的含义

指示符	含义
PID	进程id
USER	进程全部者
PR	进程优先级
NI	nice值。负值表示高优先级，正值表示低优先级
VIRT	进程使用的虚拟内存总量，单位kb。VIRT=SWAP+RES
RES	进程使用的、未被换出的物理内存大小，单位kb。RES=CODE+DATA
SHR	共享内存大小，单位kb
S	进程状态。D=不可中断的睡眠状态 R=运行 S=睡眠 T=跟踪/中止 Z=僵尸进程
%CPU	上次更新到如今的CPU时间占用百分比
%MEM	进程使用的物理内存百分比
TIME+	进程使用的CPU时间总计，单位1/100秒
COMMAND	进程名称（命令名/命令行）