JVM系列(二十) JVM调优实战-常用命令Jps/PS/Jinfo/Jstat实战

280 阅读9分钟

1.查看系统进程 JPS命令

JPS查看系统进程信息 28532 G1Test 表示进程Pid28532 的进程名字是G1Test

E:\setup\jar>jps
39024 Launcher
42832 Jps
22644
28532 G1Test
43020 RemoteMavenServer36
9756 Launcher

和我们程序的运行是保持一致的, 我们的程序名称就是G1Test

image.png

2.查看进程信息 ps -ef |grep xxx

Linux系统中,我们可以使用 ps命令来查看具体的进程信息

#查看系统 java 进程信息
ps -ef |grep java

#查看具体项目的进程信息
ps -ef |grep web-gateway

执行结果

[saas@dev-119 ~]$ ps -ef |grep web-gateway
saas      7039  5764  0 14:33 pts/0    00:00:00 grep --color=auto web-gateway
root     25030 25009  0 3月27 ?       00:00:00 /bin/bash /xxx/app/web-gateway/web-gateway.sh
root     25097 25030  3 3月27 ?       17:34:15 java -server 
-Dspring.profiles.active=docker 
-DskipTests -Dfile.encoding=UTF-8 
-Dsun.jnu.encoding=UTF-8 
-Duser.timezone=GMT+8 
-Djava.net.preferIPv6Addresses=false -agentlib:jdwp=transport=dt_socket,address=20112,server=y,suspend=n -Xms2g -Xmx2g -Ddubbo.registry.address=zoo1:2181,zoo2:2181 
-Dspring.cloud.nacos.config.namespace=xxx 
-Dsso-env=xxx 
-Dspring.cloud.nacos.discovery.group=xxx 
-DxxxUrl=https://sso119.devtest.vip 
-DxxxUrl=https://xxx 
-DxxxUrl=https://xxx 
-DxxxUrl=https://xxx 
-DxxxUrl=https://xxx 
-jar /xxx/web-gateway/web-gateway.jar

3.jinfo pid 命令查看进程信息

我们通过 jps 或者通过 ps-ef |grep xxx 都是为了找到进程信息,找到之后 有什么用 ? 我们可以通过进程信息,查看进程参数 jinfo命令

#查看进程详细参数, 执行 jinfo pid进程id
jinfo 36612

执行结果

E:\setup\jar>jinfo 36612
Attaching to process ID 36612, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.181-b13
Java System Properties:

java.runtime.name = Java(TM) SE Runtime Environment
java.vm.version = 25.181-b13
sun.boot.library.path = C:\xxxxx
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 =
sun.java.launcher = SUN_STANDARD
user.script =
user.country = CN
user.dir = E:xxxxx
java.vm.specification.name = Java Virtual Machine Specification
java.runtime.version = 1.8.0_181-b13
java.awt.graphicsenv = sun.awt.Win32GraphicsEnvironment
os.arch = amd64
java.endorsed.dirs = C:\xxxxx
line.separator =

java.io.tmpdir = C:\xxxxx
java.vm.specification.vendor = Oracle Corporation
user.variant =
os.name = Windows 10
sun.jnu.encoding = GBK
java.library.path = xxxxx
java.class.version = 52.0
sun.management.compiler = HotSpot 64-Bit Tiered Compilers
os.version = 10.0
user.home = C:\Users\jzj
user.timezone = Asia/Shanghai
java.awt.printerjob = sun.awt.windows.WPrinterJob
file.encoding = UTF-8
java.specification.version = 1.8
user.name = jzj
java.class.path =xxxxx
java.vm.specification.version = 1.8
sun.arch.data.model = 64
sun.java.command = com.jzj.jvmtest.jvmready.G1Test
java.home = C:\xxxxx
user.language = zh
java.specification.vendor = Oracle Corporation
awt.toolkit = sun.awt.windows.WToolkit
java.vm.info = mixed mode
java.version = 1.8.0_181
java.ext.dirs = xxxxx
file.separator = \
java.vendor.url.bug = http://bugreport.sun.com/bugreport/
sun.io.unicode.encoding = UnicodeLittle
sun.cpu.endian = little
sun.desktop = windows
sun.cpu.isalist = amd64

VM Flags:
Non-default VM flags: -XX:CICompilerCount=4 -XX:ConcGCThreads=3 -XX:G1HeapRegionSize=1048576 -XX:+HeapDumpOnOutOfMemoryError -XX:InitialHeapSize=10485760 -XX:MarkStackSize=4194304 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=6291456 -XX:MinHeapDeltaBytes=1048576 -XX:+PrintGC -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseG1GC -XX:-UseLargePagesIndividualAllocation

Command line:  -verbose:gc -XX:+UseG1GC -Xms10M -Xmx10M -XX:+PrintGC -XX:+PrintGCDetails -XX:+HeapDumpOnOutOfMemoryError -XX:SurvivorRatio=8 -javaagent:E:\Program Files\JetBrains\IntelliJ IDEA 2019.3.4\lib\idea_rt.jar=58937:E:\Program Files\JetBrains\IntelliJ IDEA 2019.3.4\bin -Dfile.encoding=UTF-8
3.1 系统变量

全部的java系统变量等等

  • java.version java版本
  • user.name 用户名字
  • user.timezone = Asia/Shanghai 时区信息
  • java.io.tmpdir = C:\xxxxx 临时文件存放路径
java.home = C:\xxxxx
user.language = zh
java.specification.vendor = Oracle Corporation
awt.toolkit = sun.awt.windows.WToolkit
java.vm.info = mixed mode
java.version = 1.8.0_181
java.ext.dirs = xxxxx
3.2 JVM参数

VM虚拟机参数 VM Flags

  • -XX:G1HeapRegionSize 每个Region的大小,单位MB,需要为1,2,4,8,16,32其一,默认是堆内存的1/2000
  • -XX:InitialHeapSize=10485760 等同于 -Xms设置,表示Heap的初始化大小,即JVM启动时,堆区的最小值
  • -XX:HeapDumpOnOutOfMemoryError 堆栈溢出打印OOM错误
  • -XX:MaxNewSize=6291456 JVM堆区域新生代内存的最大可分配大小(PermSize不属于堆区)
  • -XX:+UseG1GC 使用G1垃圾收集器
  • -XX:MinHeapDeltaBytes=1048576 表示当我们要扩容或者缩容的时候,决定是否要做或者尝试扩容的时候最小扩多少
  • -XX:+PrintGCDetails GC时候打印详情
  • -XX:SurvivorRatio=8 年轻到和survivor比例是 1:1:8 (s0:s1:Eden)
  • XX:MaxHeapSize=10485760 最大的堆内存分配
VM Flags:
Non-default VM flags: -XX:CICompilerCount=4 -XX:ConcGCThreads=3 -XX:G1HeapRegionSize=1048576 -XX:+HeapDumpOnOutOfMemoryError -XX:InitialHeapSize=10485760 -XX:MarkStackSize=4194304 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=6291456 -XX:MinHeapDeltaBytes=1048576 -XX:+PrintGC -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:+UseG1GC -XX:-UseLargePagesIndividualAllocation

4.jstat命令

jstat是JDK自带的轻量级小工具,专门用于监控JVM的GC情况,对Java应用程序的资源和性能进行实时的命令行的监控,包括了对Heap size和垃圾回收状况的监控,我们先看看有哪些命令可以使用

#执行 jstat options
E:\setup\jar>jstat -options
-class
-compiler
-gc
-gccapacity
-gccause
-gcmetacapacity
-gcnew
-gcnewcapacity
-gcold
-gcoldcapacity
-gcutil
-printcompilation

我们对命令进行结束

  • class 用于查看类加载情况的统计
  • compiler 用于查看HotSpot中即时编译器编译情况的统计
  • gc 用于查看JVM中堆的垃圾收集情况的统计经常使用
  • gccapacity 用于查看新生代、老生代及持久代的存储容量情况经常使用
  • gcmetacapacity 显示metaspace的大小及信息经常使用
  • gcnew 用于查看新生代垃圾收集的情况
  • gcnewcapacity 用于查看新生代存储容量的情况
  • gcold 用于查看老生代及持久代垃圾收集的情况
  • gcoldcapacity 用于查看老生代的容量
  • gcutil 显示垃圾回收信息经常使用
  • gccause 显示垃圾回收的相关信息(同-gcutil), 同时显示最后一次仅当前正在发生的垃圾收集的原因
  • printcompilation 输出JIT编译的方法信息

启动程序

@Slf4j
public class G1Test {

    //JVM 参数 -verbose:gc -Xms10M -Xmx10M  -XX:+PrintGC -XX:+PrintGCDetails -XX:+HeapDumpOnOutOfMemoryError -XX:SurvivorRatio=8
    public static void main(String[] args) throws Exception {
        byte[] b = null;
        for (int i = 1; i <= 20; i++) {
            //设置 3M的对象
            log.info("======== " + i + "次添加3M对象");
            b = new byte[2 * 1024 * 1024];
            Thread.sleep(3000);

        }
    }
}
4.1 jstat -gc pid 查看进程 GC情况

先执行 jps 找到进程PID G1Test PID是 25060

E:\setup\jar>jps
45616 Launcher
22644
25060 G1Test
44308 Jps

执行jstat -gc 25060

#执行 jstat -gc pid
E:\setup\jar>jstat -gc 25060
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
 0.0   1024.0  0.0   1024.0  3072.0    0.0      6144.0     5777.7   5504.0 5088.0 640.0  565.8       2    0.003   0      0.000    0.003
 
 #执行 jstat -gc pid 参数1(多少秒执行1次) 参数2 一共打印多少次
 #执行 jstat -gc 25060 1000  3 ,表示 1000ms执行1次, 一共执行 3次
 E:\setup\jar>jstat -gc 25060 1000 3
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
 0.0   1024.0  0.0   1024.0  3072.0    0.0      6144.0     5777.7   5504.0 5088.0 640.0  565.8       2    0.003   0      0.000    0.003
 0.0   1024.0  0.0   1024.0  3072.0    0.0      6144.0     5777.7   5504.0 5088.0 640.0  565.8       2    0.003   0      0.000    0.003
 0.0   1024.0  0.0   1024.0  3072.0    0.0      6144.0     5777.7   5504.0 5088.0 640.0  565.8       2    0.003   0      0.000    0.003

我们解释一下这些信息S0C/S1C/S0U等等代表什么意思

年轻代 幸存区S0/S1 及Eden区的使用情况(单位字节Byte)

S0CS1CS0US1UEUEC
年轻代幸存区From区S0的 容量Capacity年轻代幸存区To区S1的 容量Capacity年轻代幸存区From区S0已经使用Use的容量Capacity年轻代幸存区To区S1的 已经使用Use的容量Capacity年轻代Eden区的容量Capacity年轻代Eden区已经使用Used的容量Capacity

老年代Old区,元空间Metaspace及CCS(当前压缩类)的使用情况 (单位字节Byte)

OCOUMCMUCCSUCCSU
Old老年代 容量CapacityOld老年代已经使用Use的容量Capacity元空间Metaspace 容量Capacity元空间Metaspace已经使用Use的容量Capacity当前压缩类空间 容量Capacity当前压缩类空间已经使用Used的容量Capacity

YoungGC,FullGC发生的次数及花费的时间(秒/s)情况

YGCYGCTFGCFGCTGCT
从程序启动到采样,YoungGC 发生的次数从程序启动到采样,YoungGC 花费的时间从程序启动到采样,FullGC 发生的次数从程序启动到采样,FullGC 花费的时间从程序启动到采样,GC一共用时
4.2 jstat -gcutil pid 查看进程 GC垃圾回收情况

执行JPS找到进程PID G1Test PID 44788

E:\setup\jar>jps
22644
44788 G1Test
47492 Jps
35992 Launcher

执行 jstat -gcutil 44788 1000 10 查看垃圾回收情况 1000ms 打印一次, 一共打印10次

#执行 jstat -gcutil 44788 1000 10 
E:\setup\jar>jstat -gcutil 44788 1000 10
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
  0.00   0.00   0.00  65.24  94.24  89.56     20    0.081     4    0.037    0.118
  0.00   0.00   0.00  65.24  94.24  89.56     21    0.081     4    0.037    0.118
  0.00   0.00   0.00  65.35  94.24  89.56     21    0.092     4    0.037    0.129
  0.00   0.00   0.00  65.35  94.24  89.56     21    0.092     4    0.037    0.129
  0.00 100.00   0.00  31.89  94.24  89.56     23    0.100     5    0.037    0.137
  0.00   0.00   0.00  86.70  94.24  89.56     23    0.100     5    0.049    0.149
  0.00   0.00   0.00  86.70  94.24  89.56     23    0.100     5    0.049    0.149
  0.00 100.00   0.00  70.10  94.24  89.56     24    0.103     5    0.049    0.152
  0.00 100.00   0.00  70.10  94.24  89.56     24    0.103     5    0.049    0.152
  0.00 100.00   0.00  70.10  94.24  89.56     24    0.103     5    0.049    0.152

我们解释一下这些信息 S0/S/E/O/M/CCS/YGC/YGCT/FGC/FGCT/GCT 等代表什么意思

首先说明一点 这里打印出来的不是真实使用的容量Byte,而是为了方便查看,使用的是 百分比占比,更加直观,方便定位问题

S0S1EOMCCS
年轻代幸存区From区S0 已使用占当前容量的百分比年轻代幸存区From区S1 已使用占当前容量的百分比Eden区已经使用占当前容量的百分比Old老年代已经使用占当前容量的百分比元空间Metaspace已经使用占当前容量的百分比当前压缩类空间已经使用占当前容量的百分比

从上面可以看出来什么问题? 我们看下这两次打印

#执行 jstat -gcutil 44788 1000 10 
E:\setup\jar>jstat -gcutil 44788 1000 10
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT
  0.00   0.00   0.00  65.35  94.24  89.56     21    0.092     4    0.037    0.129
  0.00 100.00   0.00  31.89  94.24  89.56     23    0.100     5    0.037    0.137
  1. YGC从 21->23 说明1s之内发生了2次YoungGC,FGC从 4->5说明1s之内发生了1次FullGC
  2. YGC/FullGC后,S0区域开始向S1区域复制存活的对象,导致S1占比100%
  3. 说明YounGC后,需要复制的东西很多,从From转移到To区
  4. Old区从65%->31%, 老年代部分对象经历过FullGC后被销毁
  5. Metaspace 占比94.24% 元空间太小了,即将要占满
4.3 jstat -gccause pid 查看gc原因

执行JPS找到进程PID G1Test PID 44912

E:\setup\jar>jps
44912 G1Test
22644
37180 Launcher
46220 Jps

执行 jstat -gccause 44912 查看gc引起的原因

E:\setup\jar>jstat -gccause 44912
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT    LGCC                 GCC
  0.00   0.00   0.00  86.70  94.22  89.56     13    0.045     3    0.017    0.062 Allocation Failure   No GC
  • LGGC 最后一次GC的原因 Allocation Failure 内存分配失败导致
  • GCC 当前GC原因 No GC 为当前没有执行GC
E:\setup\jar>jstat -gccause 44912
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT    LGCC                 GCC
  0.00 100.00   0.00  70.07  94.22  89.56     19    0.066     4    0.023    0.089 G1 Humongous Allocation No GC
  • LGGC 最后一次GC的原因 G1 Humongous Allocation G1的大对象分配导致
  • GCC 当前GC原因 No GC 为当前没有执行GC

至此 我们学习了基本的JVM调优命令包括JPS查看进程,jinfo查看进程详细参数,Jstat查看JVM gc情况,特别是jstat的轻量级JVM调优小工具使用,我们根据具体的日志,来分析JVM产生GC的原因,进行JVM调优