手把手教你定位常見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的相關信息。下載地址能夠點擊這裏

模擬環境準備

基礎環境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 DeadLockThread(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 st101  0 128000 878384    908 468684    0    0     0     0 4071 8110498 14 86  0  0  0100  0 128000 878384    908 468684    0    0     0     0 4065 8312463 15 85  0  0  0100  0 128000 878384    908 468684    0    0     0     0 4107 8207718 14 87  0  0  0100  0 128000 878384    908 468684    0    0     0     0 4083 8410174 14 86  0  0  0100  0 128000 878384    908 468684    0    0     0     0 4083 8264377 14 86  0  0  0100  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  Command11:04:30 PM     0         -     87128      0.00     16.07  |__java11:04:30 PM     0         -     87129      0.00     15.60  |__java11:04:30 PM     0         -     87130      0.00     15.54  |__java11:04:30 PM     0         -     87131      0.00     15.60  |__java11:04:30 PM     0         -     87132      0.00     15.43  |__java11:04:30 PM     0         -     87133      0.00     16.02  |__java11:04:30 PM     0         -     87134      0.00     15.66  |__java11:04:30 PM     0         -     87135      0.00     15.23  |__java11:04:30 PM     0         -     87136      0.00     15.33  |__java11:04:30 PM     0         -     87137      0.00     16.04  |__java

根據上面採集的信息，咱們知道Java的線程每秒切換15次左右，正常狀況下，應該是個位數或者小數。結合這些信息咱們能夠判定Java線程開啓過多，致使頻繁上下文切換，從而影響了總體性能。

爲何系統的上下文切換是每秒800多萬，而 Java 進程中的某一個線程切換才15次左右？

系統上下文切換分爲三種狀況:

一、多任務：在多任務環境中，一個進程被切換出CPU，運行另一個進程，這裏會發生上下文切換。

二、中斷處理：發生中斷時，硬件會切換上下文。在vmstat命令中是in

三、用戶和內核模式切換：當操做系統中須要在用戶模式和內核模式之間進行轉換時，須要進行上下文切換,好比進行系統函數調用。

Linux 爲每一個 CPU 維護了一個就緒隊列，將活躍進程按照優先級和等待 CPU 的時間排序，而後選擇最須要 CPU 的進程，也就是優先級最高和等待 CPU 時間最長的進程來運行。也就是vmstat命令中的r。

那麼，進程在何時纔會被調度到 CPU 上運行呢？

• 進程執行完終止了，它以前使用的 CPU 會釋放出來，這時再從就緒隊列中拿一個新的進程來運行

• 爲了保證全部進程能夠獲得公平調度，CPU 時間被劃分爲一段段的時間片，這些時間片被輪流分配給各個進程。當某個進程時間片耗盡了就會被系統掛起，切換到其它等待 CPU 的進程運行。

• 進程在系統資源不足時，要等待資源知足後才能夠運行，這時進程也會被掛起，並由系統調度其它進程運行。

• 當進程經過睡眠函數 sleep 主動掛起時，也會從新調度。

• 當有優先級更高的進程運行時，爲了保證高優先級進程的運行，當前進程會被掛起，由高優先級進程來運行。

• 發生硬件中斷時，CPU 上的進程會被中斷掛起，轉而執行內核中的中斷服務程序。鄭州市不孕不育醫院：http://www.03913882333.com/

結合咱們以前的內容分析，阻塞的就緒隊列是100左右，而咱們的CPU只有4核，這部分緣由形成的上下文切換就可能會至關高，再加上中斷次數是4000左右和系統的函數調用等，整個系統的上下文切換到800萬也不足爲奇了。Java內部的線程切換才15次，是由於線程使用Thread.yield()來讓出CPU資源，可是CPU有可能繼續調度該線程，這個時候線程之間並無切換，這也是爲何內部的某個線程切換次數並非很是大的緣由。

總結

本文模擬了常見的性能問題場景，分析瞭如何定位CPU100%、內存泄漏、死鎖、線程頻繁切換問題。分析問題咱們須要作好兩件事，第一，掌握基本的原理，第二，藉助好工具。本文也列舉了分析問題的經常使用工具和命令，但願對你解決問題有所幫助。固然真正的線上環境可能十分複雜，並無模擬的環境那麼簡單，可是原理是同樣的，問題的表現也是相似的，咱們重點抓住原理，活學活用，相信複雜的線上問題也能夠順利解決。

看治不孕不育鄭州醫院哪家好:http://jbk.39.net/yiyuanfengcai/tsyl_zztjyy/991/