项目经验_之_问题排查
前言
Github：https://github.com/HealerJean
1、基本介绍
1.1、Java 所处生态
1.2、Java 服务常见问题
1.3、基于 Linux 命令排查
2、CPU 问题排查
2.1、CPU 问题原因
⬤ 单机
cpu异常可能受宿主机影响。⬤ 整个服务集群
cpu异常应该是自身程序逻辑有问题原因包括业务逻辑问题(死循环)、频繁
gc以及上下文切换过多，而最常见的往往是业务逻辑(或者框架逻辑)导致的。
2.1.1、宿主机影响
单机情况可能出现，大量节点同时受宿主影响可能性较小。
2.1.2、程序问题
1、top命令查看耗时最大的进程；
2、ps命令查看耗时最大的进程；
3、线程id，转换成16进制数；
4、jstack打印命令栈，查看对应的进场在做什么事情；
因为
cpu使用率是时间段内的统计值，jstack是一个瞬时堆栈只记录瞬时状态，两个根本不是一个维度的事，如果完全按照上面那一套步骤做的话碰到这种情况就傻眼了，冥思苦想半天却不得其解，根本不明白为什么这种代码会导致高cpu。针对可能出现的这种情况，实际排查问题的时候
jstack建议打印5次至少3次，根据多次的堆栈内容，再结合相关代码进行分析，定位高cpu出现的原因，高cpu可能是代码段中某个bug导致的而不是堆栈打印出来的那几行导致的。
2.1.1.1、top：命令确定内存情况，找到CPU过高的Java程序
1、top ：命令
top
2、P：根据CPU使用百分比大小进行排序
3、命令top -p 30030 ：只观察进程为30030，CPU百分比最大的那个Java程序
top -p 30030
观察几分钟，发现一只占用超高，那么基本上定位到它了
2.1.1.2、判断是哪个Java程序
1、ps -ef |grep PID或者ps aux | grep PID
ps -ef 30030
ps -aux 30030
定位到应用 asset-service占用比较高
2.1.1.3、定位哪个线程CPU比较高
top -H -p pid、打印该进程下线程占用cpu情况 ,定位到线程 TID30332占用较高，讲它转化成16进制 767c
top -H -p 30030 ：查看线程占用比例 得到线程30332 比较高
[work@vm10-123-3-2 ~]$ ps -mp 30030 -o THREAD,tid,time
USER %CPU PRI SCNT WCHAN USER SYSTEM TID TIME
work 95.9 - - - - - - 23-10:29:53
work 0.0 19 - futex_ - - 30030 00:00:00
work 0.0 19 - futex_ - - 30045 00:00:47
work 0.0 19 - futex_ - - 30046 00:00:20
work 0.0 19 - futex_ - - 30047 00:00:20
work 0.0 19 - futex_ - - 30048 00:00:20
work 95.6 19 - - - - 30332 23-08:37:00
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 30332 work 20 0 10.338g 1.034g 5228 R 99.9 3.3 34523:57 java 30206 work 20 0 10.338g 1.034g 5228 S 0.3 3.3 54:22.94 java 31131 work 20 0 10.338g 1.034g 5228 S 0.3 3.3 12:37.95 java 30030 work 20 0 10.338g 1.034g 5228 S 0.0 3.3 0:00.00 java 30045 work 20 0 10.338g 1.034g 5228 S 0.0 3.3 0:48.52 java 30046 work 20 0 10.338g 1.034g 5228 S 0.0 3.3 0:20.82 java 30047 work 20 0 10.338g 1.034g 5228 S 0.0 3.3 0:20.83 java
2.1.1.4、转储线程信息
2.1.1.5、下载到本地慢慢看
建议使用命令
jstack 30030 > 30030cpu.log下载到本地查看，
2.1.1.6、线程直接看
2.1.1.7、查看线程 id为30332 的16进制为 767c的线程日志
./jstack 30030 | grep 767c -A 10
[work@vm10-123-3-2 bin]$ ./jstack 30030 | grep 767c -A 10
"ObjectCleanerThread" #85 daemon prio=1 os_prio=0 tid=0x00007f20e290c800 nid=0x767c runnable [0x00007f20ec5a6000]
java.lang.Thread.State: RUNNABLE
at io.netty.util.Recycler$WeakOrderQueue$Head.run(Recycler.java:264)
at io.netty.util.internal.ObjectCleaner$AutomaticCleanerReference.cleanup(ObjectCleaner.java:143)
at io.netty.util.internal.ObjectCleaner$1.run(ObjectCleaner.java:62)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)
"Log4j2-TF-7-AsyncLoggerConfig--4" #81 daemon prio=5 os_prio=0 tid=0x00007f20e087e800 nid=0x75fe runnable [0x00007f20ec4a5000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
[work@vm10-123-3-2 bin]$
我们可以使用命令
cat jstack.log | grep "java.lang.Thread.State" | sort -nr | uniq -c来对jstack的状态有一个整体的把握，如果 WAITING 之类的特别多，那么多半是有问题啦。
3、内存问题排查
Java 的内存管理就是对象的分配和释放问题。
在 Java 中，内存的分配是由程序完成的，而内存的释放是由 GC 完成的，这种收支两条线的方法简化了程序员的工作，但同时也加重了JVM的工作。
Java 程序内存问题排查起来相对比 CPU 麻烦一些，场景也比较多。主要包括内存泄露、内存溢出、GC等问题。
3.1、内存泄露
3.1.1、定义
Java内存泄漏就是没有及时清理内存垃圾，导致系统无法再给你提供内存资源（内存资源耗尽）。Java内存泄露是说程序逻辑问题,造成申请的内存无法释放.这样的话无论多少内存,早晚都会被占用光的.最简单的例子就是死循环了.由于程序判断错误导经常发生此事。程序运行过程中动态分配内存给一些临时对象，这些对象有下面两个特点：
（1）这些对象是可达的
（2）这些对象是无用的，这些对象不会被
GC回收，然而它却占用内存，造成内存浪费。简单的描述为“被分配的对象可达但已无用”。
3.1.2、根本原因
长生命周期的对象持有短生命周期对象的引用就很可能发生内存泄漏，尽管短生命周期对象已经不再需要，但是因为长生命周期持有它的引用而导致不能被回收，这就是
Java中内存泄漏的发生场景。比如，
A对象引用B对象，A对象的生命周期（t1-t4）比B对象的生命周期（t2-t3）长的多。当B对象没有被应用程序使用之后，A对象仍然在引用着B对象。这样，垃圾回收器就没办法将B对象从内存中移除，从而导致内存问题，
3.1.3、引发原因
内存泄漏大多是代码层面设计不严谨，或设计错误（编程错误），导致程序未能释放已不再使用的内存。
内存泄漏具有隐蔽性，积累性的特征，属于遗漏型缺陷，而不是过错型缺陷，不会直接产生可观察的错误症状，而是逐渐堆积，降低应用的整体性能。
可能有以下原因：
1、ThreadLocal
2、一个类含有静态变量，这个类的对象就无法被回收
3、内存中数据量太大，比如一次性从数据库中取出来太多数据
4、代码中存在死循环，或者循环过多，产生过多的重复的对象
5、各种连接没有关闭：例如数据库连接、网络连接
6、单例模式：如果单例对象持有外部对象的引用，那么外部对象将不会被回收，引起内存泄漏
7、静态集合类中对对象的引用，在使用完后未清空(只把对象设为null，而不是从集合中移除)，使JVM不能回收，即内存泄漏
8、静态方法中只能使用全局静态变量，而如果静态变量又持有静态方法传入的参数对象的引用，会引起内存泄漏
3.1.4、症状
1、应用程序长时间连续运行时性能严重下降
2、CPU 使用率飙升，甚至到 100%
3、频繁 Full GC
4、应用程序抛出 OutOfMemoryError 错误
3.1.5、排查方法
内存泄露，很难觉察，需要不断的去观察
gc的情况，然后dump内存进行分析，才能定位到哪一段代码有问题
3.1.5.1、去监控平台看GC的情况
3.1.5.2、查看服务器本地日志是否有 OutOfMemoryError 异常日志
3.1.5.3、将jvm内存存活的对象dump下来进行分析(有专门的平台)
3.2、内存溢出
3.2.1、定义
程序运行过程中无法申请到足够的内存（某一块内存空间块耗尽）而导致的一种错误。
3.2.2、 症状
1、Caused by:java.lang.OutOfMemoryError: Java heap space：堆内存溢出
2、Caused by: java.lang.OutOfMemoryError: MetaSpace：元空间内存溢出（存在于JDK 8中）
3、Caused by: OutOfMemoryError：unable to create new native thread：创建本地线程内存溢出
4、Caused by:java.lang.OutOfMemoryError: Direct buffer memory：直接内存溢出
5、Caused by: java.lang.StackOverflowError：栈内存溢出
3.2.3、排查方法
3.3、GC问题
3.1.1、Young GC频率高
原因：
JVM参数设置不合理 ，新生代空间大小设置不合理（过大：Young GC时间长，过小：Young GC频繁）解决方案：
1、查看
-Xmn、-XX:SurvivorRatio等参数设置是否合理，能否通过调整jvm参数到达目的；2、如果参数正常，但是
young gc频率还是太高，需要分析HeapDump文件，看业务代码是否生成的对象是否合理。
3.1.3、Full GC 单次时间长 / Full GC 频率高
原因：
1、JVM参数设置不合理，尤其是新生代、老年代大小设置不合理，晋升阈值等
2、大对象创建，一次加载了过多数据到内存中（比如SQL查询未做分页），导致大对象进入了老年代
3、内存泄漏，大量对象引用没有释放
4、程序BUG、显示调用system.gc()等，触发Full GC
解决方案
1、检查新生代大小、晋升阈值是否过小，导致大量生命周期较短的对象进入老年代
2、检查老年代是否过小，导致内存不足承载存活的生命周期较长的对象
3、分析 HeapDump 文件，看业务代码生成的对象是否合理
4、指标
4.1、机器指标
4.1.1、icmp.ping.alive
icmp.ping.alive⬤ 值为1：表示机器可以
ping通，⬤ 值为0：表示机器不能
ping通(异常状态)；无法ping通时，可以理解为机器宕机。
4.1.2、cpu.idle
cpu.idle：cpu空闲百分比，该值越大代表系统cpu空闲。持续的低于10%，则需要关注**
4.1.2.1、cpu.idle可能性原因：
1、大批量的计算，大批量读写数据库
2、批量操作问题，因为IO导致cpu报警
3、QPS远大于当前负载
4、数据库慢SQL、缓存大 key 也会导致此现象
5、宿主机问题（如果多节点“流量”均衡，单独机器不定期CPU报警，堆栈内存无异常，则可怀疑此现象，直接置换即可）
4.1.2.1、解决
同
3.1.5内存泄露排查方案
4.2、GC 指标
4.2.1、指标
4.2.1.1、JVM GC 相关指标
| JVM GC 相关指标 | 描述 |
|---|---|
| jvm.gc.count | GC的次数 |
| jvm.gc.time | GC的时间，单位毫秒 |
| jvm.younggc.count | 年轻代GC的次数 ，包括的GC算法（Copy，ParNew，PS Scavenge，G1 Young Generation） |
| jvm.younggc.time | 年轻代GC的时间，单位毫秒 |
| jvm.younggc.meantime | 一分钟内的每次年轻带gc的平均时间 |
| jvm.fullgc.count | 年老代GC的次数 ，包括的GC算法（MarkSweepCompact，PS MarkSweep，ConcurrentMarkSweep，G1 Old Generation） |
| jvm.fullgc.time | 年老代GC的时间，单位毫秒 |
4.2.1.2、JVM 内存 相关指标
| JVM 内存 相关指标 | 描述 |
|---|---|
| jvm.memory.used | 内存使用总量 |
| jvm.memory.used.percent | 内存使用总量占比 |
| jvm.memory.nonheap.used | nonheap使用总量 |
| jvm.memory.nonheap.used.percent | nonheap使用总量占比 |
| jvm.memory.oldgen.used | oldgen使用总量 |
| jvm.memory.oldgen.used.percent | oldgen使用总量占比 |
| jvm.memory.oldgen.used.percent.after.fullgc | 触发fullgc之后使用oldgen的内存使用占比,此时基本剩下不可以回收对象 |
| jvm.memory.eden.used | eden使用总量 |
| jvm.memory.eden.used.percent | eden使用总量占比 |
| jvm.memory.survivor.used | survivor使用总量 |
| jvm.memory.survivor.used.percent | survivor使用总量占比 |
| jvm.memory.perm.used | perm使用总量 |
| jvm.memory.perm.used.percent | perm使用总量占比 |
| jvm.nio.directbuffer.used | directbuffer使用总量,这个一般是nio一些框架会用到 |
| jvm.nio.mapped.used | mapped使用总量，这个一般是使用java内存文件映射用到 |
4.2.1.3、JVM Thread 相关指标
| JVM Thread 相关指标 | 描述 |
|---|---|
| jvm.thread.blocked.count | blocked线程数 |
| jvm.thread.count | 线程 |
| jvm.thread.daemon.count | daemon线程数 |
| jvm.thread.deadlock.count | deadlock线程数 |
| jvm.thread.new.count | new线程数 |
| jvm.thread.runnable.count | runnable线程数 |
| jvm.thread.terminated.count | terminated线程数 |
| jvm.thread.time_waiting.count | time_waiting线程数 |
| jvm.thread.totalstarted.count | totalstarted线程数 |
| jvm.thread.waiting.count | waiting线程数 |
4.2.1.4、JVM 类加载 相关指标
| JVM 类加载 相关指标 | 描述 |
|---|---|
| jvm.classloading.totalloaded.count | jvm已经加载类的总数 |
| jvm.classloading.unloaded.count | jvm未加载类的总数 |
4.2.2、JVM GC 指标
4.2.2.1、jvm.younggc.time
年轻代
GC的时间，单位毫秒 ，一天中 平均在20ms， 最大101
