概述
性能優(yōu)化一向是后端服務(wù)優(yōu)化的重點，但是線上性能故障問題不是經(jīng)常出現(xiàn)，或者受限于業(yè)務(wù)產(chǎn)品鞋邑，根本就沒辦法出現(xiàn)性能問題，包括筆者自己遇到的性能問題也不多账蓉，所以為了提前儲備知識枚碗，當出現(xiàn)問題的時候不會手忙腳亂，我們本篇文章來模擬下常見的幾個Java性能故障铸本，來學習怎么去分析和定位肮雨。
預(yù)備知識
既然是定位問題，肯定是需要借助工具箱玷，我們先了解下需要哪些工具可以幫忙定位問題怨规。
top命令
top命令使我們最常用的Linux命令之一，它可以實時的顯示當前正在執(zhí)行的進程的CPU使用率锡足，內(nèi)存使用率等系統(tǒng)信息波丰。top -Hp pid 可以查看線程的系統(tǒng)資源使用情況。
vmstat命令
vmstat是一個指定周期和采集次數(shù)的虛擬內(nèi)存檢測工具舶得，可以統(tǒng)計內(nèi)存呀舔，CPU，swap的使用情況扩灯，它還有一個重要的常用功能媚赖，用來觀察進程的上下文切換。字段說明如下:
r: 運行隊列中進程數(shù)量（當數(shù)量大于CPU核數(shù)表示有阻塞的線程）
b: 等待IO的進程數(shù)量
swpd: 使用虛擬內(nèi)存大小
free: 空閑物理內(nèi)存大小
buff: 用作緩沖的內(nèi)存大小(內(nèi)存和硬盤的緩沖區(qū))
cache: 用作緩存的內(nèi)存大兄椴濉（CPU和內(nèi)存之間的緩沖區(qū)）
si: 每秒從交換區(qū)寫到內(nèi)存的大小惧磺，由磁盤調(diào)入內(nèi)存
so: 每秒寫入交換區(qū)的內(nèi)存大小，由內(nèi)存調(diào)入磁盤
bi: 每秒讀取的塊數(shù)
bo: 每秒寫入的塊數(shù)
in: 每秒中斷數(shù)捻撑，包括時鐘中斷磨隘。
cs: 每秒上下文切換數(shù)缤底。
us: 用戶進程執(zhí)行時間百分比(user time)
sy: 內(nèi)核系統(tǒng)進程執(zhí)行時間百分比(system time)
wa: IO等待時間百分比
-
id: 空閑時間百分比
pidstat命令
pidstat 是 Sysstat 中的一個組件，也是一款功能強大的性能監(jiān)測工具番捂，top 和 vmstat 兩個命令都是監(jiān)測進程的內(nèi)存个唧、CPU 以及 I/O 使用情況，而 pidstat 命令可以檢測到線程級別的设预。pidstat命令線程切換字段說明如下：
UID ：被監(jiān)控任務(wù)的真實用戶ID徙歼。
TGID ：線程組ID。
TID：線程ID鳖枕。
cswch/s：主動切換上下文次數(shù)魄梯，這里是因為資源阻塞而切換線程，比如鎖等待等情況宾符。
-
nvcswch/s：被動切換上下文次數(shù)酿秸，這里指CPU調(diào)度切換了線程。
jstack命令
jstack是JDK工具命令魏烫，它是一種線程堆棧分析工具辣苏，最常用的功能就是使用 jstack pid 命令查看線程的堆棧信息，也經(jīng)常用來排除死鎖情況哄褒。
jstat 命令
它可以檢測Java程序運行的實時情況考润，包括堆內(nèi)存信息和垃圾回收信息，我們常常用來查看程序垃圾回收情況读处。常用的命令是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：從應(yīng)用程序啟動到采樣時年輕代中 gc 次數(shù)碧囊；
YGCT：從應(yīng)用程序啟動到采樣時年輕代中 gc 所用時間 (s)；
FGC：從應(yīng)用程序啟動到采樣時 老年代（Full Gc）gc 次數(shù)纤怒；
FGCT：從應(yīng)用程序啟動到采樣時 老年代代（Full Gc）gc 所用時間 (s)糯而；
GCT：從應(yīng)用程序啟動到采樣時 gc 用的總時間 (s)。
jmap命令
jmap也是JDK工具命令泊窘，他可以查看堆內(nèi)存的初始化信息以及堆內(nèi)存的使用情況熄驼，還可以生成dump文件來進行詳細分析像寒。查看堆內(nèi)存情況命令jmap -heap pid。
mat內(nèi)存工具
MAT(Memory Analyzer Tool)工具是eclipse的一個插件(MAT也可以單獨使用)瓜贾，它分析大內(nèi)存的dump文件時诺祸，可以非常直觀的看到各個對象在堆空間中所占用的內(nèi)存大小、類實例數(shù)量祭芦、對象引用關(guān)系筷笨、利用OQL對象查詢，以及可以很方便的找出對象GC Roots的相關(guān)信息实束。
idea中也有這么一個插件奥秆，就是JProfiler。
相關(guān)閱讀：
- 《性能診斷利器 JProfiler 快速入門和最佳實踐》：https://segmentfault.com/a/1190000017795841
模擬環(huán)境準備
基礎(chǔ)環(huán)境jdk1.8咸灿，采用SpringBoot框架來寫幾個接口來觸發(fā)模擬場景构订，首先是模擬CPU占滿情況
CPU占滿
模擬CPU占滿還是比較簡單，直接寫一個死循環(huán)計算消耗CPU即可避矢。
/**
* 模擬CPU占滿
*/
@GetMapping("/cpu/loop")
public void testCPULoop() throws InterruptedException {
System.out.println("請求cpu死循環(huán)");
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,發(fā)現(xiàn)CPU立馬飆升到100%
通過執(zhí)行top -Hp 32805 查看Java線程情況
執(zhí)行 printf '%x' 32826 獲取16進制的線程id悼瘾，用于dump信息查詢，結(jié)果為 803a审胸。最后我們執(zhí)行jstack 32805 |grep -A 20 803a 來查看下詳細的dump信息亥宿。
這里dump信息直接定位出了問題方法以及代碼行，這就定位出了CPU占滿的問題砂沛。
內(nèi)存泄露
模擬內(nèi)存泄漏借助了ThreadLocal對象來完成烫扼，ThreadLocal是一個線程私有變量，可以綁定到線程上碍庵，在整個線程的生命周期都會存在映企，但是由于ThreadLocal的特殊性，ThreadLocal是基于ThreadLocalMap實現(xiàn)的静浴，ThreadLocalMap的Entry繼承WeakReference堰氓，而Entry的Key是WeakReference的封裝，換句話說Key就是弱引用苹享，弱引用在下次GC之后就會被回收双絮，如果ThreadLocal在set之后不進行后續(xù)的操作，因為GC會把Key清除掉得问，但是Value由于線程還在存活囤攀，所以Value一直不會被回收，最后就會發(fā)生內(nèi)存泄漏宫纬。
/**
* 模擬內(nèi)存泄漏
*/
@GetMapping(value = "/memory/leak")
public String leak() {
System.out.println("模擬內(nèi)存泄漏");
ThreadLocal<Byte[]> localVariable = new ThreadLocal<Byte[]>();
localVariable.set(new Byte[4096 * 1024]);// 為線程添加變量
return "ok";
}
我們給啟動加上堆內(nèi)存大小限制抚岗，同時設(shè)置內(nèi)存溢出的時候輸出堆棧快照并輸出日志哪怔。
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
啟動成功后我們循環(huán)執(zhí)行100次,for i in {1..500}; do curl localhost:8080/memory/leak;done,還沒執(zhí)行完畢宣蔚，系統(tǒng)已經(jīng)返回500錯誤了向抢。查看系統(tǒng)日志出現(xiàn)了如下異常：
java.lang.OutOfMemoryError: Java heap space
我們用jstat -gc pid 命令來看看程序的GC情況。
很明顯胚委，內(nèi)存溢出了挟鸠，堆內(nèi)存經(jīng)過45次 Full Gc 之后都沒釋放出可用內(nèi)存，這說明當前堆內(nèi)存中的對象都是存活的亩冬，有GC Roots引用艘希，無法回收。那是什么原因?qū)е聝?nèi)存溢出呢硅急？是不是我只要加大內(nèi)存就行了呢覆享？如果是普通的內(nèi)存溢出也許擴大內(nèi)存就行了，但是如果是內(nèi)存泄漏的話营袜，擴大的內(nèi)存不一會就會被占滿撒顿，所以我們還需要確定是不是內(nèi)存泄漏。我們之前保存了堆 Dump 文件荚板，這個時候借助我們的MAT工具來分析下凤壁。導入工具選擇Leak Suspects Report，工具直接就會給你列出問題報告跪另。
這里已經(jīng)列出了可疑的4個內(nèi)存泄漏問題拧抖，我們點擊其中一個查看詳情。
這里已經(jīng)指出了內(nèi)存被線程占用了接近50M的內(nèi)存免绿，占用的對象就是ThreadLocal唧席。如果想詳細的通過手動去分析的話，可以點擊Histogram,查看最大的對象占用是誰嘲驾，然后再分析它的引用關(guān)系淌哟，即可確定是誰導致的內(nèi)存溢出。
上圖發(fā)現(xiàn)占用內(nèi)存最大的對象是一個Byte數(shù)組距淫，我們看看它到底被那個GC Root引用導致沒有被回收。按照上圖紅框操作指引婶希，結(jié)果如下圖：
我們發(fā)現(xiàn)Byte數(shù)組是被線程對象引用的榕暇，圖中也標明，Byte數(shù)組對像的GC Root是線程喻杈，所以它是不會被回收的彤枢，展開詳細信息查看，我們發(fā)現(xiàn)最終的內(nèi)存占用對象是被ThreadLocal對象占據(jù)了筒饰。這也和MAT工具自動幫我們分析的結(jié)果一致缴啡。
死鎖
死鎖會導致耗盡線程資源，占用內(nèi)存瓷们，表現(xiàn)就是內(nèi)存占用升高业栅，CPU不一定會飆升(看場景決定)秒咐，如果是直接new線程，會導致JVM內(nèi)存被耗盡碘裕，報無法創(chuàng)建線程的錯誤携取，這也是體現(xiàn)了使用線程池的好處。
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 ");
}
}
}
}
我們循環(huán)請求接口2000次帮孔，發(fā)現(xiàn)不一會系統(tǒng)就出現(xiàn)了日志錯誤雷滋，線程池和隊列都滿了,由于我選擇的當隊列滿了就拒絕的策略，所以系統(tǒng)直接拋出異常文兢。
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晤斩，執(zhí)行jstack pid 即可出現(xiàn)java線程堆棧信息，這里發(fā)現(xiàn)了5個死鎖姆坚，我們只列出其中一個澳泵，很明顯線程pool-1-thread-2鎖住了0x00000000f8387d88等待0x00000000f8387d98鎖，線程pool-1-thread-1鎖住了0x00000000f8387d98等待鎖0x00000000f8387d88,這就產(chǎn)生了死鎖旷偿。
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時間浪費在寄存器烹俗、內(nèi)核棧以及虛擬內(nèi)存的保存和恢復上，導致系統(tǒng)整體性能下降萍程。當你發(fā)現(xiàn)系統(tǒng)的性能出現(xiàn)明顯的下降時候幢妄，需要考慮是否發(fā)生了大量的線程上下文切換。
@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資源
}
}
}
這里我創(chuàng)建多個線程去執(zhí)行基礎(chǔ)的原子+1操作茫负，然后讓出 CPU 資源蕉鸳，理論上 CPU 就會去調(diào)度別的線程，我們請求接口創(chuàng)建100個線程看看效果如何忍法，curl localhost:8080/thread/swap?num=100潮尝。接口請求成功后，我們執(zhí)行`vmstat 1 10饿序，表示每1秒打印一次勉失，打印10次，線程切換采集結(jié)果如下：
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
這里我們關(guān)注4個指標原探，r,cs,us,sy乱凿。
r=100,說明等待的進程數(shù)量是100，線程有阻塞咽弦。
cs=800多萬徒蟆，說明每秒上下文切換了800多萬次，這個數(shù)字相當大了型型。
us=14段审，說明用戶態(tài)占用了14%的CPU時間片去處理邏輯。
sy=86闹蒜，說明內(nèi)核態(tài)占用了86%的CPU寺枉，這里明顯就是做上下文切換工作了抑淫。
我們通過top命令以及top -Hp pid查看進程和線程CPU情況，發(fā)現(xiàn)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
結(jié)合上面用戶態(tài)CPU只使用了14%甘畅，內(nèi)核態(tài)CPU占用了86%埂蕊，可以基本判斷是Java程序線程上下文切換導致性能問題。
我們使用pidstat命令來看看Java進程內(nèi)部的線程切換數(shù)據(jù)疏唾，執(zhí)行pidstat -p 87093 -w 1 10 ,采集數(shù)據(jù)如下：
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
根據(jù)上面采集的信息蓄氧，我們知道Java的線程每秒切換15次左右，正常情況下槐脏，應(yīng)該是個位數(shù)或者小數(shù)喉童。結(jié)合這些信息我們可以斷定Java線程開啟過多，導致頻繁上下文切換顿天，從而影響了整體性能堂氯。
為什么系統(tǒng)的上下文切換是每秒800多萬，而 Java 進程中的某一個線程切換才15次左右牌废？
系統(tǒng)上下文切換分為三種情況:
1咽白、多任務(wù)：在多任務(wù)環(huán)境中，一個進程被切換出CPU鸟缕，運行另外一個進程晶框，這里會發(fā)生上下文切換。
2懂从、中斷處理：發(fā)生中斷時授段，硬件會切換上下文。在vmstat命令中是in
3番甩、用戶和內(nèi)核模式切換：當操作系統(tǒng)中需要在用戶模式和內(nèi)核模式之間進行轉(zhuǎn)換時侵贵，需要進行上下文切換,比如進行系統(tǒng)函數(shù)調(diào)用。
Linux 為每個 CPU 維護了一個就緒隊列缘薛，將活躍進程按照優(yōu)先級和等待 CPU 的時間排序窍育，然后選擇最需要 CPU 的進程，也就是優(yōu)先級最高和等待 CPU 時間最長的進程來運行掩宜。也就是vmstat命令中的r蔫骂。
那么么翰，進程在什么時候才會被調(diào)度到 CPU 上運行呢牺汤？
- 進程執(zhí)行完終止了，它之前使用的 CPU 會釋放出來浩嫌，這時再從就緒隊列中拿一個新的進程來運行
- 為了保證所有進程可以得到公平調(diào)度檐迟，CPU 時間被劃分為一段段的時間片补胚，這些時間片被輪流分配給各個進程。當某個進程時間片耗盡了就會被系統(tǒng)掛起追迟，切換到其它等待 CPU 的進程運行溶其。
- 進程在系統(tǒng)資源不足時，要等待資源滿足后才可以運行敦间，這時進程也會被掛起瓶逃，并由系統(tǒng)調(diào)度其它進程運行。
- 當進程通過睡眠函數(shù) sleep 主動掛起時廓块，也會重新調(diào)度厢绝。
- 當有優(yōu)先級更高的進程運行時，為了保證高優(yōu)先級進程的運行带猴，當前進程會被掛起昔汉，由高優(yōu)先級進程來運行。
- 發(fā)生硬件中斷時拴清，CPU 上的進程會被中斷掛起靶病，轉(zhuǎn)而執(zhí)行內(nèi)核中的中斷服務(wù)程序。
結(jié)合我們之前的內(nèi)容分析口予，阻塞的就緒隊列是100左右娄周，而我們的CPU只有4核，這部分原因造成的上下文切換就可能會相當高苹威，再加上中斷次數(shù)是4000左右和系統(tǒng)的函數(shù)調(diào)用等昆咽，整個系統(tǒng)的上下文切換到800萬也不足為奇了。Java內(nèi)部的線程切換才15次牙甫，是因為線程使用Thread.yield()來讓出CPU資源掷酗，但是CPU有可能繼續(xù)調(diào)度該線程，這個時候線程之間并沒有切換窟哺，這也是為什么內(nèi)部的某個線程切換次數(shù)并不是非常大的原因泻轰。
總結(jié)
本文模擬了常見的性能問題場景，分析了如何定位CPU100%且轨、內(nèi)存泄漏浮声、死鎖、線程頻繁切換問題旋奢。分析問題我們需要做好兩件事泳挥，第一，掌握基本的原理至朗，第二屉符，借助好工具。本文也列舉了分析問題的常用工具和命令，希望對你解決問題有所幫助矗钟。當然真正的線上環(huán)境可能十分復雜唆香，并沒有模擬的環(huán)境那么簡單，但是原理是一樣的吨艇，問題的表現(xiàn)也是類似的躬它，我們重點抓住原理，活學活用东涡，相信復雜的線上問題也可以順利解決冯吓。
參考
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
