Arthas 和 GC 的那点事:动态日志,强制 GC
source link: https://www.v2ex.com/t/792635
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.
Arthas
是 Alibaba 开源的 Java 诊断工具,深受开发者喜爱。
一、线上应用怎么动态打印 GC 日志?
小白正在上班摸鱼,突然运维告警,线上应用突发 GC 问题,GC 时间变长,响应变慢。 火速登陆机器,想检查 GC 日志,忽然发现,线上应用 JVM 参数没有打印 GC 信息😂。
如果增加 JVM 参数,那么要重启应用,现场就没有了,怎么办?
Arthas 可以解决这个问题!
二、使用 dashboard 命令查看 GC 信息
在 dashboard 命令里可以直接看到 GC 的数据,次数和时间:
三、使用 vmoption 命令动态打开 GC 日志
$ vmoption PrintGC true
Successfully updated the vm option.
NAME BEFORE-VALUE AFTER-VALUE
------------------------------------
PrintGC false true
$ vmoption PrintGCDetails true
Successfully updated the vm option.
NAME BEFORE-VALUE AFTER-VALUE
-------------------------------------------
PrintGCDetails false true
打开上面两个选项之后,当应用发生 GC 时,就会在标准输出里打印 GC 日志。
四、使用 vmtool 强制 GC
$ vmtool --action forceGc
然后查看应用的标准输出,可以发现有 GC 日志:
[GC (JvmtiEnv ForceGarbageCollection) [PSYoungGen: 2184K->352K(76288K)] 19298K->17474K(166912K), 0.0011562 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
[Full GC (JvmtiEnv ForceGarbageCollection) [PSYoungGen: 352K->0K(76288K)] [ParOldGen: 17122K->16100K(90112K)] 17474K->16100K(166400K), [Metaspace: 20688K->20688K(1069056K)], 0.0232947 secs] [Times: user=0.14 sys=0.01, real=0.03 secs]
五、更多 GC 开关
5.1 打印 GC ID
$ vmoption PrintGCID true
Successfully updated the vm option.
NAME BEFORE-VALUE AFTER-VALUE
--------------------------------------
PrintGCID false true
则 GC 日志里会有#
的 ID:
#5: [GC (JvmtiEnv ForceGarbageCollection) [PSYoungGen: 9219K->352K(76288K)] 25319K->16460K(166400K), 0.0017758 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
5.2 打印 GC 时间戳
$ vmoption PrintGCDateStamps true
Successfully updated the vm option.
NAME BEFORE-VALUE AFTER-VALUE
----------------------------------------------
PrintGCDateStamps false true
则 GC 日志会带上时间:
2021-07-22T17:54:08.820-0800: [GC (JvmtiEnv ForceGarbageCollection) 21111K->16334K(160768K), 0.0015284 secs]
2021-07-22T17:54:08.822-0800: [Full GC (JvmtiEnv ForceGarbageCollection) 16334K->16105K(158720K), 0.0191751 secs]
$ vmoption PrintGCTimeStamps true
Successfully updated the vm option.
NAME BEFORE-VALUE AFTER-VALUE
----------------------------------------------
PrintGCTimeStamps false true
则 GC 日志会带上应用启动时间:
1087.493: [GC (JvmtiEnv ForceGarbageCollection) 18416K->16360K(154624K), 0.0014647 secs]
1087.494: [Full GC (JvmtiEnv ForceGarbageCollection) 16360K->16105K(153600K), 0.0164804 secs]
5.3 在 GC 前后,执行 heapdump
在排查 GC 问题时,我们有时需要对比 GC 前后,生成 heapdump 文件,然后再做对比。
- 打开 HeapDumpBeforeFullGC 开关,可以在 GC 前生成 heapdump 文件
- 打开 HeapDumpAfterFullGC 开关,可以在 GC 结束后生成 heapdump 文件
$ vmoption HeapDumpBeforeFullGC true
Successfully updated the vm option.
NAME BEFORE-VALUE AFTER-VALUE
-------------------------------------------------
HeapDumpBeforeFullGC false true
$ vmtool --action forceGc
再使用vmtool --action forceGc
强制 GC,则可以在 GC 日志中发现 heapdump 信息,并且在应用目录下会生成 heapdump hprof 文件:
#9: [Heap Dump (before full gc): Dumping heap to java_pid69445.hprof ...
Heap dump file created [23915304 bytes in 0.107 secs]
再使用其它堆分析软件,对比两个 heapdump 文件,就可以知道 GC 到底回收了哪些对象。
5.4 在 GC 前后,打印类直方图
排查 GC 问题时,我们有时需要统计每个类加载的数量和占用内存大小。
- 打开
PrintClassHistogramBeforeFullGC
开关,可以在 GC 前打印类直方图 - 打开
PrintClassHistogramAfterFullGC
开关,可以在 GC 结束后打印类直方图
$ vmoption PrintClassHistogramBeforeFullGC true
Successfully updated the vm option.
NAME BEFORE-VALUE AFTER-VALUE
------------------------------------------------------------
PrintClassHistogramBeforeFullGC false true
$ vmtool --action forceGc
再使用vmtool --action forceGc
强制 GC,在 GC 日志中会打印类直方图,可以直观知道每个类的 instances 数量,占用内存大小:
#13: [Class Histogram (before full gc):
num #instances #bytes class name
----------------------------------------------
1: 24519 5783400 [C
2: 5648 5102712 [B
3: 3685 888128 [Ljava.lang.Object;
4: 3255 619560 [I
5: 24263 582312 java.lang.String
6: 4227 475320 java.lang.Class
7: 1288 402112 [Ljava.util.HashMap$Node;
8: 75 296160 [Ljava.nio.channels.SelectionKey;
9: 6759 216288 java.util.HashMap$Node
10: 2069 182072 java.lang.reflect.Method
11: 3326 133040 java.util.LinkedHashMap$Entry
- 通过
dashboard
命令查看 GC 统计信息 - 通过
vmoption
命令动态打开 GC 开关,GC 前后 heapdump,打印类直方图 - 通过
vmtool
命令可以强制 GC
最后打个广告,我们正在寻找小伙伴,特别是深圳的同学,欢迎大家加入。
Recommend
About Joyk
Aggregate valuable and interesting links.
Joyk means Joy of geeK