后端接口性能优化分析-问题发现&问题定义（上）:https://developer.aliyun.com/article/1413664
3.链路追踪
有时候某个接口涉及的逻辑很多，比如：查数据库、查redis、远程调用接口，发mq消息，执行业务代码等等。
该接口一次请求的链路很长，如果逐一排查，需要花费大量的时间，这时候，我们已经没法用传统的办法定位问题了。
有没有办法解决这问题呢？
用分布式链路跟踪系统：skywalking。
通过skywalking定位性能问题：
在skywalking中可以通过traceId（全局唯一的id），串联一个接口请求的完整链路。可以看到整个接口的耗时，调用的远程服务的耗时，访问数据库或者redis的耗时等等，功能非常强大。
之前没有这个功能的时候，为了定位线上接口性能问题，我们还需要在代码中加日志，手动打印出链路中各个环节的耗时情况，然后再逐一排查。
问题排查
1.个别接口响应慢
链路追踪
使用SkyWalking，展示出每一个与网络有关的耗时。比如：读写数据库、读写Redis、SpringCloud调用、Dubbo调用等。这样就能立马定位是哪次操作耗时了。
同时，SkyWalking可以记录每一个SQL语句，可以帮助定位。
例如：（如箭头所指处，最上边一个是总耗时，下边的线段是单个操作的耗时）
在链路上打印日志
在相应的链路上打印日志，然后查看日志，看是哪个地方耗时。
死锁问题
在这里重点讲一下出现死锁问题的排查经验吧
有这样的情况：一个线程需要同时获取多把锁，这时就容易发生死锁
t1 线程 获得 A对象 锁，接下来想获取 B对象 的锁 t2 线程 获得 B对象 锁，接下来想获取 A对象 的锁
Object A = new Object(); Object B = new Object(); Thread t1 = new Thread(() -> { synchronized (A) { log.debug("lock A"); sleep(1); synchronized (B) { log.debug("lock B"); log.debug("操作..."); } } }, "t1"); Thread t2 = new Thread(() -> { synchronized (B) { log.debug("lock B"); sleep(0.5); synchronized (A) { log.debug("lock A"); log.debug("操作..."); } } }, "t2"); t1.start(); t2.start();
12:22:06.962 [t2] c.TestDeadLock - lock B 12:22:06.962 [t1] c.TestDeadLock - lock A
定位死锁
检测死锁可以使用 jconsole工具，或者使用 jps 定位进程 id，再用 jstack 定位死锁：
jps
cmd > jps Picked up JAVA_TOOL_OPTIONS: -Dfile.encoding=UTF-8 12320 Jps 22816 KotlinCompileDaemon 33200 TestDeadLock // JVM 进程 11508 Main 28468 Launcher
cmd > jstack 33200 Picked up JAVA_TOOL_OPTIONS: -Dfile.encoding=UTF-8 2018-12-29 05:51:40 Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.91-b14 mixed mode): "DestroyJavaVM" #13 prio=5 os_prio=0 tid=0x0000000003525000 nid=0x2f60 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Thread-1" #12 prio=5 os_prio=0 tid=0x000000001eb69000 nid=0xd40 waiting for monitor entry [0x000000001f54f000] java.lang.Thread.State: BLOCKED (on object monitor) at thread.TestDeadLock.lambda$main$1(TestDeadLock.java:28) - waiting to lock <0x000000076b5bf1c0> (a java.lang.Object) - locked <0x000000076b5bf1d0> (a java.lang.Object) at thread.TestDeadLock$$Lambda$2/883049899.run(Unknown Source) at java.lang.Thread.run(Thread.java:745) "Thread-0" #11 prio=5 os_prio=0 tid=0x000000001eb68800 nid=0x1b28 waiting for monitor entry [0x000000001f44f000] java.lang.Thread.State: BLOCKED (on object monitor) at thread.TestDeadLock.lambda$main$0(TestDeadLock.java:15) - waiting to lock <0x000000076b5bf1d0> (a java.lang.Object) - locked <0x000000076b5bf1c0> (a java.lang.Object) at thread.TestDeadLock$$Lambda$1/495053715.run(Unknown Source) at java.lang.Thread.run(Thread.java:745) // 略去部分输出 Found one Java-level deadlock: ============================= "Thread-1": waiting to lock monitor 0x000000000361d378 (object 0x000000076b5bf1c0, a java.lang.Object), which is held by "Thread-0" "Thread-0": waiting to lock monitor 0x000000000361e768 (object 0x000000076b5bf1d0, a java.lang.Object), which is held by "Thread-1" Java stack information for the threads listed above: =================================================== "Thread-1": at thread.TestDeadLock.lambda$main$1(TestDeadLock.java:28) - waiting to lock <0x000000076b5bf1c0> (a java.lang.Object) - locked <0x000000076b5bf1d0> (a java.lang.Object) at thread.TestDeadLock$$Lambda$2/883049899.run(Unknown Source) at java.lang.Thread.run(Thread.java:745) "Thread-0": at thread.TestDeadLock.lambda$main$0(TestDeadLock.java:15) - waiting to lock <0x000000076b5bf1d0> (a java.lang.Object) - locked <0x000000076b5bf1c0> (a java.lang.Object) at thread.TestDeadLock$$Lambda$1/495053715.run(Unknown Source) at java.lang.Thread.run(Thread.java:745) Found 1 deadlock
这里是两个线程 “Thread-0” 和 “Thread-1” 在互相等待对方释放锁，从而导致了死锁。
线程 “Thread-1” 试图获取对象0x000000076b5bf1c0的监视器锁（即synchronized关键字保护的那个对象），但是这个锁已经被线程 “Thread-0” 持有。因此，“Thread-1” 进入了等待状态，等待 “Thread-0” 释放这个锁。
同时，线程 “Thread-0” 试图获取对象0x000000076b5bf1d0的监视器锁，但是这个锁已经被线程 “Thread-1” 持有。因此，“Thread-0” 进入了等待状态，等待 “Thread-1” 释放这个锁。
jconsole
2.所有接口响应慢
如果线上出了问题，首先判断是业务问题还是整个系统的问题。如果是业务问题，就去看应用的日志等进行排查。如果出现了如下问题，就可能是整个系统的问题
- 大量接口都很慢
- 页面打不开
如何得知系统出问题了？
系统出问题时，我们需要进行详细排查，一般情况下，有以下场景我们可以得知线上出问题了：
- 用户反馈功能不能正常使用
- 监控系统的邮件或者短信提醒
系统问题排查步骤
以下按顺序进行
- 是否CPU占用过高
- 是否内存占用过高
- 是否磁盘占用过高
- 是否网络故障
- 查看后台日志
- 是否是数据库问题（比如：索引失效、死锁）
- 是否是垃圾回收导致
CPU占用过高
什么场景需要排查CPU占用？
- 访问接口的响应速度很慢。
- 系统崩溃无响应
- 压测时要查看CPU、内存、load、rt、qps等指标
步骤简述
- 定位进程 （命令：top）
- 定位线程 （命令：top -Hp 进程号）
- 定位代码位置 （命令：jstack）
排查方法详述
- 找到占CPU最高的进程。
- top命令，记下进程号（PID）。假设最高的是：1893
- 通过进程找到对应的线程。
- top -Hp 1893。假设最高的是：4519
- （因为Java是单进程多线程的）
- 通过线程定位到代码大概的位置信息。
- printf %x 4519。结果为：11a7
- jstack 1893 | grep 11a7 -A 30 –color
结果大概是这样的：
可能导致CPU使用率飙升的操作
- 无限循环的while
- 经常使用Young GC
- 频繁的GC
如果访问量很高，可能会导致频繁的GC甚至Full GC。当调用量很大时，内存分配将如此之快以至于GC线程将连续执行，这将导致CPU飙升。
- 序列化和反序列化
序列化和反序列化本身不会导致CPU使用率飙升。序列化是将对象转换为字节流的过程，而反序列化则是将字节流转换回对象的过程。这两个过程通常在内存中完成，并不直接导致CPU使用率的飙升。
然而，在某些情况下，序列化和反序列化可能会导致CPU使用率增加。例如，当需要大量的数据进行序列化或反序列化时，可能会消耗较多的CPU资源。此外，如果序列化和反序列化的操作频繁且耗时较长，也可能对CPU使用率产生一定影响。
- 正则表达式
正则表达式本身不会导致CPU飙升，但是使用不当或者复杂的正则表达式可能会导致CPU负载增加。
正则表达式在处理大量文本时，特别是复杂的表达式或者需要进行大量回溯的情况下，可能会消耗大量的 CPU 资源。这是因为正则表达式引擎需要在文本中进行搜索和匹配，并且有些复杂的规则可能需要大量的计算才能找到匹配的结果。
因此，在编写正则表达式时，需要注意避免过于复杂或低效的表达式，尤其是在处理大量文本的场景下。另外，对于一些需要频繁执行的操作，可以考虑在代码中进行优化，以减少对 CPU 的负载影响。
- 线程上下文切换
内存占用过高
步骤简述
定位Java程序内存使用过高或者内存泄漏的问题跟CPU也类似，可分为以下步骤：
- 定位进程 （命令：top）
- 定位线程 （命令：top -Hp 进程号）
- 定位代码位置 （命令：jmap生成快照，MAT / jprofiler / VisualVM / jhat 查看快照数据）
1.定位进程
- top
- 按下M（按内存占用由大到小排序）
- // 假设定位到的进程ID为14279。
2.定位线程
top -Hp 14279;
按下M（按内存占用由大到小排序）
top - 18:33:07 up 25 days, 7:48, 1 user, load average: 0.17, 0.27, 0.23 Threads: 54 total, 1 running, 53 sleeping, 0 stopped, 0 zombie %Cpu(s): 0.5 us, 0.7 sy, 0.0 ni, 98.8 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st KiB Mem : 8168236 total, 231696 free, 3660496 used, 4276044 buff/cache KiB Swap: 969964 total, 969964 free, 0 used. 4197860 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 14293 weiping 20 0 4508772 97036 18112 S 10 12 152:35.42 java 14279 weiping 20 0 4508772 97036 18112 S 5.0 1.2 0:00.00 java 14282 weiping 20 0 4508772 97036 18112 S 0.0 1.2 0:00.37 java
注意观察两点：
- 线程的数量
- 可以看到，它线程数是54（左上角的Threads项），属于正常。
- 若比较大（比如大于1000），要考虑是不是代码有问题：
是不是代码里手动起了多个线程。比如：使用OkHttpClient时每次都创建了连接池（ConnectionPool）；应该是只创建一个连接池的。
是不是自己创建的线程池最大个数太大了。
- 占内存大的线程的PID
- 如果线程数量正常，就要dump内存的快照信息来查看。
3.定位代码位置
如果是线上环境，注意dump之前必须先将流量切走，否则大内存dump是直接卡死服务。
dump当前快照：jmap -dump:format=b,file=dump.hprof 14279
查找实例数比较多的业务相关的实例，然后找到相应代码查看。（使用工具查看dump.hprof。比如：MAT、VisualVM、jhat）
磁盘问题
步骤简介
- 是否磁盘快用完了（命令：df、du）
- TPS是否正常（命令：iostat、vmstat、lsof）
这个命令是用来检查系统的磁盘性能是否正常。具体来说：
- iostat 命令用于报告 CPU 使用情况和磁盘I/O统计信息。
- vmstat 命令用于报告虚拟内存统计信息。
- lsof 命令用于列出打开文件。
通过使用这些命令，可以获得关于磁盘 I/O 活动、CPU 使用率、内存使用等方面的统计数据。其中，磁盘 I/O 统计信息中的 TPS（每秒传输的 I/O 操作数）可以用来评估磁盘的性能是否正常。如果 TPS 过高或者过低，可能意味着磁盘存在性能问题，需要进一步分析和解决。
网络问题
垃圾回收
什么情况下，GC会对程序产生影响？
不管Minor GC还是FGC，都会造成一定程度的程序卡顿（即Stop The World：GC线程开始工作，其他工作线程被挂起），即使采用ParNew、CMS或者G1这些更先进的垃圾回收算法，也只是在减少卡顿时间，而并不能完全消除卡顿。
那到底什么情况下，GC会对程序产生影响呢？根据严重程度从高到底，包括以下4种情况：
- FGC过于频繁
- FGC通常比较慢，少则几百毫秒，多则几秒，正常情况FGC每隔几个小时甚至几天才执行一次，对系统的影响还能接受。
- 一旦出现FGC频繁（比如几十分钟执行一次），是存在问题的，会导致工作线程频繁被停止，让系统看起来一直有卡顿现象，也会使得程序的整体性能变差。
- YGC耗时过长
a. 一般来说，YGC的总耗时在几十或者上百毫秒是比较正常的，虽然会引起系统卡顿几毫秒或者几十毫秒，这种情况几乎对用户无感知，对程序的影响可以忽略不计。
b. 如果YGC耗时达到了1秒甚至几秒（都快赶上FGC的耗时了），那卡顿时间就会增大，加上YGC本身比较频繁，就会导致比较多的服务超时问题。
- FGC耗时过长
- FGC耗时增加，卡顿时间也会随之增加，尤其对于高并发服务，可能导致FGC期间比较多的超时问题，可用性降低，这种也需要关注。
- YGC过于频繁
- 即使YGC不会引起服务超时，但是YGC过于频繁也会降低服务的整体性能，对于高并发服务也是需要关注的。
如何排查
- 公司的监控系统：大部分公司都会有，可全方位监控JVM的各项指标。
- JDK自带工具：jmap、jstat
- 查看堆内存各区域的使用率以及GC情况：jstat -gcutil pid 1000 （重点关注结果中的YGC、YGCT、FGC、FGCT、GCT）
b. 查看堆内存中的存活对象，并按空间排序：jmap -histo pid | head -n20
c. dump堆内存文件：jmap -dump:format=b,file=heap pid
