以一個例子來演示排查服務器cpu占用率過高的問題。
准備
將下面的代碼文件上傳到服務器上,然后使用javac編譯,並使用java命令將程序跑起來。
public class JStackCase {
public static void main(String[] args) { ExecutorService executor = Executors.newFixedThreadPool(5); executor.submit(new Task()); executor.submit(new Task()); } } class Task implements Runnable { @Override public void run() { synchronized (this) { calculate(); } } public void calculate() { int i = 0; while (true) { i++; } } }
顯然,這段程序會導致CPU占用率較高。接下來,我們進行問題排查。
1.定位進程
使用top命令查看cpu占用情況,默認按cpu使用率從高到低排序。我們發現pid為6624的進程占用了70%的cpu。
[root@localhost bin]# top PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 6624 root 20 0 2249296 18380 10704 S 70.0 1.8 6:00.17 java 6723 root 20 0 157716 2112 1472 R 5.0 0.2 0:00.03 top 1 root 20 0 193724 3608 1972 S 0.0 0.4 0:07.07 systemd 2 root 20 0 0 0 0 S 0.0 0.0 0:00.01 kthreadd 3 root 20 0 0 0 0 S 0.0 0.0 0:13.54 ksoftirqd/0 5 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kworker/0:0H 7 root rt 0 0 0 0 S 0.0 0.0 0:00.40 migration/0 8 root 20 0 0 0 0 S 0.0 0.0 0:00.00 rcu_bh 9 root 20 0 0 0 0 S 0.0 0.0 0:04.98 rcu_sched 10 root rt 0 0 0 0 S 0.0 0.0 0:04.42 watchdog/0 12 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kdevtmpfs 13 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 netns 14 root 20 0 0 0 0 S 0.0 0.0 0:00.00 khungtaskd 15 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 writeback 16 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kintegrityd 17 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 bioset 18 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kblockd 19 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 md 25 root 20 0 0 0 0 S 0.0 0.0 0:10.50 kswapd0 26 root 25 5 0 0 0 S 0.0 0.0 0:00.00 ksmd 27 root 39 19 0 0 0 S 0.0 0.0 0:00.21 khugepaged 28 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 crypto 36 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kthrotld 38 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kmpath_rdacd 39 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kpsmoused
2.定位線程
查看pid為6624的進程下的線程cpu占用情況。發現6634和6635線程幾乎占用了大部分的cpu。
[root@localhost bin]# top -Hp 6624
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 6634 root 20 0 2249296 16532 8852 R 49.8 1.7 6:34.75 java 6635 root 20 0 2249296 16532 8852 R 49.5 1.7 6:34.69 java 6624 root 20 0 2249296 16532 8852 S 0.0 1.7 0:00.04 java 6625 root 20 0 2249296 16532 8852 S 0.0 1.7 0:00.09 java 6626 root 20 0 2249296 16532 8852 S 0.0 1.7 0:00.01 java 6627 root 20 0 2249296 16532 8852 S 0.0 1.7 0:00.00 java 6628 root 20 0 2249296 16532 8852 S 0.0 1.7 0:00.00 java 6629 root 20 0 2249296 16532 8852 S 0.0 1.7 0:00.00 java 6630 root 20 0 2249296 16532 8852 S 0.0 1.7 0:00.00 java 6631 root 20 0 2249296 16532 8852 S 0.0 1.7 0:00.00 java 6632 root 20 0 2249296 16532 8852 S 0.0 1.7 0:00.00 java 6633 root 20 0 2249296 16532 8852 S 0.0 1.7 0:00.54 java
3.定位代碼
接下來jstack就要上場了。可以使用jstack -l [pid]查看線程的堆棧信息。
jstack -l [pid] //進程id
當然,我們可以過濾我們只關注的線程的轉儲信息。
將線程pid轉為16進制
因為thread id在棧信息中是以十六進制的形式顯示的,所以可以使用printf "%x \n" [pid]命令將線程pid轉為16進制。
[root@localhost bin]# printf "%x \n" 6634 19ea [root@localhost bin]# printf "%x \n" 6635 19eb
過濾19ea線程的堆棧信息,使用jstack -l <pid> | grep <thread-hex-id> -A 10。-A 10
參數用來指定顯示行數,否則只會顯示一行信息。
[root@localhost bin]# jstack -l 6624 | grep 19ea -A 10
"pool-1-thread-1" #8 prio=5 os_prio=0 tid=0x00007f22e00e4800 nid=0x19ea runnable [0x00007f22d0729000]
java.lang.Thread.State: RUNNABLE
at Task.calculate(JStackCase.java:26) at Task.run(JStackCase.java:19) - locked <0x00000000f0a60ff8> (a Task) 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:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748)
於是,定位到代碼JstackCase類中第26行,通過信息可知是線程池引起的cpu占用率過高的問題,接下來分析對應的代碼即可。
通常,在線上環境遠比這復雜,所以需要多次獲取線程堆棧信息,進行對比綜合分析。所以,僅僅單獨分析一個文件是可能並沒有太大意義的。
當然我們也可以使用其它的工具來排查問題,比如系統自帶的perf,Alibaba開源的工具Arthas等。