手把手教你定位常見Java性能問題-有解無憂

概述

性能優化一向是后端服務優化的重點，但是線上性能故障問題不是經常出現，或者受限于業務產品，根本就沒辦法出現性能問題，包括筆者自己遇到的性能問題也不多，所以為了提前儲備知識，當出現問題的時候不會手忙腳亂，我們本篇文章來模擬下常見的幾個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，

模擬環境準備

基礎環境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 = "https://www.cnblogs.com/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 = "https://www.cnblogs.com/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

作者：snailclimb
鏈接：手把手教你定位常見Java性能問題
來源：gitee

轉載請註明出處，本文鏈接：https://www.uj5u.com/houduan/237411.html

標籤：Java

上一篇：Flutter InkWell - Flutter每周一組件

下一篇：java字串常用方法