后端接口性能优化分析-问题发现&问题定义（上）: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

后端接口性能优化分析-问题发现&问题定义（下）