JVM 調優命令&工具使用

張伯毅發表於2020-02-14

 

top命令 檢視程式佔用資源情況

jps 命令 檢視 java程式

jstack 命令  關注 WATTING   檢視死鎖問題

jstat -gc pid  檢視 GC 情況

 jinfo  pid 檢視 jvm 常用資訊

arthas  [推薦]

安裝&啟動

使用 jmap 命令 [生產環境慎用! 會造成生產環境卡頓!!!!]

使用jvisualvm 進行檢視 dump 檔案[試驗用]

 


 

調優,從規劃開始

  • 調優,從業務場景開始,沒有業務場景的調優都是耍流氓

  • 無監控(壓力測試,能看到結果),不調優

  • 步驟:

    1. 熟悉業務場景(沒有最好的垃圾回收器,只有最合適的垃圾回收器)
      1. 響應時間、停頓時間 [CMS G1 ZGC] (需要給使用者作響應)
      2. 吞吐量 = 使用者時間 /( 使用者時間 + GC時間) [PS]
    2. 選擇回收器組合
    3. 計算記憶體需求(經驗值 1.5G 16G)
    4. 選定CPU(越高越好)
    5. 設定年代大小、升級年齡
    6. 設定日誌引數
      1. -Xloggc:/opt/xxx/logs/xxx-xxx-gc-%t.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=20M -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCCause
      2. 或者每天產生一個日誌檔案
    7. 觀察日誌情況

 

top命令 檢視程式佔用資源情況

Processes: 393 total, 2 running, 391 sleeping, 1727 threads                                                                   10:26:14
Load Avg: 3.60, 3.03, 2.80  CPU usage: 21.24% user, 14.8% sys, 64.67% idle   SharedLibs: 217M resident, 60M data, 39M linkedit.
MemRegions: 111000 total, 5331M resident, 158M private, 1972M shared. PhysMem: 16G used (2420M wired), 480M unused.
VM: 2005G vsize, 1297M framework vsize, 725056(0) swapins, 845477(0) swapouts. Networks: packets: 7278266/11G in, 5756934/4837M out.
Disks: 1039370/15G read, 2239416/30G written.

PID   COMMAND      %CPU TIME     #TH   #WQ  #PORT MEM    PURG   CMPRS  PGRP PPID STATE    BOOSTS          %CPU_ME %CPU_OTHRS UID
6738  top          3.9  00:00.70 1/1   0    25    4880K+ 0B     0B     6738 4188 running  *0[1]           0.00000 0.00000    0
6736  CFNetworkAge 0.0  00:00.10 3     2    43    10M    0B     0B     6736 1    sleeping *0[1]           0.00000 0.00000    0
6734  ocspd        0.0  00:00.02 2     1    31    1636K  0B     0B     6734 1    sleeping *0[1]           0.00000 0.00000    0
6731  backupd      0.0  00:00.04 2     1    42    1612K  0B     0B     6731 1    sleeping *0[1]           0.00000 0.00000    0
6730  VTDecoderXPC 0.0  00:00.55 2     1    50    5288K  0B     0B     6730 1    sleeping  0[43]          0.00000 0.00000    501
6710  CoreServices 0.0  00:00.20 3     1    164   4288K  0B     0B     6710 1    sleeping *0[1]           0.00000 0.00000    501
6708  Google Chrom 0.0  00:00.14 12    1    100   14M    4096B  0B     737  737  sleeping *0[7]           0.00000 0.00000    501
6707  Google Chrom 0.0  00:00.52 12    1    142   25M    4096B  0B     737  737  sleeping *0[5]           0.00000 0.00000    501
6705  Google Chrom 0.0  00:00.37 12    1    134   18M    4096B  0B     737  737  sleeping *0[6]           0.00000 0.00000    501
6703  Google Chrom 0.0  00:04.29 13    1    155   72M    4096B  0B     737  737  sleeping *0[5]           0.00000 0.00000    501

 

jps 命令 檢視 java程式

MacBook-Pro:~ sysadmin$ jps
6613 Launcher
6605 
6733 Jps

 

jstack 命令  關注 WATTING   檢視死鎖問題

MacBook-Pro:~ sysadmin$ jstack 6613
2020-02-10 10:24:35
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.161-b12 mixed mode):

"Attach Listener" #13 daemon prio=9 os_prio=31 tid=0x00007fb2d1869000 nid=0xb07 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"DestroyJavaVM" #12 prio=5 os_prio=31 tid=0x00007fb2cf2ea000 nid=0x2703 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"JPS event loop" #9 prio=5 os_prio=31 tid=0x00007fb2d01de000 nid=0x4703 runnable [0x000070000bc6e000]
   java.lang.Thread.State: RUNNABLE
	at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method)
	at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198)
	at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:117)
	at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
	- locked <0x00000007b57

 

jstat -gc pid  檢視 GC 情況

MacBook-Pro:~ sysadmin$ jstat -gc 6613
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT   
10752.0 10752.0  0.0   4405.1 65536.0  26391.4   175104.0    152.0    17152.0 16563.7 2048.0 1933.2      1    0.007   0      0.000    0.007

 

 jinfo  pid 檢視 jvm 常用資訊

 


[root@henghe-023 sbin]# jinfo 27519
Attaching to process ID 27519, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.151-b12
Java System Properties:

java.runtime.name = Java(TM) SE Runtime Environment
java.vm.version = 25.151-b12
sun.boot.library.path = /opt/jdk1.8/jre/lib/amd64
hadoop.root.logger = INFO,RFA
java.vendor.url = http://java.oracle.com/
java.vm.vendor = Oracle Corporation
path.separator = :
file.encoding.pkg = sun.io
java.vm.name = Java HotSpot(TM) 64-Bit Server VM
sun.os.patch.level = unknown
sun.java.launcher = SUN_STANDARD
user.country = CN
user.dir = /opt/hadoop-2.7.4
java.vm.specification.name = Java Virtual Machine Specification
hdfs.audit.logger = INFO,NullAppender
java.runtime.version = 1.8.0_151-b12
java.awt.graphicsenv = sun.awt.X11GraphicsEnvironment
os.arch = amd64
java.endorsed.dirs = /opt/jdk1.8/jre/lib/endorsed
line.separator = 

java.io.tmpdir = /tmp
hadoop.log.file = hadoop-root-namenode-henghe-023.log
java.vm.specification.vendor = Oracle Corporation
os.name = Linux
hadoop.id.str = root
sun.jnu.encoding = UTF-8
java.library.path = /usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
hadoop.home.dir = /opt/hadoop-2.7.4
java.specification.name = Java Platform API Specification
java.class.version = 52.0
java.net.preferIPv4Stack = true
proc_namenode = 
sun.management.compiler = HotSpot 64-Bit Tiered Compilers
os.version = 3.10.0-1062.4.3.el7.x86_64
user.home = /root
user.timezone = Asia/Shanghai
java.awt.printerjob = sun.print.PSPrinterJob
file.encoding = UTF-8
java.specification.version = 1.8
user.name = root
java.class.path = /opt/hadoop-2.7.4/etc/hadoop:************.jar
java.vm.specification.version = 1.8
sun.arch.data.model = 64
sun.java.command = org.apache.hadoop.hdfs.server.namenode.NameNode
java.home = /opt/jdk1.8/jre
user.language = zh
java.specification.vendor = Oracle Corporation
hadoop.security.logger = INFO,RFAS
awt.toolkit = sun.awt.X11.XToolkit
java.vm.info = mixed mode
hadoop.log.dir = /opt/hadoop-2.7.4/logs
java.version = 1.8.0_151
java.ext.dirs = /opt/jdk1.8/jre/lib/ext:/usr/java/packages/lib/ext
sun.boot.class.path = /opt/jdk1.8/jre/lib/resources.jar:/opt/jdk1.8/jre/lib/rt.jar:/opt/jdk1.8/jre/lib/sunrsasign.jar:/opt/jdk1.8/jre/lib/jsse.jar:/opt/jdk1.8/jre/lib/jce.jar:/opt/jdk1.8/jre/lib/charsets.jar:/opt/jdk1.8/jre/lib/jfr.jar:/opt/jdk1.8/jre/classes
java.vendor = Oracle Corporation
file.separator = /
java.vendor.url.bug = http://bugreport.sun.com/bugreport/
sun.io.unicode.encoding = UnicodeLittle
sun.cpu.endian = little
hadoop.policy.file = hadoop-policy.xml
sun.cpu.isalist = 

VM Flags:
Non-default VM flags: -XX:CICompilerCount=3 -XX:InitialHeapSize=9995026432 -XX:MaxHeapSize=9995026432 -XX:MaxNewSize=1073741824 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=1073741824 -XX:OldSize=8921284608 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseParallelGC 
Command line:  -Dproc_namenode -Xmx1000m -Djava.net.preferIPv4Stack=true -Dhadoop.log.dir=/opt/hadoop-2.7.4/logs -Dhadoop.log.file=hadoop.log -Dhadoop.home.dir=/opt/hadoop-2.7.4 -Dhadoop.id.str=root -Dhadoop.root.logger=INFO,console -Dhadoop.policy.file=hadoop-policy.xml -Djava.net.preferIPv4Stack=true -Djava.net.preferIPv4Stack=true -Djava.net.preferIPv4Stack=true -Dhadoop.log.dir=/opt/hadoop-2.7.4/logs -Dhadoop.log.file=hadoop-root-namenode-henghe-023.log -Dhadoop.home.dir=/opt/hadoop-2.7.4 -Dhadoop.id.str=root -Dhadoop.root.logger=INFO,RFA -Dhadoop.policy.file=hadoop-policy.xml -Djava.net.preferIPv4Stack=true -Xmx9531m -Xms9531m -Xmn1024m -Dhadoop.security.logger=INFO,RFAS -Dhdfs.audit.logger=INFO,NullAppender -Xmx9531m -Xms9531m -Xmn1024m -Dhadoop.security.logger=INFO,RFAS -Dhdfs.audit.logger=INFO,NullAppender -Xmx9531m -Xms9531m -Xmn1024m -Dhadoop.security.logger=INFO,RFAS -Dhdfs.audit.logger=INFO,NullAppender -Dhadoop.security.logger=INFO,RFAS

 

arthas  [推薦]

Arthas 是Alibaba開源的Java診斷工具.

 

安裝&啟動

curl -O https://alibaba.github.io/arthas/arthas-boot.jar
java -jar arthas-boot.jar

 

[root@henghe-023 data]# java -jar arthas-boot.jar 
[INFO] arthas-boot version: 3.1.7
[INFO] Found existing java process, please choose one and hit RETURN.
* [1]: 28443 org.apache.hadoop.hdfs.server.datanode.DataNode
  [2]: 27519 org.apache.hadoop.hdfs.server.namenode.NameNode
2
[INFO] arthas home: /root/.arthas/lib/3.1.7/arthas
[INFO] Try to attach process 27519
[INFO] Attach process 27519 success.
[INFO] arthas-client connect 127.0.0.1 3658
  ,---.  ,------. ,--------.,--.  ,--.  ,---.   ,---.                           
 /  O  \ |  .--. ''--.  .--'|  '--'  | /  O  \ '   .-'                          
|  .-.  ||  '--'.'   |  |   |  .--.  ||  .-.  |`.  `-.                          
|  | |  ||  |\  \    |  |   |  |  |  ||  | |  |.-'    |                         
`--' `--'`--' '--'   `--'   `--'  `--'`--' `--'`-----'                          
                                                                                

wiki      https://alibaba.github.io/arthas                                      
tutorials https://alibaba.github.io/arthas/arthas-tutorials                     
version   3.1.7                                                                 
pid       28443                                                                 
time      2020-02-10 10:46:37                                                   

[arthas@28443]$ 

安裝/使用參考官方文件: https://alibaba.github.io/arthas/install-detail.html

 

[arthas@14804]$ dashboard
ID        NAME                         GROUP               PRIORITY  STATE     %CPU      TIME     INTERRUPT DAEMON    
20        pool-1-thread-12             main                5         WAITING   4         0:0      false     false     
27        pool-1-thread-19             main                5         WAITING   4         0:0      false     false     
10        pool-1-thread-2              main                5         WAITING   3         0:0      false     false     
50        pool-1-thread-42             main                5         WAITING   3         0:0      false     false     
19        pool-1-thread-11             main                5         WAITING   2         0:0      false     false     
22        pool-1-thread-14             main                5         WAITING   2         0:0      false     false     
24        pool-1-thread-16             main                5         WAITING   2         0:0      false     false     
25        pool-1-thread-17             main                5         WAITING   2         0:0      false     false     
28        pool-1-thread-20             main                5         WAITING   2         0:0      false     false     
33        pool-1-thread-25             main                5         WAITING   2         0:0      false     false     
39        pool-1-thread-31             main                5         WAITING   2         0:0      false     false     
41        pool-1-thread-33             main                5         WAITING   2         0:0      false     false     
44        pool-1-thread-36             main                5         WAITING   2         0:0      false     false     
45        pool-1-thread-37             main                5         WAITING   2         0:0      false     false     
54        pool-1-thread-46             main                5         WAITING   2         0:0      false     false     
57        pool-1-thread-49             main                5         WAITING   2         0:0      false     false     
13        pool-1-thread-5              main                5         WAITING   2         0:0      false     false     
58        pool-1-thread-50             main                5         WAITING   2         0:0      false     false     
Memory                   used     total   max      usage   GC                                                         
heap                     63M      89M     89M      71.18%  gc.ps_scavenge.count          17                           
ps_eden_space            5M       11M     11M      51.41%  gc.ps_scavenge.time(ms)       232                          
ps_survivor_space        3M       11M     11M      28.69%  gc.ps_marksweep.count         0                            
ps_old_gen               54M      67M     67M      81.52%  gc.ps_marksweep.time(ms)      0                            
nonheap                  19M      20M     -1       95.94%                                                             
code_cache               4M       4M      240M     1.79%                                                              
metaspace                13M      14M     -1       97.40%                                                             
compressed_class_space   1M       1M      1024M    0.16%                                                              
                                                                                                                      
Runtime                                                                                                               
os.name                                                    Linux                                                      
os.version                                                 3.10.0-1062.4.3.el7.x86_64                                 
java.version                                               1.8.0_151                                                  
java.home                                                  /opt/jdk1.8/jre                                            
systemload.average                                         0.60                                                       
processors                                                 6                                                          
uptime                                                     182s                                                       
                                                                                                                      
                                                                                                                      
ID        NAME                         GROUP               PRIORITY  STATE     %CPU      TIME     INTERRUPT DAEMON    
57        pool-1-thread-49             main                5         WAITING   8         0:0      false     false     
10        pool-1-thread-2              main                5         WAITING   5         0:0      false     false     
22        pool-1-thread-14             main                5         TIMED_WAI 3         0:0      false     false     
45        pool-1-thread-37             main                5         WAITING   2         0:0      false     false     
54        pool-1-thread-46             main                5         WAITING   2         0:0      false     false     
16        pool-1-thread-8              main                5         WAITING   2         0:0      false     false     
73        Timer-for-arthas-dashboard-6 system              10        RUNNABLE  1         0:0      false     true      
9         pool-1-thread-1              main                5         WAITING   1         0:0      false     false     
18        pool-1-thread-10             main                5         WAITING   1         0:0      false     false     
19        pool-1-thread-11             main                5         WAITING   1         0:0      false     false     
20        pool-1-thread-12             main                5         WAITING   1         0:0      false     false     
21        pool-1-thread-13             main                5         WAITING   1         0:0      false     false     
23        pool-1-thread-15             main                5         WAITING   1         0:0      false     false     
24        pool-1-thread-16             main                5         WAITING   1         0:0      false     false     
25        pool-1-thread-17             main                5         WAITING   1         0:0      false     false     
26        pool-1-thread-18             main                5         WAITING   1         0:0      false     false     
27        pool-1-thread-19             main                5         WAITING   1         0:0      false     false     
28        pool-1-thread-20             main                5         WAITING   1         0:0      false     false     
Memory                   used     total   max      usage   GC                                                         
heap                     68M      89M     89M      76.85%  gc.ps_scavenge.count          17                           
ps_eden_space            10M      11M     11M      96.60%  gc.ps_scavenge.time(ms)       232                          
ps_survivor_space        3M       11M     11M      28.69%  gc.ps_marksweep.count         0                            
ps_old_gen               54M      67M     67M      81.52%  gc.ps_marksweep.time(ms)      0                            
nonheap                  20M      21M     -1       95.65%                                                             
code_cache               4M       4M      240M     1.87%                                                              
metaspace                13M      14M     -1       95.72%                                                             
compressed_class_space   1M       1M      1024M    0.17%                                                              
                                                                                                                      
Runtime                                                                                                               
os.name                                                    Linux                                                      
os.version                                                 3.10.0-1062.4.3.el7.x86_64                                 
java.version                                               1.8.0_151                                                  
java.home                                                  /opt/jdk1.8/jre                                            
systemload.average                                         0.55                                                       
processors                                                 6                                                          
uptime                                                     187s   

 

使用 jmap 命令 [生產環境慎用! 會造成生產環境卡頓!!!!]

jmap -histo  $PID   | head -50          檢視類物件

示例:


[root@henghe-023 arthas]# jmap -histo 23893 | head -50

 num     #instances         #bytes  class name
----------------------------------------------
   1:        381601       27475272  java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask
   2:        506262       16200384  java.util.concurrent.locks.AbstractQueuedSynchronizer$Node
   3:        381626       15265040  java.math.BigDecimal
   4:        381600       12211200  com.zl.gc.T15_FullGC_Problem01$CardInfo
   5:        381612        9158688  java.util.Date
   6:        381602        9158448  java.util.concurrent.Executors$RunnableAdapter
   7:        381600        6105600  com.zl.gc.T15_FullGC_Problem01$$Lambda$2/245257410
   8:        131012        4192384  java.util.HashMap$Node
   9:          2470        4135208  [B
  10:         36531        2892152  [Ljava.lang.Object;
  11:             3        2662808  [Ljava.util.concurrent.RunnableScheduledFuture;
  12:         53790        2048256  [C
  13:         14342        1669984  [I
  14:         53552        1285248  java.lang.String
  15:          2355        1134592  [Ljava.util.HashMap$Node;
  16:         33494         803856  java.util.ArrayList
  17:         31471         755304  io.termd.core.term.Feature
  18:         30539         488624  io.termd.core.term.OpCode$Literal
  19:         26476         423616  io.termd.core.term.Sequence
  20:          2710         306568  java.lang.Class
  21:          5178         207120  java.util.LinkedHashMap$Entry
  22:          1575         138600  java.lang.reflect.Method
  23:           156         102336  io.netty.util.internal.shaded.org.jctools.queues.MpscArrayQueue
  24:            28          98816  [Ljava.nio.channels.SelectionKey;
  25:          1887          90576  java.util.HashMap
  26:          2700          86400  com.taobao.text.Style$Composite
  27:          2647          84704  io.termd.core.term.OpCode$Printf
  28:          4643          74288  io.termd.core.term.OpCode$PushParam
  29:          1629          52128  io.termd.core.term.Device
  30:          1795          43064  [Ljava.lang.Class;
  31:          1314          42048  io.termd.core.term.Capability
  32:           443          40336  [Ljava.lang.String;
  33:          1169          37408  io.termd.core.term.TermInfoBuilder$Entry
  34:           645          36120  java.util.LinkedHashMap
  35:           475          34200  java.lang.reflect.Field
  36:          1397          33528  io.termd.core.term.OpCode$PushConstant
  37:          1327          31848  io.termd.core.term.OpCode$If
  38:          1327          31848  io.termd.core.term.OpCode$Then
  39:           492          27552  java.util.zip.ZipFile$ZipFileInflaterInputStream
  40:           492          27552  java.util.zip.ZipFile$ZipFileInputStream
  41:            48          27264  io.netty.util.internal.shaded.org.jctools.queues.MpscUnboundedArrayQueue
  42:           667          26680  java.util.ArrayList$SubList
  43:           819          26208  java.util.concurrent.ConcurrentHashMap$Node
  44:           612          24480  java.lang.ref.Finalizer
  45:            59          22184  java.lang.Thread
  46:            10          17120  [Lio.netty.buffer.PoolSubpage;
  47:           383          15320  java.lang.ref.SoftReference
[root@henghe-023 arthas]# 

jmap -dump:format=b,file=20200210.hprof   $PID         將記憶體資訊生成檔案,進行分析 [jhat, jvisualvm,mat]

[root@henghe-023 arthas]# jmap -dump:format=b,file=20200210.hprof 23893
Dumping heap to /data/arthas/20200210.hprof ...
Heap dump file created

 

使用jvisualvm 進行檢視 dump 檔案[試驗用]

/Library/java/JavaVirtualMachines/jdk1.8.0_161.jdk/Contents/Home/bin/jvisualvm

 

JVM 日誌設定

-Xloggc:/opt/xxx/logs/xxx-xxx-gc-%t.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=20M -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCCause

 

-Xloggc:/opt/xxx/logs/xxx-gc-%t.log // GC 檔案路徑
-XX:+UseGCLogFileRotation           // 啟用 GC日誌滾動記錄功能
-XX:NumberOfGCLogFiles=5            // 生成 GC 檔案數量
-XX:GCLogFileSize=20M               // 單個 GC 檔案大小
-XX:+PrintGCDetails                 // 列印 GC 詳情
-XX:+PrintGCDateStamps              // 列印 GC 時間戳
-XX:+PrintGCCause                   // 列印 GC 產生原因                

 


 


 

物件建立流程

 

 

CMS GC 過程
 

初始標記和重新標記要 觸發 STW

 

 

 

 

 

 

 

 

 

相關文章