目录
?
注意：本文参考了?? arthas 排查内存溢出_Java应用线上排查总结_惊奇影像的博客-CSDN博客
深入理解JVM虚拟机15：Java线上故障排查全套路总结_程序员黄小斜-CSDN博客
背景
本文总结了一些常见的线上应急现象和对应排查步骤和工具。分享的主要目的是想让对线上问题接触少的同学有个预先认知，免得在遇到实际问题时手忙脚乱。毕竟作者自己也是从手忙脚乱时走过来的。
只不过这里先提示一下。在线上应急过程中要记住，只有一个总体目标：尽快恢复服务，消除影响。不管处于应急的哪个阶段，我们首先必须想到的是恢复问题，恢复问题不一定能够定位问题，也不一定有完美的解决方案，也许是通过经验判断，也许是预设开关等，但都可能让我们达到快速恢复的目的，然后保留部分现场，再去定位问题、解决问题和复盘。
在大多数情况下，我们都是先优先恢复服务，保留下当时的异常信息(内存dump、线程dump、gc log等等，在紧急情况下甚至可以不用保留，等到事后去复现)，等到服务正常，再去复盘问题。
好，现在让我们进入正题吧。
CPU 利用率高/飙升
场景预设：
监控系统突然告警，提示服务器负载异常。
预先说明：
CPU飙升只是一种现象，其中具体的问题可能有很多种，这里只是借这个现象切入。
注：CPU使用率是衡量系统繁忙程度的重要指标。但是CPU使用率的安全阈值是相对的，取决于你的系统的IO密集型还是计算密集型。一般计算密集型应用CPU使用率偏高load偏低，IO密集型相反。
常见原因：
频繁 gc
死循环、线程阻塞、io wait…etc
第一步：定位出问题的线程
方法 a: 传统的方法
top 定位CPU 最高的进程
执行top命令，查看所有进程占系统CPU的排序，定位是哪个进程搞的鬼。在本例中就是咱们的java进程。PID那一列就是进程号。(对指示符含义不清楚的见【附录】)
?
根据top命令，根据前面得到的进程号，得到对应的线程号
top -Hp pid 定位使用 CPU 最高的线程
再将这TID转为16进制，为等会在jstack中查找方便
printf ‘0x%x’ tid 线程 id 转化 16 进制
printf ‘0x%x’ 12817
0x3211
通过jstack查看对应线程的执行代码与运行状态
jstack pid | grep tid 找到线程堆栈
jstack 12816 | grep 0x3211 -A 30
也可以导出进程stack信息：
jstack -l [pid]?>>?[文件名]
eg:jstack -l 123456 >> 123.txt
当然更常见的是我们对整个jstack文件进行分析，通常我们会比较关注WAITING和TIMED_WAITING的部分，BLOCKED就不用说了。我们可以使用命令cat jstack.log | grep "java.lang.Thread.State" | sort -nr | uniq -c来对jstack的状态有一个整体的把握，如果WAITING 之类的特别多，那么多半是有问题啦。
方法 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-threadschmod +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进程show-busy-java-threads -c 方法 c: arthas thread
阿里开源的arthas（阿尔萨斯）现在已经几乎包揽了我们线上排查问题的工作，提供了一个很完整的工具集。在这个场景中，也只需要一个thread -n命令即可。
wget https://arthas.gitee.io/arthas-boot.jar # 下载chmod 755 ./arthas-boot.jar # 授权java -jar arthas-boot.jar # 运行并选择java进程thread # 列出线程thread 1001 # 查看线程1001
要注意的是，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 runnableGC 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 runnablgc 排查的内容较多，所以我决定在后面单独列一节讲述。
情况二：发现使用CPU最高的是业务线程
1 io wait
比如此例中，就是因为磁盘空间不够导致的io阻塞
2 等待内核态锁，如 synchronized
jstack -l pid | grep BLOCKED 查看阻塞态线程堆栈
dump 线程栈，分析线程持锁情况。
arthas提供了thread -b，可以找出当前阻塞其他线程的线程。针对 synchronized 情况
3 死循环
常见现象：频繁 GC
回顾GC流程与查看GC情况
在了解下面内容之前，请先花点时间回顾一下GC的整个流程。
接前面的内容，这个情况下，我们自然而然想到去查看gc 的具体情况。
方法a : 查看gc 日志
方法b : jstat -gcutil 进程号 统计间隔毫秒 统计次数(缺省代表一致统计)
jstat -gc pid 1000命令来对gc分代变化情况进行观察，1000表示采样间隔(ms)，S0C/S1C、S0U/S1U、EC/EU、OC/OU、MC/MU分别代表两个Survivor区、Eden区、老年代、元数据区的容量和使用量。YGC/YGT、FGC/FGCT、GCT则代表YoungGc、FullGc的耗时和次数以及总耗时。如果看到gc比较频繁，再针对gc方面做进一步分析。
方法c : 如果所在公司有对应用进行监控的组件当然更方便(比如Prometheus + Grafana)
这里对开启 gc log 进行补充说明。一个常常被讨论的问题(惯性思维)是在生产环境中GC日志是否应该开启。因为它所产生的开销通常都非常有限，因此我的答案是需要开启。但并不一定在启动JVM时就必须指定GC日志参数。
HotSpot JVM有一类特别的参数叫做可管理的参数。对于这些参数，可以在运行时修改他们的值。我们这里所讨论的所有参数以及以“PrintGC”开头的参数都是可管理的参数。这样在任何时候我们都可以开启或是关闭GC日志。比如我们可以使用JDK自带的jinfo工具来设置这些参数，或者是通过JMX客户端调用HotSpotDiagnostic MXBean的setVMOption方法来设置这些参数。
这里再次大赞arthas，它提供的vmoption命令可以直接查看，更新VM诊断相关的参数。
获取到gc日志之后，可以上传到GC easy帮助分析，得到可视化的图表分析结果。
GC 原因及定位
prommotion failed
从S区晋升的对象在老年代也放不下导致 FullGC(fgc 回收无效则抛 OOM)。
可能原因：
1 survivor 区太小，对象过早进入老年代
查看 SurvivorRatio 参数
2 大对象分配，没有足够的内存
dump 堆，profiler/MAT 分析对象占用情况
3 old 区存在大量对象
dump 堆，profiler/MAT 分析对象占用情况
你也可以从full GC 的效果来推断问题，正常情况下，一次full GC应该会回收大量内存，所以 正常的堆内存曲线应该是呈锯齿形。如果你发现full gc 之后堆内存几乎没有下降，那么可以推断： 堆中有大量不能回收的对象且在不停膨胀，使堆的使用占比超过full GC的触发阈值，但又回收不掉，导致full GC一直执行。换句话来说，可能是内存泄露了。
一般来说，GC相关的异常推断都需要涉及到内存分析，使用jmap之类的工具dump出内存快照(或者 Arthas的heapdump)命令，然后使用MAT、JProfiler、JVisualVM等可视化内存分析工具。
至于内存分析之后的步骤，就需要小伙伴们根据具体问题具体分析啦。
上下文切换异常
针对频繁上下文问题，我们可以使用vmstat命令来进行查看
cs(context switch)一列则代表了上下文切换的次数。如果我们希望对特定的pid进行监控那么可以使用?pidstat -w pid命令，cswch和nvcswch表示自愿及非自愿切换。
?
常见现象：线程池异常
场景预设：
业务监控突然告警，或者外部反馈提示大量请求执行失败。
异常说明：
Java 线程池以有界队列的线程池为例，当新任务提交时，如果运行的线程少于 corePoolSize，则创建新线程来处理请求。如果正在运行的线程数等于 corePoolSize 时，则新任务被添加到队列中，直到队列满。当队列满了后，会继续开辟新线程来处理任务，但不超过 maximumPoolSize。当任务队列满了并且已开辟了最大线程数，此时又来了新任务，ThreadPoolExecutor 会拒绝服务。
线程池异常常见问题和原因
这种线程池异常，一般可以通过开发查看日志查出原因，有以下几种原因：
1 下游服务 响应时间(RT)过长
这种情况有可能是因为下游服务异常导致的，作为消费者我们要设置合适的超时时间和熔断降级机制。
另外针对这种情况，一般都要有对应的监控机制：比如日志监控、metrics监控告警等，不要等到目标用户感觉到异常，从外部反映进来问题才去看日志查。
2 数据库慢 sql 或者数据库死锁
查看日志中相关的关键词。
3 Java 代码死锁
jstack –l pid | grep -i –E 'BLOCKED | deadlock'
CPU常见问题恢复
对于上文提到的一些问题，这里总结了一些恢复的方法。
?
磁盘
磁盘问题和cpu一样是属于比较基础的。首先是磁盘空间方面，我们直接使用df -hl来查看文件系统状态
更多时候，磁盘问题还是性能上的问题。我们可以通过iostatiostat -d -k -x来进行分析
?
最后一列%util可以看到每块磁盘写入的程度，而rrqpm/s以及wrqm/s分别表示读写速度，一般就能帮助定位到具体哪块磁盘出现问题了。
另外我们还需要知道是哪个进程在进行读写，一般来说开发自己心里有数，或者用iotop命令来进行定位文件读写的来源。
?
不过这边拿到的是tid，我们要转换成pid，可以通过readlink命令来找到pid:readlink -f /proc/*/task/tid/../..。?
找到pid之后就可以看这个进程具体的读写情况cat /proc/pid/io?
可以通过lsof命令来确定具体的文件读写情况lsof -p pid?
网络
涉及到网络层面的问题一般都比较复杂，场景多，定位难，成为了大多数开发的噩梦，应该是最复杂的了。这里会举一些例子，并从tcp层、应用层以及工具的使用等方面进行阐述。
超时
超时错误大部分处在应用层面，所以这块着重理解概念。超时大体可以分为连接超时和读写超时，某些使用连接池的客户端框架还会存在获取连接超时和空闲连接清理超时。
1 读写超时。readTimeout/writeTimeout，有些框架叫做so_timeout或者socketTimeout，均指的是数据读写超时。注意这边的超时大部分是指逻辑上的超时。soa的超时指的也是读超时。读写超时一般都只针对客户端设置。
2 连接超时。connectionTimeout，客户端通常指与服务端建立连接的最大时间。服务端这边connectionTimeout就有些五花八门了，jetty中表示空闲连接清理时间，tomcat则表示连接维持的最大时间。
3 其他。包括连接获取超时connectionAcquireTimeout和空闲连接清理超时idleConnectionTimeout。多用于使用连接池或队列的客户端或服务端框架。
我们在设置各种超时时间中，需要确认的是尽量保持客户端的超时小于服务端的超时，以保证连接正常结束。
在实际开发中，我们关心最多的应该是接口的读写超时了。
如何设置合理的接口超时是一个问题。如果接口超时设置的过长，那么有可能会过多地占用服务端的tcp连接。而如果接口设置的过短，那么接口超时就会非常频繁。
服务端接口明明rt降低，但客户端仍然一直超时又是另一个问题。这个问题其实很简单，客户端到服务端的链路包括网络传输、排队以及服务处理等，每一个环节都可能是耗时的原因。
TCP队列溢出
tcp队列溢出是个相对底层的错误，它可能会造成超时、rst等更表层的错误。因此错误也更隐蔽，所以我们单独说一说。
?
如上图所示，这里有两个队列：syns queue(半连接队列）、accept queue（全连接队列）。三次握手，在server收到client的syn后，把消息放到syns queue，回复syn+ack给client，server收到client的ack，如果这时accept queue没满，那就从syns queue拿出暂存的信息放入accept queue中，否则按tcp_abort_on_overflow指示的执行。
tcp_abort_on_overflow 0表示如果三次握手第三步的时候accept queue满了那么server扔掉client发过来的ack。tcp_abort_on_overflow 1则表示第三步的时候如果全连接队列满了，server发送一个rst包给client，表示废掉这个握手过程和这个连接，意味着日志里可能会有很多connection reset / connection reset by peer。
那么在实际开发中，我们怎么能快速定位到tcp队列溢出呢？
netstat命令，执行netstat -s | egrep "listen|LISTEN"
?
如上图所示，overflowed表示全连接队列溢出的次数，sockets dropped表示半连接队列溢出的次数。
ss命令，执行ss -lnt
上面看到Send-Q 表示第三列的listen端口上的全连接队列最大为5，第一列Recv-Q为全连接队列当前使用了多少。
接着我们看看怎么设置全连接、半连接队列大小吧：
全连接队列的大小取决于min(backlog, somaxconn)。backlog是在socket创建的时候传入的，somaxconn是一个os级别的系统参数。而半连接队列的大小取决于max(64, /proc/sys/net/ipv4/tcp_max_syn_backlog)。
在日常开发中，我们往往使用servlet容器作为服务端，所以我们有时候也需要关注容器的连接队列大小。在tomcat中backlog叫做acceptCount，在jetty里面则是acceptQueueSize。
RST异常
RST包表示连接重置，用于关闭一些无用的连接，通常表示异常关闭，区别于四次挥手。
在实际开发中，我们往往会看到connection reset / connection reset by peer错误，这种情况就是RST包导致的。
端口不存在
如果像不存在的端口发出建立连接SYN请求，那么服务端发现自己并没有这个端口则会直接返回一个RST报文，用于中断连接。
主动代替FIN终止连接
一般来说，正常的连接关闭都是需要通过FIN报文实现，然而我们也可以用RST报文来代替FIN，表示直接终止连接。实际开发中，可设置SO_LINGER数值来控制，这种往往是故意的，来跳过TIMED_WAIT，提供交互效率，不闲就慎用。
客户端或服务端有一边发生了异常，该方向对端发送RST以告知关闭连接
我们上面讲的tcp队列溢出发送RST包其实也是属于这一种。这种往往是由于某些原因，一方无法再能正常处理请求连接了(比如程序崩了，队列满了)，从而告知另一方关闭连接。
接收到的TCP报文不在已知的TCP连接内
比如，一方机器由于网络实在太差TCP报文失踪了，另一方关闭了该连接，然后过了许久收到了之前失踪的TCP报文，但由于对应的TCP连接已不存在，那么会直接发一个RST包以便开启新的连接。
一方长期未收到另一方的确认报文，在一定时间或重传次数后发出RST报文
这种大多也和网络环境相关了，网络环境差可能会导致更多的RST报文。
之前说过RST报文多会导致程序报错，在一个已关闭的连接上读操作会报connection reset，而在一个已关闭的连接上写操作则会报connection reset by peer。通常我们可能还会看到broken pipe错误，这是管道层面的错误，表示对已关闭的管道进行读写，往往是在收到RST，报出connection reset错后继续读写数据报的错，这个在glibc源码注释中也有介绍。
我们在排查故障时候怎么确定有RST包的存在呢？当然是使用tcpdump命令进行抓包，并使用wireshark进行简单分析了。tcpdump -i en0 tcp -w xxx.cap，en0表示监听的网卡。
?
接下来我们通过wireshark打开抓到的包，可能就能看到如下图所示，红色的就表示RST包了。?
TIME_WAIT和CLOSE_WAIT
TIME_WAIT和CLOSE_WAIT是啥意思相信大家都知道。在线上时，我们可以直接用命令netstat -n | awk '/^tcp/ {++S[$NF]} END {for(a in S) print a, S[a]}'来查看time-wait和close_wait的数量
用ss命令会更快ss -ant | awk '{++S[$1]} END {for(a in S) print a, S[a]}'
?
TIME_WAIT
time_wait的存在一是为了丢失的数据包被后面连接复用，二是为了在2MSL的时间范围内正常关闭连接。它的存在其实会大大减少RST包的出现。
过多的time_wait在短连接频繁的场景比较容易出现。这种情况可以在服务端做一些内核参数调优:
-
#表示开启重用。允许将TIME-WAIT sockets重新用于新的TCP连接，默认为0，表示关闭 -
net.ipv4.tcp_tw_reuse?=?1 -
#表示开启TCP连接中TIME-WAIT?sockets的快速回收，默认为0，表示关闭 -
net.ipv4.tcp_tw_recycle?=?1
当然我们不要忘记在NAT环境下因为时间戳错乱导致数据包被拒绝的坑了，另外的办法就是改小tcp_max_tw_buckets，超过这个数的time_wait都会被干掉，不过这也会导致报time wait bucket table overflow的错。
CLOSE_WAIT
close_wait往往都是因为应用程序写的有问题，没有在ACK后再次发起FIN报文。close_wait出现的概率甚至比time_wait要更高，后果也更严重。往往是由于某个地方阻塞住了，没有正常关闭连接，从而渐渐地消耗完所有的线程。
想要定位这类问题，最好是通过jstack来分析线程堆栈来排查问题，具体可参考上述章节。这里仅举一个例子。
开发同学说应用上线后CLOSE_WAIT就一直增多，直到挂掉为止，jstack后找到比较可疑的堆栈是大部分线程都卡在了countdownlatch.await方法，找开发同学了解后得知使用了多线程但是确没有catch异常，修改后发现异常仅仅是最简单的升级sdk后常出现的class not found。