JVM调优工具详解及调优实战

事先启动一个web应用程序,用jps查看其进程id,接着用各种jdk自带命令优化应用

Jmap

此命令可以用来查看内存信息,实例个数以及占用内存大小

打开log.txt,文件内容如下:

num:序号instances:实例数量bytes:占用空间大小

class name:类名称,[C is a char[],[S is a short[],[I is a int[],[B is a byte[],[[I is a int[][]

堆信息

堆内存dump

dump:format=b,file

=eureka.hprof 14660

1 jmap

也可以设置内存溢出自动导出dump文件(内存很大的时候,可能会导不出来)

  1. -XX:+HeapDumpOnOutOfMemoryError
  2. -XX:HeapDumpPath=./ (路径) 示例代码:

1 public class OOMTest {

2

3 public static List<Object> list = new ArrayList<>();

4

  1. // JVM设置
  2. // ‐Xms10M ‐Xmx10M ‐XX:+PrintGCDetails ‐XX:+HeapDumpOnOutOfMemoryError ‐XX:HeapDumpPath=D:\jvm.dump
  3. public static void main(String[] args) {
  4. List<Object> list = new ArrayList<>();
  5. int i = 0;
  6. int j = 0;
  7. while (true) {
  8. list.add(new User(i++, UUID.randomUUID().toString()));
  9. new User(j‐‐, UUID.randomUUID().toString());

14 }

15 }

16 }

可以用jvisualvm命令工具导入该dump文件分析

Jstack

用jstack加进程id查找死锁,见如下示例

1 public class DeadLockTest {

2

  1. private static Object lock1 = new Object();
  2. private static Object lock2 = new Object();

5

  1. public static void main(String[] args) {
  2. new Thread(() ‐> {
  3. synchronized (lock1) {
  4. try {
  5. System.out.println("thread1 begin");
  6. Thread.sleep(5000);
  7. } catch (InterruptedException e) {

13 }

  1. synchronized (lock2) {
  2. System.out.println("thread1 end");

16 }

17 }

18 }).start();

19

  1. new Thread(() ‐> {
  2. synchronized (lock2) {
  3. try {
  4. System.out.println("thread2 begin");
  5. Thread.sleep(5000);
  6. } catch (InterruptedException e) {

26 }

  1. synchronized (lock1) {
  2. System.out.println("thread2 end");

29 }

30 }

31 }).start();

32

33 System.out.println("main thread end");

34 }

35 }

"Thread-1" 线程名

prio=5 优 先 级 =5 tid=0x000000001fa9e000 线 程 id nid=0x2d64 线程对应的本地线程标识nid java.lang.Thread.State: BLOCKED 线程状态

还可以用jvisualvm自动检测死锁

远程连接jvisualvm

启动普通的jar程序JMX端口配置:

1 java Dcom.sun.management.jmxremote.port=8888 Djava.rmi.server.hostname=192.168.50.60 Dcom.sun.management.jmxremot e.ssl=false Dcom.sun.management.jmxremote.authenticate=false jar microserviceeurekaserver.jar

PS:

-Dcom.sun.management.jmxremote.port 为远程机器的JMX端口

-Djava.rmi.server.hostname 为远程机器IP

tomcat的JMX配置:在catalina.sh文件里的最后一个JAVA_OPTS的赋值语句下一行增加如下配置行

1 JAVA_OPTS

="$JAVA_OPTS ‐Dcom.sun.management.jmxremote.port=8888 ‐Djava.rmi.server.hostname=192.168.50.60 ‐Dcom.sun.ma

nagement.jmxremote.ssl=false ‐Dcom.sun.management.jmxremote.authenticate=false"

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

1 package com.tuling.jvm;

2

3 /**

4 * 运行此代码,cpu会飙高

5 */

6 public class Math {

7

  1. public static final int initData = 666;
  2. public static User user = new User();

10

  1. public int compute() { //一个方法对应一块栈帧内存区域
  2. int a = 1;
  3. int b = 2;

14 int c = (a + b) * 10;

15 return c;

16 }

17

  1. public static void main(String[] args) {
  2. Math math = new Math();
  3. while (true){
  4. math.compute();

22 }

23 }

24 }

1,使用命令top -p ,显示你的java进程的内存情况,pid是你的java进程号,比如19663

2,按H,获取每个线程的内存情况

3,找到内存和cpu占用最高的线程tid,比如19664

4,转为十六进制得到 0x4cd0,此为线程id的十六进制表示

5,执行 jstack 19663|grep -A 10 4cd0,得到线程堆栈信息中 4cd0 这个线程所在行的后面10行,从堆栈中可以发现导致cpu飙高的调用方法

6,查看对应的堆栈信息找出可能存在问题的代码

Jinfo

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

查看java系统参数

Jstat

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

注意:使用的jdk版本是jdk8

垃圾回收统计

jstat -gc pid 最常用,可以评估程序内存使用及GC压力整体情况

S0C:第一个幸存区的大小,单位KB S1C:第二个幸存区的大小

S0U:第一个幸存区的使用大小

S1U:第二个幸存区的使用大小EC:伊甸园区的大小

EU:伊甸园区的使用大小OC:老年代大小

OU:老年代使用大小MC:方法区大小(元空间) MU:方法区使用大小CCSC:压缩类空间大小CCSU:压缩类空间使用大小YGC:年轻代垃圾回收次数

YGCT:年轻代垃圾回收消耗时间,单位s FGC:老年代垃圾回收次数

FGCT:老年代垃圾回收消耗时间,单位s GCT:垃圾回收消耗总时间,单位s

堆内存统计

NGCMN:新生代最小容量NGCMX:新生代最大容量NGC:当前新生代容量S0C:第一个幸存区大小S1C:第二个幸存区的大小EC:伊甸园区的大小OGCMN:老年代最小容量OGCMX:老年代最大容量OGC:当前老年代大小 OC:当前老年代大小MCMN:最小元数据容量MCMX:最大元数据容量MC:当前元数据空间大小

CCSMN:最小压缩类空间大小CCSMX:最大压缩类空间大小CCSC:当前压缩类空间大小YGC:年轻代gc次数

FGC:老年代GC次数

新生代垃圾回收统计

S0C:第一个幸存区的大小S1C:第二个幸存区的大小S0U:第一个幸存区的使用大小S1U:第二个幸存区的使用大小TT:对象在新生代存活的次数

MTT:对象在新生代存活的最大次数DSS:期望的幸存区大小

EC:伊甸园区的大小EU:伊甸园区的使用大小

YGC:年轻代垃圾回收次数YGCT:年轻代垃圾回收消耗时间

新生代内存统计

NGCMN:新生代最小容量NGCMX:新生代最大容量NGC:当前新生代容量S0CMX:最大幸存1区大小S0C:当前幸存1区大小S1CMX:最大幸存2区大小S1C:当前幸存2区大小ECMX:最大伊甸园区大小EC:当前伊甸园区大小YGC:年轻代垃圾回收次数FGC:老年代回收次数

老年代垃圾回收统计

MC:方法区大小MU:方法区使用大小CCSC:压缩类空间大小

CCSU:压缩类空间使用大小OC:老年代大小

OU:老年代使用大小YGC:年轻代垃圾回收次数FGC:老年代垃圾回收次数

FGCT:老年代垃圾回收消耗时间GCT:垃圾回收消耗总时间

老年代内存统计

OGCMN:老年代最小容量OGCMX:老年代最大容量OGC:当前老年代大小OC:老年代大小

YGC:年轻代垃圾回收次数FGC:老年代垃圾回收次数FGCT:老年代垃圾回收消耗时间GCT:垃圾回收消耗总时间

元数据空间统计

MCMN:最小元数据容量MCMX:最大元数据容量MC:当前元数据空间大小CCSMN:最小压缩类空间大小CCSMX:最大压缩类空间大小CCSC:当前压缩类空间大小YGC:年轻代垃圾回收次数FGC:老年代垃圾回收次数

FGCT:老年代垃圾回收消耗时间GCT:垃圾回收消耗总时间

S0:幸存1区当前使用比例S1:幸存2区当前使用比例E:伊甸园区使用比例

O:老年代使用比例M:元数据区使用比例CCS:压缩使用比例

YGC:年轻代垃圾回收次数FGC:老年代垃圾回收次数FGCT:老年代垃圾回收消耗时间GCT:垃圾回收消耗总时间

JVM运行情况预估

用 jstat gc -pid 命令可以计算出如下一些关键数据,有了这些数据就可以采用之前介绍过的优化思路,先给自己的系统设置一些初始性的JVM参数,比如堆内存大小,年轻代大小,Eden和Survivor的比例,老年代的大小,大对象的阈值,大龄对象进入老年代的阈值等。

年轻代对象增长的速率

可以执行命令 jstat -gc pid 1000 10 (每隔1秒执行1次命令,共执行10次),通过观察EU(eden区的使用)来估算每秒eden大概新增多少对象,如果系统负载不高,可以把频率1秒换成1分钟,甚至10分钟来观察整体情况。注意,一般系统可能有高峰期和日常期,所以需要在不同的时间分别估算不同情况下对象增长速率。

Young GC的触发频率和每次耗时

知道年轻代对象增长速率我们就能推根据eden区的大小推算出Young GC大概多久触发一次,Young GC的平均耗时可以通过 YGCT/YGC 公式算出,根据结果我们大概就能知道系统大概多久会因为Young GC的执行而卡顿多久。

每次Young GC后有多少对象存活和进入老年代

这个因为之前已经大概知道Young GC的频率,假设是每5分钟一次,那么可以执行命令 jstat -gc pid 300000 10 ,观察每次结果eden, survivor和老年代使用的变化情况,在每次gc后eden区使用一般会大幅减少,survivor和老年代都有可能增长,这些增长的对象就是每次Young GC后存活的对象,同时还可以看出每次Young GC后进去老年代大概多少对象,从而可以推算出老年代对象增长速率。

Full GC的触发频率和每次耗时

知道了老年代对象的增长速率就可以推算出Full GC的触发频率了,Full GC的每次耗时可以用公式 FGCT/FGC 计算得出。

优化思路其实简单来说就是尽量让每次Young GC后的存活对象小于Survivor区域的50%,都留存在年轻代里。尽量别让对象进入老年代。尽量减少Full GC的频率,避免频繁Full GC对JVM性能的影响。

系统频繁Full GC导致系统卡顿是怎么回事

机器配置:2核4G JVM内存大小:2G 系统运行时间:7天

期间发生的Full GC次数和耗时:500多次,200多秒期间发生的Young GC次数和耗时:1万多次,500多秒

大致算下来每天会发生70多次Full GC,平均每小时3次,每次Full GC在400毫秒左右; 每天会发生1000多次Young GC,每分钟会发生1次,每次Young GC在50毫秒左右。

JVM参数设置如下:

  1. Xms1536M Xmx1536M Xmn512M Xss256K XX:SurvivorRatio=6 XX:MetaspaceSize=256M XX:MaxMetaspaceSize=256M
  2. XX:+UseParNewGC XX:+UseConcMarkSweepGC XX:CMSInitiatingOccupancyFraction=75 XX:+UseCMSInitiatingOccupancyOnly

大家可以结合对象挪动到老年代那些规则推理下我们这个程序可能存在的一些问题经过分析感觉可能会由于对象动态年龄判断机制导致full gc较为频繁

为了给大家看效果,我模拟了一个示例程序(见课程对应工程代码:jvm-full-gc),打印了jstat的结果如下:

1

jstat

gc

13456

2000

10000

对于对象动态年龄判断机制导致的full gc较为频繁可以先试着优化下JVM参数,把年轻代适当调大点:

  1. Xms1536M Xmx1536M Xmn1024M Xss256K XX:SurvivorRatio=6 XX:MetaspaceSize=256M XX:MaxMetaspaceSize=256M
  2. XX:+UseParNewGC XX:+UseConcMarkSweepGC XX:CMSInitiatingOccupancyFraction=92 XX:+UseCMSInitiatingOccupancyOnly

优化完发现没什么变化,full gc的次数比minor gc的次数还多了

我们可以推测下full gc比minor gc还多的原因有哪些? 1、元空间不够导致的多余full gc

2、显示调用System.gc()造成多余的full gc,这种一般线上尽量通过­XX:+DisableExplicitGC参数禁用,如果加上了这个JVM启动参数,那么代码中调用System.gc()没有任何效果

3、老年代空间分配担保机制

最快速度分析完这些我们推测的原因以及优化后,我们发现young gc和full gc依然很频繁了,而且看到有大量的对象频繁的被挪动到老年代,这种情况我们可以借助jmap命令大概看下是什么对象

查到了有大量User对象产生,这个可能是问题所在,但不确定,还必须找到对应的代码确认,如何去找对应的代码了? 1、代码里全文搜索生成User对象的地方(适合只有少数几处地方的情况)

2、如果生成User对象的地方太多,无法定位具体代码,我们可以同时分析下占用cpu较高的线程,一般有大量对象不断产生,对应的方法代码肯定会被频繁调用,占用的cpu必然较高

可以用上面讲过的jstack或jvisualvm来定位cpu使用较高的代码,最终定位到的代码如下:

1 import java.util.ArrayList;

2

  1. @RestController
  2. public class IndexController {

5

  1. @RequestMapping("/user/process")
  2. public String processUserData() throws InterruptedException {
  3. ArrayList<User> users = queryUsers();

9

  1. for (User user: users) {
  2. //TODO 业务处理
  3. System.out.println("user:" + user.toString());

13 }

14 return "end";

15 }

16

17 /**

  1. * 模拟批量查询用户场景
  2. * @return

20 */

  1. private ArrayList<User> queryUsers() {
  2. ArrayList<User> users = new ArrayList<>();

23 for (int i = 0; i < 5000; i++) {

24 users.add(new User(i,"zhuge"));

25 }

26 return users;

27 }

28 }

同时,java的代码也是需要优化的,一次查询出500M的对象出来,明显不合适,要根据之前说的各种原则尽量优化到合适的值,尽量消

除这种朝生夕死的对象导致的full gc

内存泄露到底是怎么回事

再给大家讲一种情况,一般电商架构可能会使用多级缓存架构,就是redis加上JVM级缓存,大多数同学可能为了图方便对于JVM级缓存就简单使用一个hashmap,于是不断往里面放缓存数据,但是很少考虑这个map的容量问题,结果这个缓存map越来越大,一直占用着老 年代的很多空间,时间长了就会导致full gc非常频繁,这就是一种内存泄漏,对于一些老旧数据没有及时清理导致一直占用着宝贵的内存资源,时间长了除了导致full gc,还有可能导致OOM。

这种情况完全可以考虑采用一些成熟的JVM级缓存框架来解决,比如ehcache等自带一些LRU数据淘汰算法的框架来作为JVM级的缓存。

GC日志详解

对于java应用我们可以通过一些配置把程序运行过程中的gc日志全部打印出来,然后分析gc日志得到关键性指标,分析GC原因,调优JVM参数。

打印GC日志方法,在JVM参数里增加参数,%t 代表时间

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

Tomcat则直接加在JAVA_OPTS变量里。

如何分析GC日志

运行程序加上对应gc日志

jar Xloggc:./gc‐%t.log XX:+PrintGCDetails XX:+PrintGCDateStamps XX:+PrintGCTimeStamps XX:

+PrintGCCause

1 java

XX:+UseGCLogFileRotation XX:NumberOfGCLogFiles=10 XX:GCLogFileSize=100M microserviceeureka

server.jar

2

下图中是我截取的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都是由于元空间不够导致的,所以我们可以将元空间调大点

  1. java jar Xloggc:./gcadjust‐%t.log XX:MetaspaceSize=256M XX:MaxMetaspaceSize=256M XX:+PrintGCDetails XX:+Print GCDateStamps
  2. XX:+PrintGCTimeStamps XX:+PrintGCCause XX:+UseGCLogFileRotation XX:NumberOfGCLogFiles=10 XX:GCLogFileSize=100M
  3. microserviceeurekaserver.jar

调整完我们再看下gc日志发现已经没有因为元空间不够导致的fullgc了

对于CMS和G1收集器的日志会有一点不一样,也可以试着打印下对应的gc日志分析下,可以发现gc日志里面的gc步骤跟 我们之前讲过的步骤是类似的

1 public class HeapTest {

2

3 byte[] a = new byte[1024 * 100]; //100KB

4

  1. public static void main(String[] args) throws InterruptedException {
  2. ArrayList<HeapTest> heapTests = new ArrayList<>();
  3. while (true) {
  4. heapTests.add(new HeapTest());
  5. Thread.sleep(10);

10 }

11 }

12 }

CMS

  1. Xloggc:d:/gccms‐%t.log Xms50M Xmx50M XX:MetaspaceSize=256M XX:MaxMetaspaceSize=256M XX:+PrintGCDetails XX:+P rintGCDateStamps
  2. XX:+PrintGCTimeStamps XX:+PrintGCCause XX:+UseGCLogFileRotation XX:NumberOfGCLogFiles=10 XX:GCLogFileSize=100M
  3. XX:+UseParNewGC XX:+UseConcMarkSweepGC

G1

  1. Xloggc:d:/gcg1‐%t.log Xms50M Xmx50M XX:MetaspaceSize=256M XX:MaxMetaspaceSize=256M XX:+PrintGCDetails XX:+Pr intGCDateStamps
  2. XX:+PrintGCTimeStamps XX:+PrintGCCause XX:+UseGCLogFileRotation XX:NumberOfGCLogFiles=10 XX:GCLogFileSize=100M

XX:+UseG1GC

上面的这些参数,能够帮我们查看分析GC的垃圾收集情况。但是如果GC日志很多很多,成千上万行。就算你一目十行, 看完了,脑子也是一片空白。所以我们可以借助一些功能来帮助我们分析,这里推荐一个gceasy(https://gceasy.io),可以 上传gc文件,然后他会利用可视化的界面来展现GC情况。具体下图所示

上图我们可以看到年轻代,老年代,以及永久代的内存分配,和最大使用情况。

上图我们可以看到堆内存在GC之前和之后的变化,以及其他信息。

这个工具还提供基于机器学习的JVM智能优化建议,当然现在这个功能需要付费

JVM参数汇总查看命令

java -XX:+PrintFlagsInitial 表示打印出所有参数选项的默认值

java -XX:+PrintFlagsFinal 表示打印出所有参数选项在运行程序时生效的值

发表评论
留言与评论(共有 0 条评论) “”
   
验证码:

相关文章

推荐文章