JVM学习四（JVM调优工具详解）

爬台阶的蚂蚁

已于 2023-11-16 21:42:41 修改

阅读量263

点赞数

分类专栏： JVM 文章标签： jvm 学习 java

于 2022-12-27 08:56:23 首次发布

本文链接：https://blog.csdn.net/qq_45003354/article/details/128451330

版权

JVM 专栏收录该内容

5 篇文章 0 订阅

订阅专栏

前言：jvm调优主要是为了减少程序出现的full gc让程序变得更加稳定。

一、jmap:此命令可以用来查看内存信息，实例个数以及占用内存大小

jmap -histo 8484#查看历史生成的实例
jmap -histo:live 8484#查看当前存活的实例，执行过程中可能会触发一次full gc

1.查看当前运行程序生成的实例个数。
在这里插入图片描述
2.堆内存dump

jmap -dump:format=b,file=aa.hprof 8484

在这里插入图片描述
也可以设置程序启动的jvm参数内存溢出自动导出dump文件(内存很大的时候，可能会导不出来)

-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=./   （路径）

二、Jstack

1.用jstack加进程id查找死锁

jstack 8484

2.jstack找出占用cpu最高的线程堆栈信息

使用命令top -p ，显示你的java进程的内存情况，pid是你的java进程号，比如8484
按H，获取每个线程的内存情况
找到内存和cpu占用最高的线程tid，比如19664
将线程id转为十六进制得到 0x4cd0，此为线程id的十六进制表示
执行 jstack 8484|grep -A 10 4cd0，得到线程堆栈信息中 4cd0 这个线程所在行的后面10行，从堆栈中可以发现导致cpu飙高的调用方法

三、Jinfo

1.查看正在运行的Java应用程序的扩展参数

jinfo -flags 8484

在这里插入图片描述
2.查看java系统参数

jinfo -sysprops 8484

在这里插入图片描述

四、Jstat

1.jstat命令可以查看堆内存各部分的使用量，以及加载类的数量。命令的格式如下：
jstat [-命令选项] [vmid] [间隔时间(毫秒)] [查询次数]

2.垃圾回收统计，可以评估程序内存使用及GC压力整体情况

jstat -gc pid 1000 10

在这里插入图片描述

S0C：第一个幸存区的大小，单位KB
S1C：第二个幸存区的大小
S0U：第一个幸存区的使用大小
S1U：第二个幸存区的使用大小
EC：伊甸园区的大小
EU：伊甸园区的使用大小
OC：老年代大小
OU：老年代使用大小
MC：方法区大小(元空间)
MU：方法区使用大小
CCSC:压缩类空间大小
CCSU:压缩类空间使用大小
YGC：年轻代垃圾回收次数
YGCT：年轻代垃圾回收消耗时间，单位s
FGC：老年代垃圾回收次数
FGCT：老年代垃圾回收消耗时间，单位s
GCT：垃圾回收消耗总时间，单位s

五、Arthas

1.用java -jar运行即可，可以识别机器上所有Java进程（根据提示输入需要连接的程序序号）
在这里插入图片描述
2.输入dashboard可以查看整个进程的运行情况，线程、内存、GC、运行环境信息

3.输入thread可以查看线程详细情况

4.输入 thread加上线程ID 可以查看线程堆栈

5.输入 thread -b 可以查看线程死锁

6.输入 jad加类的全名可以反编译，这样可以方便我们查看线上代码是否是正确的版本
7.使用trace命令查看方法内部调用路径，并输出方法路径上的每个节点上耗时

$ trace demo.MathGame run
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 28 ms.
`---ts=2019-12-04 00:45:08;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[0.617465ms] demo.MathGame:run()
        `---[0.078946ms] demo.MathGame:primeFactors() #24 [throws Exception]

`---ts=2019-12-04 00:45:09;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[1.276874ms] demo.MathGame:run()
        `---[0.03752ms] demo.MathGame:primeFactors() #24 [throws Exception]

提示结果里的 #24，表示在 run 函数里，在源文件的第24行调用了primeFactors()函数。

指定class匹配的最大数量

$ trace demo.MathGame run -m 1
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 412 ms, listenerId: 4
`---ts=2022-12-25 21:00:00;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@b4aac2
    `---[0.762093ms] demo.MathGame:run()
        `---[30.21% 0.230241ms] demo.MathGame:primeFactors() #46 [throws Exception]

`---ts=2022-12-25 21:00:10;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@b4aac2
    `---[0.315298ms] demo.MathGame:run()
        `---[13.95% 0.043995ms] demo.MathGame:primeFactors() #46 [throws Exception]

trace捕捉次数限制

$ trace demo.MathGame run -n 1
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 20 ms.
`---ts=2019-12-04 00:45:53;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[0.549379ms] demo.MathGame:run()
        +---[0.059839ms] demo.MathGame:primeFactors() #24
        `---[0.232887ms] demo.MathGame:print() #25

Command execution times exceed limit: 1, so command will exit. You can set it with -n option.

trace打印JDK函数

默认情况下，trace 不会包含 jdk 里的函数调用，如果希望 trace jdk 里的函数，需要显式设置–skipJDKMethod false。

$ trace --skipJDKMethod false demo.MathGame run
Press Q or Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 60 ms.
`---ts=2019-12-04 00:44:41;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[1.357742ms] demo.MathGame:run()
        +---[0.028624ms] java.util.Random:nextInt() #23
        +---[0.045534ms] demo.MathGame:primeFactors() #24 [throws Exception]
        +---[0.005372ms] java.lang.StringBuilder:<init>() #28
        +---[0.012257ms] java.lang.Integer:valueOf() #28
        +---[0.234537ms] java.lang.String:format() #28
        +---[min=0.004539ms,max=0.005778ms,total=0.010317ms,count=2] java.lang.StringBuilder:append() #28
        +---[0.013777ms] java.lang.Exception:getMessage() #28
        +---[0.004935ms] java.lang.StringBuilder:toString() #28
        `---[0.06941ms] java.io.PrintStream:println() #28

`---ts=2019-12-04 00:44:42;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[3.030432ms] demo.MathGame:run()
        +---[0.010473ms] java.util.Random:nextInt() #23
        +---[0.023715ms] demo.MathGame:primeFactors() #24 [throws Exception]
        +---[0.005198ms] java.lang.StringBuilder:<init>() #28
        +---[0.006405ms] java.lang.Integer:valueOf() #28
        +---[0.178583ms] java.lang.String:format() #28
        +---[min=0.011636ms,max=0.838077ms,total=0.849713ms,count=2] java.lang.StringBuilder:append() #28
        +---[0.008747ms] java.lang.Exception:getMessage() #28
        +---[0.019768ms] java.lang.StringBuilder:toString() #28
        `---[0.076457ms] java.io.PrintStream:println() #28

详细的使用教程见官方文档：https://arthas.aliyun.com/doc/

trace打印信息根据时间过滤

只会展示耗时大于 10ms 的调用路径，有助于在排查问题的时候，只关注异常情况

$ trace demo.MathGame run '#cost > 10'
Press Ctrl+C to abort.
Affect(class-cnt:1 , method-cnt:1) cost in 41 ms.
`---ts=2018-12-04 01:12:02;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[12.033735ms] demo.MathGame:run()
        +---[0.006783ms] java.util.Random:nextInt()
        +---[11.852594ms] demo.MathGame:primeFactors()
        `---[0.05447ms] demo.MathGame:print()

trace跟踪多级方法

打开终端 1，trace 上面 demo 里的run函数，可以看到打印出 listenerId: 1

[arthas@59161]$ trace demo.MathGame run
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 112 ms, listenerId: 1
`---ts=2020-07-09 16:48:11;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[1.389634ms] demo.MathGame:run()
        `---[0.123934ms] demo.MathGame:primeFactors() #24 [throws Exception]

`---ts=2020-07-09 16:48:12;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[3.716391ms] demo.MathGame:run()
        +---[3.182813ms] demo.MathGame:primeFactors() #24
        `---[0.167786ms] demo.MathGame:print() #25

现在想要深入子函数primeFactors，可以打开一个新终端 2，使用telnet localhost 3658连接上 arthas，再 trace primeFactors时，指定listenerId

[arthas@59161]$ trace demo.MathGame primeFactors --listenerId 1
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 34 ms, listenerId: 1

这时终端 2 打印的结果，说明已经增强了一个函数：Affect(class count: 1 , method count: 1)，但不再打印更多的结果
再查看终端 1，可以发现 trace 的结果增加了一层，打印了primeFactors函数里的内容

`---ts=2020-07-09 16:49:29;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[0.492551ms] demo.MathGame:run()
        `---[0.113929ms] demo.MathGame:primeFactors() #24 [throws Exception]
            `---[0.061462ms] demo.MathGame:primeFactors()
                `---[0.001018ms] throw:java.lang.IllegalArgumentException() #46

`---ts=2020-07-09 16:49:30;thread_name=main;id=1;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@3d4eac69
    `---[0.409446ms] demo.MathGame:run()
        +---[0.232606ms] demo.MathGame:primeFactors() #24
        |   `---[0.1294ms] demo.MathGame:primeFactors()
        `---[0.084025ms] demo.MathGame:print() #25

六、打印GC日志

-Xloggc:./gc-%t.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps  -XX:+PrintGCTimeStamps -XX:+PrintGCCause  
-XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M

-Xloggc:./gc-%t.log ：定义gclog日志打印格式和位置
-XX:+PrintGCDetails -XX:+PrintGCDateStamps：程序输出gc日志
-XX:+PrintGCCause：打印gc产生的原因
-XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 ：gc日志滚动打印，保存文件10个
-XX:GCLogFileSize=100M：每个gc日志文件100M

如何分析GC日志

下图中是我截取的JVM刚启动的一部分GC日志

在这里插入图片描述
我们可以看到图中第一行红框，是项目的配置参数。这里不仅配置了打印GC日志，还有相关的VM内存参数。
第二行红框中的是在这个GC时间点发生GC之后相关GC情况。
1、对于2.909：这是从jvm启动开始计算到这次GC经过的时间，前面还有具体的发生时间日期。
2、Full GC(Metadata GC Threshold)指这是一次full gc，括号里是gc的原因， PSYoungGen是年轻代的GC，ParOldGen是老年代的GC，Metaspace是元空间的GC
3、 6160K->0K(141824K)，这三个数字分别对应GC之前占用年轻代的大小，GC之后年轻代占用，以及整个年轻代的大小。
4、112K->6056K(95744K)，这三个数字分别对应GC之前占用老年代的大小，GC之后老年代占用，以及整个老年代的大小。
5、6272K->6056K(237568K)，这三个数字分别对应GC之前占用堆内存的大小，GC之后堆内存占用，以及整个堆内存的大小。
6、20516K->20516K(1069056K)，这三个数字分别对应GC之前占用元空间内存的大小，GC之后元空间内存占用，以及整个元空间内存的大小。
7、0.0209707是该时间点GC总耗费时间。
从日志可以发现几次fullgc都是由于元空间不够导致的，所以我们可以将元空间调大点

七.根据JVM运行情况，预估JVM运行内存模型

堆内存大小、年轻代、老年大占比可以通过查看应用的JVM参数知道，具体每秒钟产生的对象大小和多久占满eden区可以通过固定时间内的youngGC次数推算出。
jstat -gc pid 2000(间隔多长时间打印一次) 10000（打印多少次）
在这里插入图片描述
有了内存运行模型，我们的优化目的就是减少程序的full gc次数。
full gc产生的原因：1.有可能是因为元空间占满了扩容造成，所以最好初始时就指定元空间大小，避免因为扩容而产生full gc
设置元空间大小参数：

-XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M

2.老年代内存区域占满会产生full gc。除开老年代内存设置不合理特别小的情况，正常情况下，都是因为年轻代有大量对象移动到老年代造成。结合对象分配到老年代的几个原因：1.大对象（看程序中是否定义有特别大的对象）2.长期存活的对象进入老年代（这种一般为缓存对象或者spring的bean，这种对象不可能每时每刻都有大量产生）3.对象动态年龄判断机制（一批对象的总大小大于这块Survivor区域内存大小的50%）4.老年代空间分配担保机制（老年代可用空间小于年轻代里现有的所有对象大小之和(包括垃圾对象)，这种情况一般是因为老年代设置太小）。基于这几种对象移动到老年代的原因，我们可以调节年轻代和老年代内存大小。
3.如果是新对象过于多造成的现象，就需要具体定位是什么原因造成的对象频繁产生，可以先借助jmap命令大概看下是什么对象产生大量实例，频繁产生对象的代码大概率也会占用很高的cpu，可以接用jstack或jvisualvm来定位cpu使用较高的代码。如果是代码问题，评估内存大小，修改代码每秒钟产生的对象数。

八、JVM参数设置

-Xms2048M -Xmx2048M -Xmn1024M -Xss512K -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M

-Xms：初始堆大小，默认物理内存的1/64
-Xmx：最大堆大小，默认物理内存的1/4
-Xmn：新生代大小
-XX:NewSize：设置新生代初始大小
-XX:NewRatio：默认2表示新生代占年老代的1/2，占整个堆内存的1/3。
-XX:SurvivorRatio：默认8表示一个survivor区占用1/8的Eden内存，即1/10的新生代内存。
关于元空间的JVM参数有两个：-XX:MetaspaceSize=N和 -XX:MaxMetaspaceSize=N
-XX：MaxMetaspaceSize：设置元空间最大值，默认是-1，即不限制，或者说只受限于本地内存大小。
-XX：MetaspaceSize：指定元空间触发Fullgc的初始阈值(元空间无固定初始大小)，以字节为单位，默认是21M左右，达到该值就会触发full gc进行类型卸载，同时收集器会对该值进行调整：如果释放了大量的空间，就适当降低该值；如果释放了很少的空间，那么在不超过-XX：MaxMetaspaceSize（如果设置了的话）的情况下，适当提高该值。这个跟早期jdk版本的-XX:PermSize参数意思不一样，-XX:PermSize代表永久代的初始容量。
由于调整元空间的大小需要Full GC，这是非常昂贵的操作，如果应用在启动的时候发生大量Full GC，通常都是由于永久代或元空间发生了大小调整，基于这种情况，一般建议在JVM参数中将MetaspaceSize和MaxMetaspaceSize设置成一样的值，并设置得比初始值要大，对于8G物理内存的机器来说，一般我会将这两个值都设置为256M。