b话不多说,直接起飞~
准备一个工程jar包。
1.Jmap
1.1实例个数以及大小
先启动eureka工程:
然后在开一个cmd窗口,然后输入命令(jmap -histo pid > ./eureka-jvm.txt),如下图所示:
在文件夹中就会出现eureka-jvm.txt:
打开txt文件,我们看下里面有啥:
num #instances #bytes class name ---------------------------------------------- 1: 18813 35641112 [I 2: 175715 29894296 [C 3: 130413 3129912 java.lang.String 4: 6526 2073664 [B 5: 23345 2054360 java.lang.reflect.Method 6: 40128 1284096 java.util.concurrent.ConcurrentHashMap$Node 7: 11513 1266592 java.lang.Class 8: 18926 963704 [Ljava.lang.Object; 9: 13374 855936 java.net.URL 10: 20236 809440 java.util.LinkedHashMap$Entry 11: 8746 750544 [Ljava.util.HashMap$Node; 12: 23098 739136 org.springframework.boot.loader.jar.StringSequence 13: 31214 655584 [Ljava.lang.Class; 14: 18055 577760 java.util.HashMap$Node 15: 7688 553536 java.lang.reflect.Field 16: 9865 552440 java.util.LinkedHashMap 17: 27971 447536 java.lang.Object 18: 211 446032 [Ljava.util.concurrent.ConcurrentHashMap$Node; 19: 13018 312432 java.lang.StringBuffer 20: 5446 261408 org.springframework.util.ConcurrentReferenceHashMap$SoftEntryReference 21: 10176 244224 org.springframework.boot.loader.jar.JarURLConnection$JarEntryName 22: 2844 227520 org.springframework.boot.loader.jar.JarURLConnection 23: 4593 220464 java.util.zip.Inflater 24: 2668 213440 java.lang.reflect.Constructor 25: 4845 209352 [Ljava.lang.reflect.Method; 26: 1699 203880 org.springframework.boot.loader.jar.JarEntry 27: 7987 191688 java.util.ArrayList 28: 4783 191320 java.lang.ref.Finalizer 29: 2836 181504 java.util.regex.Matcher 30: 3554 170592 java.util.HashMap 31: 3936 152664 [Ljava.lang.String; 32: 3122 149856 org.springframework.core.ResolvableType 33: 5776 138624 java.lang.StringBuilder 34: 2283 127848 java.lang.Class$ReflectionData 35: 1965 125760 java.text.DecimalFormatSymbols 36: 3797 121504 java.util.LinkedHashMap$LinkedKeyIterator 37: 2969 118760 java.util.Formatter$FormatSpecifier 38: 2819 112760 java.lang.ref.SoftReference 39: 4593 110232 java.util.zip.ZStreamRef
上面为截取的一部分,可以清晰的看到:
number:文件行号;
instances:实例数量;
bytes:占用空间大小;
class name:类名称,C is a char[],S is a short[],I is a int[],B is a byte[];
1.2堆信息
我们接着输入命令(jmap -heap pid):
出现了一系列的内存信息,年轻代 ,老年代,原空间等都在上面一览无遗。
1.3dump堆内存文件
我们接着输入命令(jmap -dump:format=b,file=eureka-jvm.hprof pid),出现以下文件:
1.4使用jvisualvm分析hprof文件
我们在打开一个cmd,输入命令(jvisualvm),出现窗口:
然后载入我们刚刚dump出来的文件:
可以看到一系列类的信息:
分析这些个类的时候,如果是jvm的gc有问题,我们就能很快找到我们的哪些类在jvm内存中一直占着比较高的内存,找到这些类,在找对应代码分析这些类生成是否一致被引用,从而导致gc无法回收这些我们自定义的类。
2.Jinfo
2.1查看jvm参数
输入命令(jinfo -flags pid):
可以看到jar包启动的jvm参数。
2.2查看java系统参数
输入命令(jinfo -sysprops pid):
Attaching to process ID 20380, please wait... Debugger attached successfully. Server compiler detected. JVM version is 25.60-b23 java.runtime.name = Java(TM) SE Runtime Environment java.vm.version = 25.60-b23 sun.boot.library.path = D:\work\java\jdk1.8.0_60\jre\bin java.protocol.handler.pkgs = org.springframework.boot.loader java.vendor.url = http://java.oracle.com/ java.vm.vendor = Oracle Corporation path.separator = ; java.rmi.server.randomIDs = true 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 = D:\work\mycode\cloud-parent\release java.vm.specification.name = Java Virtual Machine Specification PID = 20380 java.runtime.version = 1.8.0_60-b27 java.awt.graphicsenv = sun.awt.Win32GraphicsEnvironment os.arch = amd64 java.endorsed.dirs = D:\work\java\jdk1.8.0_60\jre\lib\endorsed line.separator = java.io.tmpdir = C:\Users\ADMINI~1\AppData\Local\Temp\ java.vm.specification.vendor = Oracle Corporation user.variant = os.name = Windows 10 sun.jnu.encoding = GBK java.library.path = D:\work\java\jdk1.8.0_60\bin;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\NVIDIA Corporation\PhysX\Common;D:\work\java\jdk1.8.0_60\bin;D:\work\java\jdk1.8.0_60\jre\bin;D:\work\apache-maven-3.5.0\bin;C:\Program Files\Intel\WiFi\bin\;C:\Program Files\Common Files\Intel\WirelessCommon\;D:\work\git\Git\cmd;C:\Program Files\MySQL\MySQL Shell 8.0\bin\;. spring.beaninfo.ignore = true java.class.version = 52.0 java.specification.name = Java Platform API Specification sun.management.compiler = HotSpot 64-Bit Tiered Compilers os.version = 10.0 user.home = C:\Users\Administrator user.timezone = Asia/Shanghai catalina.useNaming = false java.awt.printerjob = sun.awt.windows.WPrinterJob file.encoding = GBK @appId = cloud-eureka java.specification.version = 1.8 catalina.home = C:\Users\Administrator\AppData\Local\Temp\tomcat.1038740370446942821.5000 user.name = Administrator java.class.path = cloud-eureka-1.0.0.jar java.vm.specification.version = 1.8 sun.arch.data.model = 64 sun.java.command = cloud-eureka-1.0.0.jar java.home = D:\work\java\jdk1.8.0_60\jre user.language = zh java.specification.vendor = Oracle Corporation org.apache.logging.log4j.assignedSequences = 16294 awt.toolkit = sun.awt.windows.WToolkit java.vm.info = mixed mode java.version = 1.8.0_60 java.ext.dirs = D:\work\java\jdk1.8.0_60\jre\lib\ext;C:\Windows\Sun\Java\lib\ext sun.boot.class.path = D:\work\java\jdk1.8.0_60\jre\lib\resources.jar;D:\work\java\jdk1.8.0_60\jre\lib\rt.jar;D:\work\java\jdk1.8.0_60\jre\lib\sunrsasign.jar;D:\work\java\jdk1.8.0_60\jre\lib\jsse.jar;D:\work\java\jdk1.8.0_60\jre\lib\jce.jar;D:\work\java\jdk1.8.0_60\jre\lib\charsets.jar;D:\work\java\jdk1.8.0_60\jre\lib\jfr.jar;D:\work\java\jdk1.8.0_60\jre\classes java.awt.headless = true java.vendor = Oracle Corporation sun.stderr.encoding = ms936 catalina.base = C:\Users\Administrator\AppData\Local\Temp\tomcat.1038740370446942821.5000 file.separator = \ java.vendor.url.bug = http://bugreport.sun.com/bugreport/ sun.io.unicode.encoding = UnicodeLittle sun.cpu.endian = little sun.stdout.encoding = ms936 sun.desktop = windows sun.cpu.isalist = amd64
出现一系列java系统参数。
3.jstack
查找一个死锁,我们看如下代码:
public static void main(String[] args) { new Thread(() -> { synchronized (lock1) { try { System.out.println("thread1 begin"); Thread.sleep(5000); } catch (InterruptedException e) { } synchronized (lock2) { System.out.println("thread1 end"); } } }).start(); new Thread(() -> { synchronized (lock2) { try { System.out.println("thread2 begin"); Thread.sleep(5000); } catch (InterruptedException e) { } synchronized (lock1) { System.out.println("thread2 end"); } } }).start(); System.out.println("main thread end"); }
这是一个死锁程序,我们运行起来;然后找到pid,输入命令(jstack pid):
2020-08-11 11:13:26 Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.60-b23 mixed mode): "DestroyJavaVM" #13 prio=5 os_prio=0 tid=0x00000000034b9000 nid=0x2d24 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Thread-1" #12 prio=5 os_prio=0 tid=0x000000001a18e000 nid=0x5524 waiting for monitor entry [0x000000001ab8f000] java.lang.Thread.State: BLOCKED (on object monitor) at com.ghsy.user.test.DeadLockTest.lambda$main$1(DeadLockTest.java:30) - waiting to lock <0x00000000d6530650> (a java.lang.Object) - locked <0x00000000d6530660> (a java.lang.Object) at com.ghsy.user.test.DeadLockTest$$Lambda$2/917142466.run(Unknown Source) at java.lang.Thread.run(Thread.java:745) "Thread-0" #11 prio=5 os_prio=0 tid=0x000000001a1a2800 nid=0x5248 waiting for monitor entry [0x000000001aa8f000] java.lang.Thread.State: BLOCKED (on object monitor) at com.ghsy.user.test.DeadLockTest.lambda$main$0(DeadLockTest.java:17) - waiting to lock <0x00000000d6530660> (a java.lang.Object) - locked <0x00000000d6530650> (a java.lang.Object) at com.ghsy.user.test.DeadLockTest$$Lambda$1/305808283.run(Unknown Source) at java.lang.Thread.run(Thread.java:745) "Service Thread" #10 daemon prio=9 os_prio=0 tid=0x0000000019f06800 nid=0x25d4 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C1 CompilerThread2" #9 daemon prio=9 os_prio=2 tid=0x0000000019eac000 nid=0x5520 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread1" #8 daemon prio=9 os_prio=2 tid=0x0000000019efc000 nid=0x4cf4 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" #7 daemon prio=9 os_prio=2 tid=0x0000000019d12800 nid=0x57b8 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Monitor Ctrl-Break" #6 daemon prio=5 os_prio=0 tid=0x0000000019d10800 nid=0x4e04 runnable [0x000000001a48e000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:170) at java.net.SocketInputStream.read(SocketInputStream.java:141) at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284) at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326) at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178) - locked <0x00000000d64a9120> (a java.io.InputStreamReader) at java.io.InputStreamReader.read(InputStreamReader.java:184) at java.io.BufferedReader.fill(BufferedReader.java:161) at java.io.BufferedReader.readLine(BufferedReader.java:324) - locked <0x00000000d64a9120> (a java.io.InputStreamReader) at java.io.BufferedReader.readLine(BufferedReader.java:389) at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:64) "Attach Listener" #5 daemon prio=5 os_prio=2 tid=0x0000000018207800 nid=0xdb4 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" #4 daemon prio=9 os_prio=2 tid=0x00000000181f6800 nid=0x30e4 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" #3 daemon prio=8 os_prio=1 tid=0x00000000035a8800 nid=0x12c in Object.wait() [0x000000001952e000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000d5f070b8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143) - locked <0x00000000d5f070b8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209) "Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x00000000035a5000 nid=0x2f8c in Object.wait() [0x000000001942f000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000d5f06af8> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:502) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:157) - locked <0x00000000d5f06af8> (a java.lang.ref.Reference$Lock) "VM Thread" os_prio=2 tid=0x00000000181a8000 nid=0x356c runnable "GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00000000034ce800 nid=0x56ec runnable "GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00000000034d0800 nid=0x1af4 runnable "GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00000000034d2000 nid=0x53c runnable "GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00000000034d3800 nid=0x365c runnable "VM Periodic Task Thread" os_prio=2 tid=0x0000000019f85800 nid=0x2ab4 waiting on condition JNI global references: 336 Found one Java-level deadlock: //发现一个java死锁 ============================= "Thread-1": waiting to lock monitor 0x00000000181af6e8 (object 0x00000000d6530650, a java.lang.Object), which is held by "Thread-0" "Thread-0": waiting to lock monitor 0x00000000181accf8 (object 0x00000000d6530660, a java.lang.Object), which is held by "Thread-1" Java stack information for the threads listed above: =================================================== "Thread-1": at com.ghsy.user.test.DeadLockTest.lambda$main$1(DeadLockTest.java:30) - waiting to lock <0x00000000d6530650> (a java.lang.Object) - locked <0x00000000d6530660> (a java.lang.Object) at com.ghsy.user.test.DeadLockTest$$Lambda$2/917142466.run(Unknown Source) at java.lang.Thread.run(Thread.java:745) "Thread-0": at com.ghsy.user.test.DeadLockTest.lambda$main$0(DeadLockTest.java:17) - waiting to lock <0x00000000d6530660> (a java.lang.Object) - locked <0x00000000d6530650> (a java.lang.Object) at com.ghsy.user.test.DeadLockTest$$Lambda$1/305808283.run(Unknown Source) at java.lang.Thread.run(Thread.java:745) Found 1 deadlock.
上面是命令找寻死锁,我们再用jvisualvm来看看:
直接就检测到线程死锁了,然后看dump文件:
跟上面的命令行查看结果是一样的。
4.jstat
4.1垃圾回收统计
输入命令(jstat -gc pid):
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
8704.0 10240.0 8680.1 0.0 327168.0 254875.7 90624.0 12922.0 52312.0 49692.9 7296.0 6748.5 16 0.111 2 0.126 0.237
S0C:第一个幸存区的大小
S1C:第二个幸存区的大小
S0U:第一个幸存区的使用大小
S1U:第二个幸存区的使用大小
EC:伊甸园区的大小
EU:伊甸园区的使用大小
OC:老年代大小
OU:老年代使用大小
MC:方法区大小(元空间)
MU:方法区使用大小
CCSC:压缩类空间大小
CCSU:压缩类空间使用大小
YGC:年轻代垃圾回收次数
YGCT:年轻代垃圾回收消耗时间,单位s
FGC:老年代垃圾回收次数
FGCT:老年代垃圾回收消耗时间,单位s
GCT:垃圾回收消耗总时间,单位s
这个命令可以查看gc回收的信息,如果按照规律时间去获取gc信息,可以计算一些区域的对象增长情况:
输入命令(jstat -gc pid 1000 10)(1s中打印一次gc情况,打印10次):
8704.0 10240.0 8680.1 0.0 327168.0 254875.7 90624.0 12922.0 52312.0 49692.9 7296.0 6748.5 16 0.111 2 0.126 0.237 8704.0 10240.0 8680.1 0.0 327168.0 254875.7 90624.0 12922.0 52312.0 49692.9 7296.0 6748.5 16 0.111 2 0.126 0.237 8704.0 10240.0 8680.1 0.0 327168.0 254875.7 90624.0 12922.0 52312.0 49692.9 7296.0 6748.5 16 0.111 2 0.126 0.237 8704.0 10240.0 8680.1 0.0 327168.0 254875.7 90624.0 12922.0 52312.0 49692.9 7296.0 6748.5 16 0.111 2 0.126 0.237 8704.0 10240.0 8680.1 0.0 327168.0 254875.7 90624.0 12922.0 52312.0 49692.9 7296.0 6748.5 16 0.111 2 0.126 0.237 8704.0 10240.0 8680.1 0.0 327168.0 254875.7 90624.0 12922.0 52312.0 49692.9 7296.0 6748.5 16 0.111 2 0.126 0.237 8704.0 10240.0 8680.1 0.0 327168.0 254875.7 90624.0 12922.0 52312.0 49692.9 7296.0 6748.5 16 0.111 2 0.126 0.237 8704.0 10240.0 8680.1 0.0 327168.0 254875.7 90624.0 12922.0 52312.0 49692.9 7296.0 6748.5 16 0.111 2 0.126 0.237 8704.0 10240.0 8680.1 0.0 327168.0 254875.7 90624.0 12922.0 52312.0 49692.9 7296.0 6748.5 16 0.111 2 0.126 0.237 8704.0 10240.0 8680.1 0.0 327168.0 254875.7 90624.0 12922.0 52312.0 49692.9 7296.0 6748.5 16 0.111 2 0.126 0.237
如果gc比较频繁的话,上面就可以体现出来,从里面去找问题分析。
4.2堆内存统计
输入命令(jstat -gccapacity pid):
NGCMN NGCMX NGC S0C S1C EC OGCMN OGCMX OGC OC MCMN MCMX MC CCSMN CCSMX CCSC YGC FGC
43520.0 689152.0 350208.0 8704.0 10240.0 327168.0 87552.0 1379328.0 90624.0 90624.0 0.0 1093632.0 52312.0 0.0 1048576.0 7296.0 16 2
NGCMN:新生代最小容量
NGCMX:新生代最大容量
NGC:当前新生代容量
S0C:第一个幸存区大小
S1C:第二个幸存区的大小
EC:伊甸园区的大小
OGCMN:老年代最小容量
OGCMX:老年代最大容量
OGC:当前老年代大小
OC:当前老年代大小
MCMN:最小元数据容量
MCMX:最大元数据容量
MC:当前元数据空间大小
CCSMN:最小压缩类空间大小
CCSMX:最大压缩类空间大小
CCSC:当前压缩类空间大小
YGC:年轻代gc次数
FGC:老年代GC次数
如果需要做堆内存分析,方法跟gc分析一样,命令后面加入时间和次数。(不在过多赘述)
4.3内存区域大小情况统计
新生代内存统计(jstat -gcnewcapacity pid):
NGCMN NGCMX NGC S0CMX S0C S1CMX S1C ECMX EC YGC FGC
43520.0 689152.0 350208.0 229376.0 8704.0 229376.0 10240.0 688128.0 327168.0 16 2
NGCMN:新生代最小容量
NGCMX:新生代最大容量
NGC:当前新生代容量
S0CMX:最大幸存1区大小
S0C:当前幸存1区大小
S1CMX:最大幸存2区大小
S1C:当前幸存2区大小
ECMX:最大伊甸园区大小
EC:当前伊甸园区大小
YGC:年轻代垃圾回收次数
FGC:老年代回收次数
老年代内存统计,输入命令(jstat -gcoldcapacity pid):
OGCMN OGCMX OGC OC YGC FGC FGCT GCT
87552.0 1379328.0 90624.0 90624.0 16 2 0.126 0.237
OGCMN:老年代最小容量
OGCMX:老年代最大容量
OGC:当前老年代大小
OC:老年代大小
YGC:年轻代垃圾回收次数
FGC:老年代垃圾回收次数
FGCT:老年代垃圾回收消耗时间
GCT:垃圾回收消耗总时间
原空间内存统计,输入命令(jstat -gcmetacapacity pid):
MCMN MCMX MC CCSMN CCSMX CCSC YGC FGC FGCT GCT
0.0 1093632.0 52312.0 0.0 1048576.0 7296.0 16 2 0.126 0.237
MCMN:最小元数据容量
MCMX:最大元数据容量
MC:当前元数据空间大小
CCSMN:最小压缩类空间大小
CCSMX:最大压缩类空间大小
CCSC:当前压缩类空间大小
YGC:年轻代垃圾回收次数
FGC:老年代垃圾回收次数
FGCT:老年代垃圾回收消耗时间
GCT:垃圾回收消耗总时间
4.4内存区域回收情况统计
新生代垃圾回收统计,输入命令(jstat -gcnew pid):
S0C S1C S0U S1U TT MTT DSS EC EU YGC YGCT
8704.0 10240.0 8680.1 0.0 6 15 10240.0 327168.0 258147.4 16 0.111
S0C:第一个幸存区的大小
S1C:第二个幸存区的大小
S0U:第一个幸存区的使用大小
S1U:第二个幸存区的使用大小
TT:对象在新生代存活的次数
MTT:对象在新生代存活的最大次数
DSS:期望的幸存区大小
EC:伊甸园区的大小
EU:伊甸园区的使用大小
YGC:年轻代垃圾回收次数
YGCT:年轻代垃圾回收消耗时间
老年代回收统计,输入命令(jstat -gcold pid):
MC MU CCSC CCSU OC OU YGC FGC FGCT GCT
52312.0 49692.9 7296.0 6748.5 90624.0 12922.0 16 2 0.126 0.237
MC:方法区大小
MU:方法区使用大小
CCSC:压缩类空间大小
CCSU:压缩类空间使用大小
OC:老年代大小
OU:老年代使用大小
YGC:年轻代垃圾回收次数
FGC:老年代垃圾回收次数
FGCT:老年代垃圾回收消耗时间
GCT:垃圾回收消耗总时间
注(上述命令如果需要分析都只需要在后面跟时间和次数)。
5.上述工具优化思路
5.1JVM运行情况预估
用 jstat gc -pid 命令可以计算出如下一些关键数据,有了这些数据就可以采用之前介绍过的优化思路,先给自己的系统设置一些初始性的 JVM参数,比如堆内存大小,年轻代大小,Eden和Survivor的比例,老年代的大小,大对象的阈值,大龄对象进入老年代的阈值等。
5.2年轻代对象增长的速率
可以执行命令 jstat -gc pid 1000 10 (每隔1秒执行1次命令,共执行10次),通过观察EU(eden区的使用)来估算每秒eden大概新增多少对 象,如果系统负载不高,可以把频率1秒换成1分钟,甚至10分钟来观察整体情况。注意,一般系统可能有高峰期和日常期,所以需要在不 同的时间分别估算不同情况下对象增长速率。
5.3Young GC的触发频率和每次耗时
知道年轻代对象增长速率我们就能推根据eden区的大小推算出Young GC大概多久触发一次,Young GC的平均耗时可以通过 YGCT/YGC 公式算出,根据结果我们大概就能知道系统大概多久会因为Young GC的执行而卡顿多久。
5.4每次Young GC后有多少对象存活和进入老年代
这个因为之前已经大概知道Young GC的频率,假设是每5分钟一次,那么可以执行命令 jstat -gc pid 300000 10 ,观察每次结果eden, survivor和老年代使用的变化情况,在每次gc后eden区使用一般会大幅减少,survivor和老年代都有可能增长,这些增长的对象就是每次 Young GC后存活的对象,同时还可以看出每次Young GC后进去老年代大概多少对象,从而可以推算出老年代对象增长速率。
5.5Full GC的触发频率和每次耗时
知道了老年代对象的增长速率就可以推算出Full GC的触发频率了,Full GC的每次耗时可以用公式 FGCT/FGC 计算得出。
6.gc日志
我们把eureka服务先停了,加入启动参数(‐XX:+PrintGCDetails ‐XX:+PrintGCTimeStamps ‐XX:+PrintGCDateStamps ‐Xloggc:./gc.log):
我们看是否生成文件了?
我们打开这个文件:
Java HotSpot(TM) 64-Bit Server VM (25.60-b23) for windows-amd64 JRE (1.8.0_60-b27), built on Aug 4 2015 11:06:27 by "java_re" with MS VC++ 10.0 (VS2010) Memory: 4k page, physical 8266092k(1929292k free), swap 24910288k(3898600k free) CommandLine flags: -XX:InitialHeapSize=132257472 -XX:MaxHeapSize=2116119552 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 2020-08-11T12:23:05.886+0800: 0.393: [GC (Allocation Failure) [PSYoungGen: 33280K->2720K(38400K)] 33280K->2736K(125952K), 0.0035626 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2020-08-11T12:23:06.399+0800: 0.904: [GC (Allocation Failure) [PSYoungGen: 36000K->3193K(38400K)] 36016K->3217K(125952K), 0.0030169 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2020-08-11T12:23:06.544+0800: 1.049: [GC (Allocation Failure) [PSYoungGen: 36473K->3548K(38400K)] 36497K->3644K(125952K), 0.0030608 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2020-08-11T12:23:06.780+0800: 1.286: [GC (Allocation Failure) [PSYoungGen: 36828K->4924K(71680K)] 36924K->5028K(159232K), 0.0046017 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 2020-08-11T12:23:06.948+0800: 1.454: [GC (Allocation Failure) [PSYoungGen: 71484K->5113K(71680K)] 71588K->5529K(159232K), 0.0107722 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 2020-08-11T12:23:07.049+0800: 1.555: [GC (Allocation Failure) [PSYoungGen: 71673K->5420K(138752K)] 72089K->5844K(226304K), 0.0054675 secs] [Times: user=0.03 sys=0.00, real=0.00 secs] 2020-08-11T12:23:07.306+0800: 1.811: [GC (Allocation Failure) [PSYoungGen: 138028K->3088K(139264K)] 138452K->6418K(226816K), 0.0105116 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 2020-08-11T12:23:07.322+0800: 1.828: [GC (Metadata GC Threshold) [PSYoungGen: 11465K->1584K(271872K)] 14795K->6409K(359424K), 0.0039439 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2020-08-11T12:23:07.326+0800: 1.832: [Full GC (Metadata GC Threshold) [PSYoungGen: 1584K->0K(271872K)] [ParOldGen: 4825K->6082K(48128K)] 6409K->6082K(320000K), [Metaspace: 20640K->20638K(1067008K)], 0.0500660 secs] [Times: user=0.14 sys=0.00, real=0.05 secs] 2020-08-11T12:23:08.421+0800: 2.926: [GC (Allocation Failure) [PSYoungGen: 265216K->2964K(271872K)] 271298K->9054K(320000K), 0.0055440 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 2020-08-11T12:23:09.479+0800: 3.985: [GC (Allocation Failure) [PSYoungGen: 268180K->6381K(385024K)] 274270K->12479K(433152K), 0.0116420 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 2020-08-11T12:23:09.757+0800: 4.262: [GC (Metadata GC Threshold) [PSYoungGen: 44390K->992K(391680K)] 50488K->12966K(439808K), 0.0093152 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 2020-08-11T12:23:09.766+0800: 4.272: [Full GC (Metadata GC Threshold) [PSYoungGen: 992K->0K(391680K)] [ParOldGen: 11974K->12147K(70656K)] 12966K->12147K(462336K), [Metaspace: 34083K->34083K(1079296K)], 0.0973103 secs] [Times: user=0.30 sys=0.00, real=0.10 secs] 2020-08-11T12:23:12.675+0800: 7.181: [GC (Allocation Failure) [PSYoungGen: 384000K->5736K(521728K)] 396147K->17883K(592384K), 0.0115240 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
上面可以看到我们的jvm启动参数,我们从左往右看一行gc日志分别是:
gc发生时间,
哪个区域发生gc,
每次gc的gc前区域大小,
gc后内存区域大小,
区域总大小,
然后是gc耗时,
gc日志分析工具(https://gceasy.io):
我们打开这个网站:
选中我们生成的gc日志文件,点击Analyze:
jvm内存大小。
区域gc前和gc后的比较。
当然,最主要的是这个网站可以给出优化建议,如果自己优化搞不定,可以花钱去上面购买优化建议: