java虚拟机(十)--性能监控工具测试内存溢出和死锁基本思路
在之前就曾经简单介绍过jdk自带的性能检测工具，但是只是很入门的内容。没有真正的用过都是白扯了，面试的时候也说不过去，更别提真正
在生产环境去解决问题，所以这里我们学习一下真正解决问题的过程，最起码面试的时候不是只能纸上谈兵。
如果没有了解过java性能监控与故障处理工具，可以参考：java虚拟机(八)--java性能监控与故障处理工具，当然这篇文章也会介绍这些内容
jvm参数类型：java虚拟机(九)--常用jvm参数
本文基于jdk1.8
jvm参数类型：
这部分内容之前也简单介绍过，这里再重新学习下，参数可以以下几种：
标准参数：不同jvm版本几乎不会变化
-help
-server -client
-version -showversion
# java -version java version "1.8.0_102" Java(TM) SE Runtime Environment (build 1.8.0_102-b14) Java HotSpot(TM) 64-Bit Server VM (build 25.102-b14, mixed mode)
-cp -classpath
X参数：非标准化参数，不同jvm版本可能发生变化，但是变化不大
-Xint：解释执行
-Xcomp：第一次使用编译成本地代码
-Xmixed：混合模式，jvm自己决定是否编译成本地代码
[root@iZuf6fkfhthmdm1nwdg5isZ ~]# java -version java version "1.8.0_102" Java(TM) SE Runtime Environment (build 1.8.0_102-b14) Java HotSpot(TM) 64-Bit Server VM (build 25.102-b14, mixed mode) [root@iZuf6fkfhthmdm1nwdg5isZ ~]# java -Xcomp -version java version "1.8.0_102" Java(TM) SE Runtime Environment (build 1.8.0_102-b14) Java HotSpot(TM) 64-Bit Server VM (build 25.102-b14, compiled mode) [root@iZuf6fkfhthmdm1nwdg5isZ ~]# java -Xint -version java version "1.8.0_102" Java(TM) SE Runtime Environment (build 1.8.0_102-b14) Java HotSpot(TM) 64-Bit Server VM (build 25.102-b14, interpreted mode)
XX参数：非标准化参数，想对不太稳定，主要用户jvm调优和debug
Boolean类型：
格式：-XX:[+ -]<name>表示启动或者禁用name属性
举个栗子：
-XX:+UseConcMarkSweepGC，使用cms垃圾处理器
-XX:+UseG1GC，使用G1垃圾处理器
非Boolean类型：
格式：-XX:<name>=<value>键值对类型，表示name属性值为value
举个栗子：
-XX:MaxGCPauseMillis=500，表示GC停顿的最大时间为500ms
-XX:GCTimeRatio=19
-Xmx：就是-XX:InitialHeapSize，初始化堆大小，也就是最小堆内存
-Xms：就是-XX:MaxHeapSize，最大堆内存
所以-Xmx和-Xms不是X类型参数，而是XX类型参数
查看运行时参数：
-XX:+PrintFlagsInitial，打印出参数初始值
-XX:+PrintFlagsFinal，打印出参数最终值
-XX:+UnlockExperimentalVMOptions解锁试验参数
-XX:+UnlockDiagnosticVMOptions解锁诊断参数
-XX:+PrintCommandLineFlags打印命令行参数
举个栗子：
java -XX:+PrintFlagsInitial -version > a.txt
我们上面命令启动的进程把所有的命令初始值都打印到a.txt，打开文件发现700+参数
uintx MaxGCMinorPauseMillis = 18446744073709551615 {product} uintx MaxGCPauseMillis = 18446744073709551615 {product} uintx MaxHeapFreeRatio = 70 {manageable} uintx MaxHeapSize = 130862280 {product} intx MaxInlineLevel = 9 {product} bool UseG1GC = false {product}
这里=指的是默认jvm的参数，而:=为用户自行修改了参数，我这里还没修改过参数
jdk8所有命令参数详解：https://docs.oracle.com/javase/8/docs/technotes/tools/unix/，来自Oracle官网，当然其他版本的文档也都有
jps命令：参看正在运行的Java线程，和Linux的ps差不多
[root@iZuf6fkfhthmdm1nwdg5isZ local]# jps 32464 jar 17593 jar 14234 Jps [root@iZuf6fkfhthmdm1nwdg5isZ local]# jps -l 32464 user-0.0.1-SNAPSHOT.jar 17593 eureka-0.0.1-SNAPSHOT.jar 14252 sun.tools.jps.Jps
Jinfo命令：查看正在运行的参数，和jps联合使用
查看17593的参数，这里是Spring cloud的eureka组件运行进程号
[root@iZuf6fkfhthmdm1nwdg5isZ local]# jinfo -flag MaxHeapSize 17593 //打印出进程号为17593的MaxHeapSize参数大小 -XX:MaxHeapSize=994050048 [root@iZuf6fkfhthmdm1nwdg5isZ local]# jinfo -flags 17593 //打印出17593的所有非默认参数，而命令行参数这里是为空 Attaching to process ID 17593, please wait... Debugger attached successfully. Server compiler detected. JVM version is 25.102-b14 Non-default VM flags: -XX:CICompilerCount=2 -XX:InitialHeapSize=62914560 -XX:MaxHeapSize=994050048 -XX:MaxNewSize=331350016 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=20971520 -XX:OldSize=41943040 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC Command line:
Jstat：查看jvm统计信息
option：-class，-compiler，-gc等
1、类加载：
# jstat -class 17593 1000 10 //查看该进程的类加载信息，每1000ms打印一次，总打印10次 Loaded Bytes Unloaded Bytes Time 11618 20145.6 74 109.7 10.47 11618 20145.6 74 109.7 10.47 11618 20145.6 74 109.7 10.47 11618 20145.6 74 109.7 10.47 11618 20145.6 74 109.7 10.47 11618 20145.6 74 109.7 10.47 11618 20145.6 74 109.7 10.47 11618 20145.6 74 109.7 10.47 11618 20145.6 74 109.7 10.47 11618 20145.6 74 109.7 10.47
2、垃圾回收：
option：-gc、-gcutil、-gccause、-gcnew、-gcold
# jstat -gc 17593 1000 5 S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT 1024.0 1024.0 0.0 384.0 29184.0 24461.9 75776.0 26031.3 61784.0 58858.3 8064.0 7502.5 107 0.696 3 0.366 1.062 1024.0 1024.0 0.0 384.0 29184.0 24461.9 75776.0 26031.3 61784.0 58858.3 8064.0 7502.5 107 0.696 3 0.366 1.062 1024.0 1024.0 0.0 384.0 29184.0 24461.9 75776.0 26031.3 61784.0 58858.3 8064.0 7502.5 107 0.696 3 0.366 1.062 1024.0 1024.0 0.0 384.0 29184.0 24461.9 75776.0 26031.3 61784.0 58858.3 8064.0 7502.5 107 0.696 3 0.366 1.062 1024.0 1024.0 0.0 384.0 29184.0 24461.9 75776.0 26031.3 61784.0 58858.3 8064.0 7502.5 107 0.696 3 0.366 1.062
-gc选项
S0C、S1C、S0U、S1U：当前survivor0、survivor1容量（kB）和使用率
EC、EU：当前的eden space容量（kB）和使用率
OC、OU：当前old space容量（kB）和使用率
MC、MU：Metaspace 容量（kB）和使用率
CCSC、CCSU：Compressed class space容量（kB）和使用率
YGC、YGCT：Young GC的次数和时间
FGC、FGCT：Full GC的次数和时间
GCT：GC总时间
C：Capacity就是次数、容量
U：utilization就是使用率、利用率
T：time就是时间
3、JIT编译：
Option：-compiler、-PrintCompilation
# jstat -compiler 17593 Compiled Failed Invalid Time FailedType FailedMethod 11759 1 0 50.01 1 org/springframework/core/annotation/AnnotationUtils findAnnotation
这里我们先实现堆和非堆的内存溢出，然后后面通过工具进行分析内存映像文件，找到原因，解决问题
堆内存溢出：不断生成对象，并且保持其可达性，从而不被GC
@Data @AllArgsConstructor public class User { private int id; private String name; } //设置堆大小为-Xms20m -Xmx20m @GetMapping("/heap") public String heap() { int i = 0; while (true) { userList.add(new User(i++, UUID.randomUUID().toString())); } }
输出结果：java.lang.OutOfMemoryError: GC overhead limit exceeded
Metaspace内存溢出：
这里需要asm去创建class文件
<dependency> <groupId>asm</groupId> <artifactId>asm</artifactId> <version>3.2</version> </dependency>
public class Metaspace extends ClassLoader { public static List<Class<?>> createClasses() { // 类持有 List<Class<?>> classes = new ArrayList<Class<?>>(); // 循环1000w次生成1000w个不同的类。 for (int i = 0; i < 10000000; ++i) { ClassWriter cw = new ClassWriter(0); // 定义一个类名称为Class{i}，它的访问域为public，父类为java.lang.Object，不实现任何接口 cw.visit(Opcodes.V1_1, Opcodes.ACC_PUBLIC, "Class" + i, null, "java/lang/Object", null); // 定义构造函数<init>方法 MethodVisitor mw = cw.visitMethod(Opcodes.ACC_PUBLIC, "<init>", "()V", null, null); // 第一个指令为加载this mw.visitVarInsn(Opcodes.ALOAD, 0); // 第二个指令为调用父类Object的构造函数 mw.visitMethodInsn(Opcodes.INVOKESPECIAL, "java/lang/Object", "<init>", "()V"); // 第三条指令为return mw.visitInsn(Opcodes.RETURN); mw.visitMaxs(1, 1); mw.visitEnd(); Metaspace test = new Metaspace(); byte[] code = cw.toByteArray(); // 定义类 Class<?> exampleClass = test.defineClass("Class" + i, code, 0, code.length); classes.add(exampleClass); } return classes; } }
//设置非堆metaspace大小为-XX:MetaspaceSize=32M -XX:MaxMetaspaceSize=32M @GetMapping("/nonheap") public String nonheap() { while (true) { classList.addAll(Metaspace.createClasses()); } }
输出结果：java.lang.OutOfMemoryError: Metaspace
导入内存映像文件
自动导出：
-XX:+HeapDumpOnOutMemoryError
-XX:HeapDumpPath=./
使用jmap命令导出：
$ jps -l 10384 sun.tools.jps.Jps 2160 8180 com.it.MonitorApplication 14988 org.jetbrains.idea.maven.server.RemoteMavenServer 9372 org.jetbrains.jps.cmdline.Launcher $ jmap -dump:format=b,file=heap.hprof 8180 Dumping heap to D:\Java\project\SocketChat\heap.hprof ... Heap dump file created
首先通过jps找到进程，然后通过jmap dump到对应的文件
通过MAT(eclipse)或者JProfiler(Intellij idea)分析dump文件，或者是jdk自带的VisualVM打开都可以
我这里用的是JProfiler打开
发现user对象数量为749377个，肯定有问题，进一步查看引用，是MemoryController中的ArrayList
如果是VisualVM打开hprof文件，也是可以找到原因
当然这个例子很简单，不用工具我们也知道原因，这个例子只是个思路，通过对象的数量和占用内存情况去定位OOM问题，然后可以逐渐去解决工作中的问题
对于使用eclipse的MAT，对于dump文件的分析可能更加直观，同样可以定位问题
jstack：
死循环导致CPU使用率飙升：
/** * 死循环 * */ @RequestMapping("/loop") public List<Long> loop(){ String data = "{\"data\":[{\"partnerid\":]"; return getPartneridsFromJson(data); } public static List<Long> getPartneridsFromJson(String data){ //{\"data\":[{\"partnerid\":982,\"count\":\"10000\",\"cityid\":\"11\"},{\"partnerid\":983,\"count\":\"10000\",\"cityid\":\"11\"},{\"partnerid\":984,\"count\":\"10000\",\"cityid\":\"11\"}]} //上面是正常的数据 List<Long> list = new ArrayList<Long>(2); if(data == null || data.length() <= 0){ return list; } int datapos = data.indexOf("data"); if(datapos < 0){ return list; } int leftBracket = data.indexOf("[",datapos); int rightBracket= data.indexOf("]",datapos); if(leftBracket < 0 || rightBracket < 0){ return list; } String partners = data.substring(leftBracket+1,rightBracket); if(partners == null || partners.length() <= 0){ return list; } while(partners!=null && partners.length() > 0){ int idpos = partners.indexOf("partnerid"); if(idpos < 0){ break; } int colonpos = partners.indexOf(":",idpos); int commapos = partners.indexOf(",",idpos); if(colonpos < 0 || commapos < 0){ //partners = partners.substring(idpos+"partnerid".length());//1 continue; } String pid = partners.substring(colonpos+1,commapos); if(pid == null || pid.length() <= 0){ //partners = partners.substring(idpos+"partnerid".length());//2 continue; } try{ list.add(Long.parseLong(pid)); }catch(Exception e){ //do nothing } partners = partners.substring(commapos); } return list; }
通过top命令找到CPU使用率比较高的进程pid，然后通过
jstack pid> a.txt
将pid转换为16进制，因为导出文件id就是16进制，而top命令得到的pid为十进制，通过在文件中搜索得到
死锁问题：
private Object lock1 = new Object(); private Object lock2 = new Object(); /** * 死锁 * */ @RequestMapping("/deadlock") public String deadlock(){ new Thread(()->{ synchronized(lock1) { try {Thread.sleep(1000);}catch(Exception e) {} synchronized(lock2) { System.out.println("Thread1 over"); } } }) .start(); new Thread(()->{ synchronized(lock2) { try {Thread.sleep(1000);}catch(Exception e) {} synchronized(lock1) { System.out.println("Thread2 over"); } } }) .start(); return "deadlock"; }
通过jps -l或者ps -ef|grep java找到对应的线程，然后找到进程号，通过jstack pid > a.txt
打开a.txt，如果出现死锁，在文件的末尾
Found one Java-level deadlock: ============================= "Thread-5": waiting to lock monitor 0x00007fc8e40062c8 (object 0x00000000c55d6df0, a java.lang.Object), which is held by "Thread-4" "Thread-4": waiting to lock monitor 0x00007fc8e40048a8 (object 0x00000000c55d6e00, a java.lang.Object), which is held by "Thread-5" Java stack information for the threads listed above: =================================================== "Thread-5": at com.it.test1.MemoryController.lambda$deadlock$1(MemoryController.java:62) - waiting to lock <0x00000000c55d6df0> (a java.lang.Object) - locked <0x00000000c55d6e00> (a java.lang.Object) at com.it.test1.MemoryController$$Lambda$336/1566045595.run(Unknown Source) at java.lang.Thread.run(Thread.java:745) "Thread-4": at com.it.test1.MemoryController.lambda$deadlock$0(MemoryController.java:54) - waiting to lock <0x00000000c55d6e00> (a java.lang.Object) - locked <0x00000000c55d6df0> (a java.lang.Object) at com.it.test1.MemoryController$$Lambda$335/744771958.run(Unknown Source) at java.lang.Thread.run(Thread.java:745) Found 1 deadlock.
Found 1 deadlock，上面是具体的问题原因，就是两个线程获得锁然后相互等待导致了死锁
