关于java:手把手教你定位常见Java性能问题

39次阅读

共计 10133 个字符，预计需要花费 26 分钟才能阅读完成。

概述

性能优化一贯是后端服务优化的重点，然而线上性能故障问题不是经常出现，或者受限于业务产品，基本就没方法呈现性能问题，包含笔者本人遇到的性能问题也不多，所以为了提前储备常识，当呈现问题的时候不会慌手慌脚，咱们本篇文章来模仿下常见的几个 Java 性能故障，来学习怎么去剖析和定位。

准备常识

既然是定位问题，必定是须要借助工具，咱们先理解下须要哪些工具能够帮忙定位问题。

top 命令

top命令使咱们最罕用的 Linux 命令之一，它能够实时的显示以后正在执行的过程的 CPU 使用率，内存使用率等零碎信息。top -Hp pid 能够查看线程的系统资源应用状况。

vmstat 命令

vmstat 是一个指定周期和采集次数的虚拟内存检测工具，能够统计内存，CPU，swap 的应用状况，它还有一个重要的罕用性能，用来察看过程的上下文切换。字段阐明如下:

  • r: 运行队列中过程数量（当数量大于 CPU 核数示意有阻塞的线程）
  • b: 期待 IO 的过程数量
  • swpd: 应用虚拟内存大小
  • free: 闲暇物理内存大小
  • buff: 用作缓冲的内存大小(内存和硬盘的缓冲区)
  • cache: 用作缓存的内存大小（CPU 和内存之间的缓冲区）
  • si: 每秒从替换区写到内存的大小，由磁盘调入内存
  • so: 每秒写入替换区的内存大小，由内存调入磁盘
  • bi: 每秒读取的块数
  • bo: 每秒写入的块数
  • in: 每秒中断数，包含时钟中断。
  • cs: 每秒上下文切换数。
  • us: 用户过程执行工夫百分比(user time)
  • sy: 内核零碎过程执行工夫百分比(system time)
  • wa: IO 等待时间百分比
  • id: 闲暇工夫百分比

    pidstat 命令

pidstat 是 Sysstat 中的一个组件，也是一款功能强大的性能监测工具，top 和 vmstat 两个命令都是监测过程的内存、CPU 以及 I/O 应用状况，而 pidstat 命令能够检测到线程级别的。pidstat命令线程切换字段阐明如下：

  • UID：被监控工作的实在用户 ID。
  • TGID：线程组 ID。
  • TID：线程 ID。
  • cswch/s：被动切换上下文次数，这里是因为资源阻塞而切换线程，比方锁期待等状况。
  • nvcswch/s：被动切换上下文次数，这里指 CPU 调度切换了线程。

    jstack 命令

jstack 是 JDK 工具命令，它是一种线程堆栈剖析工具，最罕用的性能就是应用 jstack pid 命令查看线程的堆栈信息，也常常用来排除死锁状况。

jstat 命令

它能够检测 Java 程序运行的实时状况，包含堆内存信息和垃圾回收信息，咱们经常用来查看程序垃圾回收状况。罕用的命令是jstat -gc pid。信息字段阐明如下：

  • S0C：年老代中 To Survivor 的容量（单位 KB）；
  • S1C：年老代中 From Survivor 的容量（单位 KB）；
  • S0U：年老代中 To Survivor 目前已应用空间（单位 KB）；
  • S1U：年老代中 From Survivor 目前已应用空间（单位 KB）；
  • EC：年老代中 Eden 的容量（单位 KB）；
  • EU：年老代中 Eden 目前已应用空间（单位 KB）；
  • OC：老年代的容量（单位 KB）；
  • OU：老年代目前已应用空间（单位 KB）；
  • MC：元空间的容量（单位 KB）；
  • MU：元空间目前已应用空间（单位 KB）；
  • YGC：从应用程序启动到采样时年老代中 gc 次数；
  • YGCT：从应用程序启动到采样时年老代中 gc 所用工夫 (s)；
  • FGC：从应用程序启动到采样时 老年代（Full Gc）gc 次数；
  • FGCT：从应用程序启动到采样时 老年代代（Full Gc）gc 所用工夫 (s)；
  • GCT：从应用程序启动到采样时 gc 用的总工夫 (s)。

jmap 命令

jmap 也是 JDK 工具命令，他能够查看堆内存的初始化信息以及堆内存的应用状况，还能够生成 dump 文件来进行详细分析。查看堆内存状况命令jmap -heap pid。

mat 内存工具

MAT(Memory Analyzer Tool)工具是 eclipse 的一个插件(MAT 也能够独自应用)，它剖析大内存的 dump 文件时，能够十分直观的看到各个对象在堆空间中所占用的内存大小、类实例数量、对象援用关系、利用 OQL 对象查问，以及能够很不便的找出对象 GC Roots 的相干信息。

idea 中也有这么一个插件，就是 JProfiler。

相干浏览：

  1. 《性能诊断利器 JProfiler 疾速入门和最佳实际》：https://segmentfault.com/a/1190000017795841

模仿环境筹备

根底环境 jdk1.8，采纳 SpringBoot 框架来写几个接口来触发模仿场景，首先是模仿 CPU 占满状况

CPU 占满

模仿 CPU 占满还是比较简单，间接写一个死循环计算耗费 CPU 即可。

     /**
     * 模仿 CPU 占满
     */
    @GetMapping("/cpu/loop")
    public void testCPULoop() throws InterruptedException {System.out.println("申请 cpu 死循环");
        Thread.currentThread().setName("loop-thread-cpu");
        int num = 0;
        while (true) {
            num++;
            if (num == Integer.MAX_VALUE) {System.out.println("reset");
            }
            num = 0;
        }

    }

申请接口地址测试curl localhost:8080/cpu/loop, 发现 CPU 立马飙升到 100%

通过执行top -Hp 32805 查看 Java 线程状况

执行 printf '%x' 32826 获取 16 进制的线程 id，用于 dump 信息查问，后果为 803a。最初咱们执行 jstack 32805 |grep -A 20 803a 来查看下具体的dump 信息。

这里 dump 信息间接定位出了问题办法以及代码行，这就定位出了 CPU 占满的问题。

内存泄露

模仿内存透露借助了 ThreadLocal 对象来实现，ThreadLocal 是一个线程公有变量，能够绑定到线程上，在整个线程的生命周期都会存在，然而因为 ThreadLocal 的特殊性，ThreadLocal 是基于 ThreadLocalMap 实现的，ThreadLocalMap 的 Entry 继承 WeakReference，而 Entry 的 Key 是 WeakReference 的封装，换句话说 Key 就是弱援用，弱援用在下次 GC 之后就会被回收，如果 ThreadLocal 在 set 之后不进行后续的操作，因为 GC 会把 Key 革除掉，然而 Value 因为线程还在存活，所以 Value 始终不会被回收，最初就会产生内存透露。

/**
     * 模仿内存透露
     */
    @GetMapping(value = "/memory/leak")
    public String leak() {System.out.println("模仿内存透露");
        ThreadLocal<Byte[]> localVariable = new ThreadLocal<Byte[]>();
        localVariable.set(new Byte[4096 * 1024]);// 为线程增加变量
        return "ok";
    }

咱们给启动加上堆内存大小限度，同时设置内存溢出的时候输入堆栈快照并输入日志。

java -jar -Xms500m -Xmx500m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp/heapdump.hprof -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:/tmp/heaplog.log analysis-demo-0.0.1-SNAPSHOT.jar

启动胜利后咱们循环执行 100 次,for i in {1..500}; do curl localhost:8080/memory/leak;done, 还没执行结束，零碎曾经返回 500 谬误了。查看系统日志呈现了如下异样：

java.lang.OutOfMemoryError: Java heap space

咱们用jstat -gc pid 命令来看看程序的 GC 状况。

很显著，内存溢出了，堆内存通过 45 次 Full Gc 之后都没开释出可用内存，这阐明以后堆内存中的对象都是存活的，有 GC Roots 援用，无奈回收。那是什么起因导致内存溢出呢？是不是我只有加大内存就行了呢？如果是一般的内存溢出兴许扩充内存就行了，然而如果是内存透露的话，扩充的内存不一会就会被占满，所以咱们还须要确定是不是内存透露。咱们之前保留了堆 Dump 文件，这个时候借助咱们的 MAT 工具来剖析下。导入工具抉择Leak Suspects Report，工具间接就会给你列出问题报告。

这里曾经列出了可疑的 4 个内存透露问题，咱们点击其中一个查看详情。

这里曾经指出了内存被线程占用了靠近 50M 的内存，占用的对象就是 ThreadLocal。如果想具体的通过手动去剖析的话，能够点击Histogram, 查看最大的对象占用是谁，而后再剖析它的援用关系，即可确定是谁导致的内存溢出。

上图发现占用内存最大的对象是一个 Byte 数组，咱们看看它到底被那个 GC Root 援用导致没有被回收。依照上图红框操作指引，后果如下图：

咱们发现 Byte 数组是被线程对象援用的，图中也表明，Byte 数组对像的 GC Root 是线程，所以它是不会被回收的，开展详细信息查看，咱们发现最终的内存占用对象是被 ThreadLocal 对象占据了。这也和 MAT 工具主动帮咱们剖析的后果统一。

死锁

死锁会导致耗尽线程资源，占用内存，体现就是内存占用升高，CPU 不肯定会飙升(看场景决定)，如果是间接 new 线程，会导致 JVM 内存被耗尽，报无奈创立线程的谬误，这也是体现了应用线程池的益处。

 ExecutorService service = new ThreadPoolExecutor(4, 10,
            0, TimeUnit.SECONDS, new LinkedBlockingQueue<Runnable>(1024),
            Executors.defaultThreadFactory(),
            new ThreadPoolExecutor.AbortPolicy());
   /**
     * 模仿死锁
     */
    @GetMapping("/cpu/test")
    public String testCPU() throws InterruptedException {System.out.println("申请 cpu");
        Object lock1 = new Object();
        Object lock2 = new Object();
        service.submit(new DeadLockThread(lock1, lock2), "deadLookThread-" + new Random().nextInt());
        service.submit(new DeadLockThread(lock2, lock1), "deadLookThread-" + new Random().nextInt());
        return "ok";
    }

public class DeadLockThread implements Runnable {
    private Object lock1;
    private Object lock2;

    public DeadLockThread1(Object lock1, Object lock2) {
        this.lock1 = lock1;
        this.lock2 = lock2;
    }

    @Override
    public void run() {synchronized (lock2) {System.out.println(Thread.currentThread().getName()+"get lock2 and wait lock1");
            try {TimeUnit.MILLISECONDS.sleep(2000);
            } catch (InterruptedException e) {e.printStackTrace();
            }
            synchronized (lock1) {System.out.println(Thread.currentThread().getName()+"get lock1 and lock2");
            }
        }
    }
}

咱们循环申请接口 2000 次，发现不一会零碎就呈现了日志谬误，线程池和队列都满了, 因为我抉择的当队列满了就回绝的策略，所以零碎间接抛出异样。

java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@2760298 rejected from java.util.concurrent.ThreadPoolExecutor@7ea7cd51[Running, pool size = 10, active threads = 10, queued tasks = 1024, completed tasks = 846]

通过 ps -ef|grep java 命令找出 Java 过程 pid，执行 jstack pid 即可呈现 java 线程堆栈信息，这里发现了 5 个死锁，咱们只列出其中一个，很显著线程pool-1-thread-2 锁住了 0x00000000f8387d88 期待 0x00000000f8387d98 锁，线程 pool-1-thread-1 锁住了 0x00000000f8387d98 期待锁0x00000000f8387d88, 这就产生了死锁。

Java stack information for the threads listed above:
===================================================
"pool-1-thread-2":
        at top.luozhou.analysisdemo.controller.DeadLockThread2.run(DeadLockThread.java:30)
        - waiting to lock <0x00000000f8387d98> (a java.lang.Object)
        - locked <0x00000000f8387d88> (a java.lang.Object)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
"pool-1-thread-1":
        at top.luozhou.analysisdemo.controller.DeadLockThread1.run(DeadLockThread.java:30)
        - waiting to lock <0x00000000f8387d88> (a java.lang.Object)
        - locked <0x00000000f8387d98> (a java.lang.Object)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

 Found 5 deadlocks.

线程频繁切换

上下文切换会导致将大量 CPU 工夫节约在寄存器、内核栈以及虚拟内存的保留和复原上，导致系统整体性能降落。当你发现零碎的性能呈现显著的降落时候，须要思考是否产生了大量的线程上下文切换。

 @GetMapping(value = "/thread/swap")
    public String theadSwap(int num) {System.out.println("模仿线程切换");
        for (int i = 0; i < num; i++) {new Thread(new ThreadSwap1(new AtomicInteger(0)),"thread-swap"+i).start();}
        return "ok";
    }
public class ThreadSwap1 implements Runnable {
    private AtomicInteger integer;

    public ThreadSwap1(AtomicInteger integer) {this.integer = integer;}

    @Override
    public void run() {while (true) {integer.addAndGet(1);
            Thread.yield(); // 让出 CPU 资源}
    }
}

这里我创立多个线程去执行根底的原子 + 1 操作，而后让出 CPU 资源，实践上 CPU 就会去调度别的线程，咱们申请接口创立 100 个线程看看成果如何，curl localhost:8080/thread/swap?num=100。接口申请胜利后，咱们执行 `vmstat 1 10，示意每 1 秒打印一次，打印 10 次，线程切换采集后果如下：

procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
101  0 128000 878384    908 468684    0    0     0     0 4071 8110498 14 86  0  0  0
100  0 128000 878384    908 468684    0    0     0     0 4065 8312463 15 85  0  0  0
100  0 128000 878384    908 468684    0    0     0     0 4107 8207718 14 87  0  0  0
100  0 128000 878384    908 468684    0    0     0     0 4083 8410174 14 86  0  0  0
100  0 128000 878384    908 468684    0    0     0     0 4083 8264377 14 86  0  0  0
100  0 128000 878384    908 468688    0    0     0   108 4182 8346826 14 86  0  0  0

这里咱们关注 4 个指标，r,cs,us,sy。

r=100, 阐明期待的过程数量是 100，线程有阻塞。

cs=800 多万，阐明每秒上下文切换了 800 多万次，这个数字相当大了。

us=14，阐明用户态占用了 14% 的 CPU 工夫片去解决逻辑。

sy=86，阐明内核态占用了 86% 的 CPU，这里显著就是做上下文切换工作了。

咱们通过 top 命令以及 top -Hp pid 查看过程和线程 CPU 状况，发现 Java 线程 CPU 占满了，然而线程 CPU 应用状况很均匀，没有某一个线程把 CPU 吃满的状况。

PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                            
 87093 root      20   0 4194788 299056  13252 S 399.7 16.1  65:34.67 java 
 PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND                                                                             
 87189 root      20   0 4194788 299056  13252 R  4.7 16.1   0:41.11 java                                                                                
 87129 root      20   0 4194788 299056  13252 R  4.3 16.1   0:41.14 java                                                                                
 87130 root      20   0 4194788 299056  13252 R  4.3 16.1   0:40.51 java                                                                                
 87133 root      20   0 4194788 299056  13252 R  4.3 16.1   0:40.59 java                                                                                
 87134 root      20   0 4194788 299056  13252 R  4.3 16.1   0:40.95 java

联合下面用户态 CPU 只应用了 14%，内核态 CPU 占用了 86%，能够根本判断是 Java 程序线程上下文切换导致性能问题。

咱们应用 pidstat 命令来看看 Java 过程外部的线程切换数据，执行pidstat -p 87093 -w 1 10 , 采集数据如下：

11:04:30 PM   UID       TGID       TID   cswch/s nvcswch/s  Command
11:04:30 PM     0         -     87128      0.00     16.07  |__java
11:04:30 PM     0         -     87129      0.00     15.60  |__java
11:04:30 PM     0         -     87130      0.00     15.54  |__java
11:04:30 PM     0         -     87131      0.00     15.60  |__java
11:04:30 PM     0         -     87132      0.00     15.43  |__java
11:04:30 PM     0         -     87133      0.00     16.02  |__java
11:04:30 PM     0         -     87134      0.00     15.66  |__java
11:04:30 PM     0         -     87135      0.00     15.23  |__java
11:04:30 PM     0         -     87136      0.00     15.33  |__java
11:04:30 PM     0         -     87137      0.00     16.04  |__java

依据下面采集的信息，咱们晓得 Java 的线程每秒切换 15 次左右，失常状况下，应该是个位数或者小数。联合这些信息咱们能够判定 Java 线程开启过多，导致频繁上下文切换，从而影响了整体性能。

为什么零碎的上下文切换是每秒 800 多万，而 Java 过程中的某一个线程切换才 15 次左右？

零碎上下文切换分为三种状况:

1、多任务：在多任务环境中，一个过程被切换出 CPU，运行另外一个过程，这里会产生上下文切换。

2、中断解决：产生中断时，硬件会切换上下文。在 vmstat 命令中是in

3、用户和内核模式切换：当操作系统中须要在用户模式和内核模式之间进行转换时，须要进行上下文切换, 比方进行零碎函数调用。

Linux 为每个 CPU 保护了一个就绪队列，将沉闷过程依照优先级和期待 CPU 的工夫排序，而后抉择最须要 CPU 的过程，也就是优先级最高和期待 CPU 工夫最长的过程来运行。也就是 vmstat 命令中的r。

那么，过程在什么时候才会被调度到 CPU 上运行呢？

  • 过程执行完终止了，它之前应用的 CPU 会释放出来，这时再从就绪队列中拿一个新的过程来运行
  • 为了保障所有过程能够失去偏心调度，CPU 工夫被划分为一段段的工夫片，这些工夫片被轮流调配给各个过程。当某个过程工夫片耗尽了就会被零碎挂起，切换到其它期待 CPU 的过程运行。
  • 过程在系统资源有余时，要期待资源满足后才能够运行，这时过程也会被挂起，并由系统调度其它过程运行。
  • 当过程通过睡眠函数 sleep 被动挂起时，也会从新调度。
  • 当有优先级更高的过程运行时，为了保障高优先级过程的运行，以后过程会被挂起，由高优先级过程来运行。
  • 产生硬件中断时，CPU 上的过程会被中断挂起，转而执行内核中的中断服务程序。

联合咱们之前的内容分析，阻塞的就绪队列是 100 左右，而咱们的 CPU 只有 4 核，这部分起因造成的上下文切换就可能会相当高，再加上中断次数是 4000 左右和零碎的函数调用等，整个零碎的上下文切换到 800 万也难能可贵了。Java 外部的线程切换才 15 次，是因为线程应用 Thread.yield() 来让出 CPU 资源，然而 CPU 有可能持续调度该线程，这个时候线程之间并没有切换，这也是为什么外部的某个线程切换次数并不是十分大的起因。

总结

本文模仿了常见的性能问题场景，剖析了如何定位 CPU100%、内存透露、死锁、线程频繁切换问题。剖析问题咱们须要做好两件事，第一，把握根本的原理，第二，借助好工具。本文也列举了剖析问题的常用工具和命令，心愿对你解决问题有所帮忙。当然真正的线上环境可能十分复杂，并没有模仿的环境那么简略，然而原理是一样的，问题的体现也是相似的，咱们重点抓住原理，活学活用，置信简单的线上问题也能够顺利解决。

参考

1、https://linux.die.net/man/1/pidstat

2、https://linux.die.net/man/8/vmstat

3、https://help.eclipse.org/2020-03/index.jsp?topic=/org.eclipse.mat.ui.help/welcome.html

4、https://www.linuxblogs.cn/articles/18120200.html

5、https://www.tutorialspoint.com/what-is-context-switching-in-operating-system

正文完
java
发表至： java
2020-12-19
 0
关于java:JAVA已过气Too-young-too-naive
关于java:一站式兼容所有云厂商文件存储Spring-Boot-实现
关于java:2020-Java开发者数据分析中国已成为-Java-第一大国
关于java:Kafka三消费者消费方式三种分区分配策略offset维护