作者：木木匠 鏈接：
https://juejin.im/post/5e9725c1f265da47dc4cd8bd
概述
性能優化一向是後端服務優化的重點，但是線上性能故障問題不是經常出現，或者受限於業務產品，根本就沒辦法出現性能問題，包括筆者自己遇到的性能問題也不多，所以為了提前儲備知識，當出現問題的時候不會手忙腳亂，我們本篇文章來模擬下常見的幾個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即可。
<code> /**
* 模擬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;
}
}/<code>請求接口地址測試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一直不會被回收，最後就會發生內存洩漏。
<code>/**
* 模擬內存洩漏
*/
@GetMapping(value = "/memory/leak")
public String leak() {
System.out.println("模擬內存洩漏");
ThreadLocal localVariable = new ThreadLocal();
localVariable.set(new Byte[4096 * 1024]);// 為線程添加變量
return "ok";
}/<code>我們給啟動加上堆內存大小限制，同時設置內存溢出的時候輸出堆棧快照並輸出日誌。
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錯誤了。查看系統日誌出現瞭如下異常：
<code>java.lang.OutOfMemoryError: Java heap space/<code>
我們用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內存被耗盡，報無法創建線程的錯誤，這也是體現了使用線程池的好處。
<code> ExecutorService service = new ThreadPoolExecutor(4, 10,
0, TimeUnit.SECONDS, new LinkedBlockingQueue(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 ");
}
}
}
}/<code>我們循環請求接口2000次，發現不一會系統就出現了日誌錯誤，線程池和隊列都滿了,由於我選擇的當隊列滿了就拒絕的策略，所以系統直接拋出異常。
<code>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]/<code>
通過ps -ef|grep java命令找出 Java 進程 pid，執行jstack pid 即可出現java線程堆棧信息，這裡發現了5個死鎖，我們只列出其中一個，很明顯線程pool-1-thread-2鎖住了0x00000000f8387d88等待0x00000000f8387d98鎖，線程pool-1-thread-1鎖住了0x00000000f8387d98等待鎖0x00000000f8387d88,這就產生了死鎖。
<code>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./<code>線程頻繁切換
上下文切換會導致將大量CPU時間浪費在寄存器、內核棧以及虛擬內存的保存和恢復上，導致系統整體性能下降。當你發現系統的性能出現明顯的下降時候，需要考慮是否發生了大量的線程上下文切換。
<code> @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資源
}
}
}/<code>這裡我創建多個線程去執行基礎的原子+1操作，然後讓出 CPU 資源，理論上 CPU 就會去調度別的線程，我們請求接口創建100個線程看看效果如何，curl
localhost:8080/thread/swap?num=100。接口請求成功後，我們執行`vmstat 1 10，表示每1秒打印一次，打印10次，線程切換採集結果如下：
<code>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/<code>
這裡我們關注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吃滿的情況。
<code>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 /<code>
<code> 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 /<code>
結合上面用戶態CPU只使用了14%，內核態CPU佔用了86%，可以基本判斷是Java程序線程上下文切換導致性能問題。
我們使用pidstat命令來看看Java進程內部的線程切換數據，執行pidstat -p 87093 -w 1 10,採集數據如下：
<code>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/<code>
根據上面採集的信息，我們知道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%、內存洩漏、死鎖、線程頻繁切換問題。分析問題我們需要做好兩件事，第一，掌握基本的原理，第二，藉助好工具。本文也列舉了分析問題的常用工具和命令，希望對你解決問題有所幫助。當然真正的線上環境可能十分複雜，並沒有模擬的環境那麼簡單，但是原理是一樣的，問題的表現也是類似的，我們重點抓住原理，活學活用，相信複雜的線上問題也可以順利解決。
小福利
從正式成為一名程序員的那天起，註定要進行沒有止境的學習，堅持每天都高效的學習，私信回覆【666】送你
