概述 性能優化一向是後端服務優化的重點,但是線上性能故障問題不是經常出現,或者受限於業務產品,根本就沒辦法出現性能問題,包括筆者自己遇到的性能問題也不多,所以為了提前儲備知識,當出現問題的時候不會手忙腳亂,我們本篇文章來模擬下常見的幾個Java性能故障,來學習怎麼去分析和定位。 另外要註意:光理論是 ...
概述
性能優化一向是後端服務優化的重點,但是線上性能故障問題不是經常出現,或者受限於業務產品,根本就沒辦法出現性能問題,包括筆者自己遇到的性能問題也不多,所以為了提前儲備知識,當出現問題的時候不會手忙腳亂,我們本篇文章來模擬下常見的幾個Java性能故障,來學習怎麼去分析和定位。
另外要註意:光理論是不夠的,Java架構項目經驗永遠是核心,如果你沒有最新JAVA架構實戰教程及大廠30k+面試寶典,可以去小編的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 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有可能繼續調度該線程,這個時候線程之間並沒有切換,這也是為什麼內部的某個線程切換次數並不是非常大的原因。
總結註意:光理論是不夠的,Java架構項目經驗永遠是核心,如果你沒有最新JAVA架構實戰教程及大廠30k+面試寶典,可以去小編的Java架構學習.裙 :七吧傘吧零而衣零傘 (數字的諧音)轉換下可以找到了,裡面很多新JAVA架構項目教程,還可以跟老司機交流討教!
本文模擬了常見的性能問題場景,分析瞭如何定位CPU100%、記憶體泄漏、死鎖、線程頻繁切換問題。分析問題我們需要做好兩件事,第一,掌握基本的原理,第二,藉助好工具。本文也列舉了分析問題的常用工具和命令,希望對你解決問題有所幫助。當然真正的線上環境可能十分複雜,並沒有模擬的環境那麼簡單,但是原理是一樣的,問題的表現也是類似的,我們重點抓住原理,活學活用,相信複雜的線上問題也可以順利解決。
本文的文字及圖片來源於網路加上自己的想法,僅供學習、交流使用,不具有任何商業用途,版權歸原作者所有,如有問題請及時聯繫我們以作處理