JAVA定位CPU佔用率高

1、top命令定位cpu佔用率高的進程號（pid），找到pid後，top -p pid -H,記錄出cpu佔用率高的線程號（tid），用printf "%x\n" tid將其轉換爲16進制

2、使用jstack打印進程信息，爲準肯定位能夠多來幾回，jstack pid > pid_1.log

3、打開日誌文件，找到十六進制的線程信息，可定位到具體類的某一行。

 

示例

一、

 1 Tasks: 546 total,   1 running, 544 sleeping,   0 stopped,   1 zombie
 2 Cpu(s): 15.3%us,  0.1%sy,  0.0%ni, 84.7%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
 3 Mem:  24633804k total, 23710152k used,   923652k free,   784472k buffers
 4 Swap: 32764556k total,   127120k used, 32637436k free,  7000668k cached
 5 
 6   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                                                                                       
 7 25930 weblogic  18   0 5311m 4.5g  29m S 488.1 19.3  35663:17 java                                                                                                                                                                          
 8 16830 weblogic  15   0 13168 1472  824 R  0.7  0.0   0:00.04 top                                                                                                                                                                            
 9 13834 weblogic  16   0 13028 1424  812 S  0.3  0.0   5900:50 top                                                                                                                                                                            
10 17263 weblogic  23   0 2410m 1.5g  28m S  0.3  6.2 390:24.31 java                                                                                                                                                                           
11 17438 weblogic  25   0 3429m 1.7g  25m S  0.3  7.2 217:35.39 java                                                                                                                                                                           
12 26316 weblogic  23   0 4695m 2.5g  29m S  0.3 10.8  31:47.38 java                                                                                                                                                                           
13     1 root      15   0 10372  600  568 S  0.0  0.0   2:12.76 init                                                                                                                                                                           
14     2 root      RT  -5     0    0    0 S  0.0  0.0  22:18.89 migration/0                                                                                                                                                                    
15     3 root      34  19     0    0    0 S  0.0  0.0   2:38.19 ksoftirqd/0                                                                                                                                                                    
16     4 root      RT  -5     0    0    0 S  0.0  0.0   0:00.00 watchdog/0                                                                                                                                                                     
17     5 root      RT  -5     0    0    0 S  0.0  0.0  19:16.83 migration/1                                                                                                                                                                    
18     6 root      34  19     0    0    0 S  0.0  0.0   6:37.27 ksoftirqd/1                                                                                                                                                                    
19     7 root      RT  -5     0    0    0 S  0.0  0.0   0:00.00 watchdog/1                                                                                                                                                                     
20     8 root      RT  -5     0    0    0 S  0.0  0.0  11:11.42 migration/2                                                                                                                                                                    
21     9 root      34  19     0    0    0 S  0.0  0.0   6:59.29 ksoftirqd/2                                                                                                                                                                    
22    10 root      RT  -5     0    0    0 S  0.0  0.0   0:00.00 watchdog/2                                                                                                                                                                     
23    11 root      RT  -5     0    0    0 S  0.0  0.0   5:36.90 migration/3                                                                                                                                                              

進程號 爲25930的java進程cpu使用率很高，top -p 25930  -H

 1 Tasks: 220 total,   1 running, 219 sleeping,   0 stopped,   0 zombie
 2 Cpu(s):  8.7%us,  0.1%sy,  0.0%ni, 91.2%id,  0.0%wa,  0.0%hi,  0.1%si,  0.0%st
 3 Mem:  24633804k total, 23712492k used,   921312k free,   784472k buffers
 4 Swap: 32764556k total,   127120k used, 32637436k free,  7000868k cached
 5 
 6   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                                                                                                                       
 7 25960 weblogic  15   0 5311m 4.5g  29m S 51.9 19.3   5615:15 java                                                                                                                                                                           
 8 25941 weblogic  16   0 5311m 4.5g  29m S 15.0 19.3 798:46.36 java                                                                                                                                                                           
 9 25939 weblogic  15   0 5311m 4.5g  29m S 11.3 19.3 798:26.28 java                                                                                                                                                                           
10 25951 weblogic  15   0 5311m 4.5g  29m S 11.3 19.3 799:05.00 java                                                                                                                                                                           
11 25936 weblogic  15   0 5311m 4.5g  29m S 11.0 19.3 799:14.41 java                                                                                                                                                                           
12 25937 weblogic  15   0 5311m 4.5g  29m S 11.0 19.3 798:37.65 java                                                                                                                                                                           
13 25943 weblogic  15   0 5311m 4.5g  29m S 11.0 19.3 799:30.19 java                                                                                                                                                                           
14 25944 weblogic  15   0 5311m 4.5g  29m S 11.0 19.3 799:58.25 java                                                                                                                                                                           
15 25945 weblogic  15   0 5311m 4.5g  29m S 11.0 19.3 798:56.29 java                                                                                                                                                                           

tid爲25960的線程cpu使用率很高。

1 [weblogic@shtpeb2b2eapp01 adminserver]$ printf "%x\n" 25960
2 6568

二、使用jstack打印進程信息並導入日誌文件

jstack 25930 >25930_1.log

jstack 25930 >25930_2.log

jstack 25930 >25930_3.log

三、查看相關日誌信息

 1 [weblogic@shtpeb2b2eapp01 bin]$ grep -A 10 0x6568 25930_1.log 
 2 "Concurrent Mark-Sweep GC Thread" prio=10 tid=0x0000000048b59000 nid=0x6568 runnable 
 3 "Gang worker#0 (Parallel CMS Threads)" prio=10 tid=0x0000000048b4f000 nid=0x6563 runnable 
 4 
 5 "Gang worker#1 (Parallel CMS Threads)" prio=10 tid=0x0000000048b51000 nid=0x6564 runnable 
 6 
 7 "Gang worker#2 (Parallel CMS Threads)" prio=10 tid=0x0000000048b53000 nid=0x6565 runnable 
 8 
 9 "Gang worker#3 (Parallel CMS Threads)" prio=10 tid=0x0000000048b54800 nid=0x6566 runnable 
10 
11 "Gang worker#4 (Parallel CMS Threads)" prio=10 tid=0x0000000048b56800 nid=0x6567 runnable 
12 
13 [weblogic@shtpeb2b2eapp01 bin]$ grep -A 10 0x6568 25930_2.log 
14 "Concurrent Mark-Sweep GC Thread" prio=10 tid=0x0000000048b59000 nid=0x6568 runnable 
15 "Gang worker#0 (Parallel CMS Threads)" prio=10 tid=0x0000000048b4f000 nid=0x6563 runnable 
16 
17 "Gang worker#1 (Parallel CMS Threads)" prio=10 tid=0x0000000048b51000 nid=0x6564 runnable 
18 
19 "Gang worker#2 (Parallel CMS Threads)" prio=10 tid=0x0000000048b53000 nid=0x6565 runnable 
20 
21 "Gang worker#3 (Parallel CMS Threads)" prio=10 tid=0x0000000048b54800 nid=0x6566 runnable 
22 
23 "Gang worker#4 (Parallel CMS Threads)" prio=10 tid=0x0000000048b56800 nid=0x6567 runnable 

從輸出信息來看，此線程是JVM的GC線程，此時能夠基本肯定是內存不足或內存泄露致使gc線程持續運行，致使CPU佔用太高。
因此接下來咱們要找的內存方面的問題。

 1 [weblogic@shtpeb2b2eapp01 bin]$ jstat -gcutil 25930 2000 10
 2   S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT   
 3   0.00   0.00  94.78 100.00  87.22   1035   92.722 251436 158050.083 158142.805
 4   0.00   0.00  94.78 100.00  87.22   1035   92.722 251437 158050.083 158142.805
 5   0.00   0.00  94.78 100.00  87.22   1035   92.722 251438 158051.345 158144.067
 6   0.00   0.00  94.79 100.00  87.22   1035   92.722 251438 158052.279 158145.001
 7   0.00   0.00  94.79 100.00  87.22   1035   92.722 251439 158052.279 158145.001
 8   0.00   0.00  94.79 100.00  87.22   1035   92.722 251440 158053.553 158146.275
 9   0.00   0.00  94.79 100.00  87.22   1035   92.722 251440 158054.475 158147.197
10   0.00   0.00  94.79 100.00  87.22   1035   92.722 251441 158054.475 158147.197
11   0.00   0.00  94.79 100.00  87.22   1035   92.722 251441 158055.753 158148.475

從輸出信息能夠看出，Eden區內存佔用95%，Old區內存佔用100%，根據這些信息，基本能夠肯定是程序代碼上出現了問題，可能存在不合理建立對象的地方。

使用文檔編輯器打開日誌

 

 發現大量的線程等待以及被鎖住的資源，而後丟給相關開發同事