线上GC日志如何查看
附上案例的jvm参数
-server
-Xms2048M
-Xmx2048M
-Xss256k
-XX:NewSize=512M
-XX:MaxNewSize=512M
-XX:SurvivorRatio=8
-XX:CMSInitiatingOccupancyFraction=50
-XX:+AggressiveOpts
-XX:+UseBiasedLocking
-XX:+DisableExplicitGC
-XX:+UseParNewGC
-XX:+UseConcMarkSweepGC
-XX:MaxTenuringThreshold=15
-XX:+CMSParallelRemarkEnabled
-XX:+UseCMSCompactAtFullCollection
-XX:LargePageSizeInBytes=128m
-XX:+UseFastAccessorMethods
-XX:+UseCMSInitiatingOccupancyOnly
-Duser.timezone=Asia/Shanghai
-XX:+PrintGCTimeStamps
-XX:+PrintGCDetails
-XX:+UseGCLogFileRotation
-XX:GCLogFileSize=512M
-Xloggc:/log/admin/gc.log
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/log/admin/heap/
-Djava.awt.headless=true'
一、gc.log日志
-Xloggc:/log/admin/gc.log 这行命令则可以指定gc输出日志
- young Gc分析
11629.462: [GC (Allocation Failure) 11629.462: [ParNew: 429718K->4154K(471872K), 0.0143104 secs] 576435K->150877K(2044736K), 0.0144074 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
11679.009: [GC (Allocation Failure) 11679.009: [ParNew: 423610K->2629K(471872K), 0.0123434 secs] 570333K->149356K(2044736K), 0.0124526 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
11734.620: [GC (Allocation Failure) 11734.621: [ParNew: 422085K->1344K(471872K), 0.0122582 secs] 568812K->148074K(2044736K), 0.0123579 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
11825.884: [GC (Allocation Failure) 11825.884: [ParNew: 420800K->1393K(471872K), 0.0128264 secs] 567530K->148133K(2044736K), 0.0129706 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
GC (Allocation Failure): 表示是对象分配失败执行GC
11629.462 :的意思系统运行以后过了多少秒发生了本次GC,这里则是11629秒之后发生了本次GC
[ParNew: 429718K->4154K(471872K), 0.0143104 secs] :ParNew表示垃圾回收器
429718K->4154K(471872K), 0.0143104 secs 的意思是执行gc之前年轻代(统计eden区和其中一个Survivor区的内存)使用了429718KB,执行之后年轻代还存活4154KB,本次gc耗时0.0143104 secs(秒)。
576435K->150877K(2044736K), 0.0144074 secs 表示整个堆执行完本次gc的内存情况
[Times: user=0.02 sys=0.00, real=0.01 secs] 则是本次gc耗费的时间
- full Gc 分析
18.383: [GC (CMS Initial Mark) [1 CMS-initial-mark: 78665K(1572864K)] 137492K(2044736K), 0.0160823 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
18.399: [CMS-concurrent-mark-start]
18.544: [CMS-concurrent-mark: 0.138/0.144 secs] [Times: user=0.28 sys=0.00, real=0.15 secs]
18.544: [CMS-concurrent-preclean-start]
18.547: [CMS-concurrent-preclean: 0.004/0.004 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
18.547: [CMS-concurrent-abortable-preclean-start]
20.005: [GC (Allocation Failure) 20.005: [ParNew20.015: [CMS-concurrent-abortable-preclean: 1.329/1.468 secs] [Times: user=2.72 sys=0.00, real=1.47 secs]
: 462334K->42351K(471872K), 0.0526851 secs] 540999K->126061K(2044736K), 0.0527633 secs] [Times: user=0.10 sys=0.01, real=0.05 secs]
20.059: [GC (CMS Final Remark) [YG occupancy: 42535 K (471872 K)]20.059: [Rescan (parallel) , 0.0199761 secs]20.079: [weak refs processing, 0.0000367 secs]20.079: [class unloading, 0.0298806 secs]20.109: [scrub symbol table, 0.0123509 secs]20.121: [scrub string table, 0.0011941 secs][1 CMS-remark: 83709K(1572864K)] 126245K(2044736K), 0.0642231 secs] [Times: user=0.08 sys=0.00, real=0.07 secs]
20.128: [CMS-concurrent-sweep-start]
20.164: [CMS-concurrent-sweep: 0.035/0.036 secs] [Times: user=0.07 sys=0.00, real=0.04 secs]
20.164: [CMS-concurrent-reset-start]
20.166: [CMS-concurrent-reset: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
二、jstat -gc pid
首先查看java进程的pid
- jps命令
- ps -ef|grep java
执行jstat -gc 26229 1000 10
这个命令就是每隔1秒更新出来最新的一行jstat统计信息,一共执行10次jstat统计
S0C:这是From Survivor区的大小
S1C:这是To Survivor区的大小
S0U:这是From Survivor区当前使用的内存大小
S1U:这是To Survivor区当前使用的内存大小
EC:这是Eden区的大小
EU:这是Eden区当前使用的内存大小
OC:这是老年代的大小
OU:这是老年代当前使用的内存大小
MC:这是方法区(永久代、元数据区)的大小MU:这是方法区(永久代、元数据区)的当前使用的内存大小
YGC:这是系统运行迄今为止的Young GC次数
YGCT:这是Young GC的耗时
FGC:这是系统运行迄今为止的Full GC次数
FGCT:这是Full GC的耗时
GCT:这是所有GC的总耗时
- 其他的jstat命令
除了上面的jstat -gc命令是最常用的以外,他还有一些命令可以看到更多详细的信息,如下所示:
jstat -gccapacity PID:堆内存分析
jstat -gcnew PID:年轻代GC分析,这里的TT和MTT可以看到对象在年轻代存活的年龄和存活的最大年龄
jstat -gcnewcapacity PID:年轻代内存分析
jstat -gcold PID:老年代GC分析
jstat -gcoldcapacity PID:老年代内存分析
jstat -gcmetacapacity PID:元数据区内存分析
这个命令就非常关键了
可以分析出每秒对象的增速,每秒产生多少对象,然后再根据具体情况调整jvm参数。
统计youngGc触发的频率以及耗时。多久触发一次younGc 高峰期和正常的时候都一目了然。
每次youngGc之后有多少对象进入老年代。
fullGc的触发时机。
三、jmap 和jhat
jmap -heap PID
这个信息会打印出来堆内存相关的一些参数设置,然后就是当前堆内存里的一些基本各个区域的情况
其实jmap命令比较有用的一个使用方式,是如下的:
map -histo PID
当前jvm中的对象对内存占用的情况
jmap -dump:live,format=b,file=dump.hprof PID
这个命令会在当前目录下生成一个dump.hrpof文件,这里是二进制的格式,你不能直接打开看的,他把这一时刻JVM堆内存里所有对 象的快照放到文件里去了,供你后续去分析
jhat dump.hprof -port 7000 接着你就在浏览器上访问当前这台机器的7000
jhat内置了web服务器,他会支持你通过浏览器来以图形化的方式分析堆转储快照