目录
一、JVM配置参数
二、GC回收日志分析
三、虚拟机性能监控和故障处理工具
1.命令工具
1)：基础工具
2)：性能监控和故障处理
2.可视化工具
四、JVM常出现问题
五、参考资料
一、JVM配置参数
HotSpot直到JDK9才提供统一的日志处理框架，其所有日志都归结到-Xlog参数，详细见《JVM的-Xlog使用方法》。但笔者使用的是JDK8，其配置参数如下表所示。
参看JVM所有初始化配置参数-XX:+PrintFlagsInitial、最终参数-XX:+PrintFlagsFinal、覆盖的项-XX:+PrintCommandLineFlags，如下使用方式。
java -XX:+PrintFlagsFinal
| 分类 | 参数 | 说明 |
| 常用 | -Xms20M | 初始化堆大小 |
| -Xmx20M | 堆的最大大小，若是与-Xms相同，则不可扩展 | |
| -Xss108K | 1.栈容量大小； 2.默认大小与当前java的JVM版本与OS有关 | |
| -Xmn10M | 1.Eden区大小； 2.与同时配置-XX:newSize、-XX:MaxnewSize两值相同 | |
| -XX:NewSize=512M | 新生代初始内存大小，小于-Xms的值 | |
| -XX:MaxNewSize=512M | 新生代可被分配的内存最大上限，小于-Xmx的值； | |
| -XX:ConcGCThreads | 并发的线程数量 | |
| -XX:MaxDirectMemorySize=10M | 1.设置堆外内存最大值； 2.若没有指定大小则与-Xmx大小一致 | |
| -XX:PreBlockSpin | 锁自旋次数，默认10次 | |
| GC日志 | -XX:+PrintGC | 输出GC日志，类似：-verbose:gc |
| -XX:+PrintGCDetails | 打印GC详细信息 | |
| -XX:+PrintGCTimeStamps | 输出JVM启动后在线时长 | |
| -XX:+PrintGCDateStamps | 1.输出GC发生时的时间戳； | |
| -Xloggc:E:/logs/GC-LOG.log | GC日志输出文件路径 | |
| -XX:+PrintHeapAtGC | 每一次GC前和GC后，都打印堆信息 | |
| -XX:+HeapDumpOnOutOfMemoryError | JVM异常退出时，生成Dump堆转储快照，进行分析 | |
| -XX:+PrintGCApplicationConcurrentTime | GC过程中用户线程并发时间 | |
| -XX:+PrintGCApplicationStoppedTime | GC过程中停顿时间 | |
| -XX:+PrintReferenceGC | 输出回收不同引用类型的引用次数及耗时 | |
| -XX:+DisableExplicitGC | 1.禁止人工触发GC; 2.禁止System.gc()会触发一次Full GC | |
| -Xnoclassgc | 关闭类回收，默认允许类回收（即：没有该参数） | |
| -XX:+UseTLAB | 1.使用TLAB，默认开启； 2.TLAB（Thread Local Allocation Buffer）每个线程单独分配了一个缓冲区（线程私有）；从GC看都可以回收 | |
| -XX:TLABSize | 设置每个线程的缓冲区大小，默认0 | |
| -XX:+PrintTLAB | 输出TLAB的使用情况 | |
| Parallel Scavenge | -XX:+UseParallelGC | 1.使用Parallel Scavenge + Serial Old组合； 2.JDK9前的server下默认打开 |
| -XX:+UseParallelOldGC | 使用Parallel Scavenge + Parallel Old组合 | |
| -XX:SurvivorRatio | Eden区与Survivor的容量比例，默认8:1 | |
| -XX:MaxTenuringThreshold | 晋升到老生代年龄阈值，默认15 | |
| -XX:PretenureSizeThreshold | 1.新生代对象大小阈值，大于该值时直接进入老年代； 2.默认0（先存入新生代） | |
| -XX:+UseAdaptiveSizePolicy | 允许动态调整堆中各区域的大小，默认true | |
| -XX:GCTimeRatio | 1.GC时间占总时间的比率； 2.默认值99（允许1%的GC时间） 3.只有Parallel Scavenge使用 | |
| -XX:+ParallelGCThreads | 并行收集的线程数，一般与CPU核数相同 | |
| -XX:MaxGCPauseMillis | 1.设置GC最大停止时间； 2.G1收集器也有该参数 | |
| G1 | -XX:+UseG1GC | 使用G1收集器，JDK9默认开启 |
| -XX:MetaspaceSize=256M | 初始化元空间大小，64位默认21M | |
| -XX:MaxMetaspaceSize=512M | 最大元空间大小 | |
| -XX:MaxGCPauseMillis=200 | 1.GC的停顿时间，默认200ms； 2.一个建议时间，GC会尝试用各种手段达到这个时间，比如减小年轻代 | |
| -XX:GCPauseIntervalMillis | 两次GC操作之间的时间间隔，默认0 | |
| -XX:G1HeapRegionSize=1 | 1.Region分区大小，建议逐渐增大该值：1 2 4 8 16 32； 2.Region增加，垃圾的存活时间更长，GC间隔更长，但每次GC的时间也会更长 | |
| -XX:G1NewSizePercent | 新生代最小比例，默认为5% | |
| -XX:G1MaxNewSizePercent | 新生代最大比例，默认为60% | |
| -XX:InitiatingHeapOccupancyPercent | 触发标记周期的堆占用率阈值，默认45% | |
二、GC回收日志分析
服务的启动restart.sh脚本，如下所示。JDK8使用的是G1收集器。
#!/bin/bash
echo "$(date '+%Y-%m-%d %H:%M:%S') kill java"
#kill -9 `pgrep java`
kill -9 $(ps -ef|grep java | grep noms-worldcup.jar | awk '{print $2}')
echo "Sleep 2 Seconds:"
sleep 7
echo "$(date '+%Y-%m-%d %H:%M:%S') start java"
nohup java -XX:+PrintGCDetails -XX:+HeapDumpOnOutOfMemoryError -XX:+UseG1GC -XX:MaxGCPauseMillis=200 -Xloggc:/data/logs/gc.log -Xms1024M -Xmx1024M -Xss512k -XX:NewSize=512M -XX:MaxNewSize=512M -XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=512M -Djava.security.egd=file:/dev/./urandom -Djava.awt.headless=true -Dcom.sun.management.jmxremote -Dcom.sun.management.jmxremote.port=8010 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false -jar -Denv=dev -Dspring.profiles.active=dev instance-test.jar > nohup.out 2>&1 &
echo "$(date '+%Y-%m-%d %H:%M:%S') print java process"
sleep 2
echo "Sleep 2 Seconds:"
echo "$(date '+%Y-%m-%d %H:%M:%S') $(ps -ef |grep java)"G1的执行GC详细日志，如下所示。
20548727.124: [GC pause (G1 Evacuation Pause) (young), 0.0187588 secs]
[Parallel Time: 9.6 ms, GC Workers: 4]
[GC Worker Start (ms): Min: 20548727124.8, Avg: 20548727125.0, Max: 20548727125.2, Diff: 0.4]
[Ext Root Scanning (ms): Min: 4.9, Avg: 5.8, Max: 6.3, Diff: 1.4, Sum: 23.4]
[Update RS (ms): Min: 0.9, Avg: 1.1, Max: 1.3, Diff: 0.4, Sum: 4.4]
[Processed Buffers: Min: 1, Avg: 8.8, Max: 25, Diff: 24, Sum: 35]
[Scan RS (ms): Min: 0.1, Avg: 0.2, Max: 0.4, Diff: 0.3, Sum: 1.0]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1]
[Object Copy (ms): Min: 1.6, Avg: 1.7, Max: 1.7, Diff: 0.2, Sum: 6.7]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4]
[GC Worker Other (ms): Min: 0.0, Avg: 0.3, Max: 1.1, Diff: 1.0, Sum: 1.4]
[GC Worker Total (ms): Min: 9.0, Avg: 9.2, Max: 9.4, Diff: 0.4, Sum: 36.9]
[GC Worker End (ms): Min: 20548727134.2, Avg: 20548727134.2, Max: 20548727134.2, Diff: 0.0]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 1.0 ms]
[Other: 8.2 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 6.1 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.4 ms]
[Humongous Register: 0.0 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 1.0 ms]
[Eden: 508.0M(508.0M)->0.0B(509.0M) Survivors: 4096.0K->3072.0K Heap: 596.7M(1024.0M)->87.4M(1024.0M)]
[Times: user=0.04 sys=0.00, real=0.02 secs] | 内容 | 说明 |
| 20548727.124 | JVM启动到现在的时间（JVM生命时间） |
| [GC pause (G1 Evacuation Pause) (young), 0.0187588 secs] | 1.(young)：年轻代GC； (mixed)：混合gc(年轻代+老年代) 2. (G1 Evacuation Pause)：G1迁移完成，young已满引发的本次GC； (G1 Humongous Allocation)：大对象空间分配申请，引发的本次GC 注意：每一个大对象分配内存时会触发GC尝试，若是当前已处在标记阶段，则不会触发GC回收。 3.意思是：young已满引发的本次GC，耗时19ms |
| [Parallel Time: 9.6 ms, GC Workers: 4] | 1.Parallel Time：并行处理时间； 2.GC Workers：并行处理线程数； 3.意思是：4个线程并行处理，共耗时9.6ms |
| [GC Worker Start (ms): Min: 20548727124.8, Avg: 20548727125.0, Max: 20548727125.2, Diff: 0.4] | 1.回收线程的启动时间，该值 = JVM进程启动时间点 - 当前时间点； 2.Min：4个回收线程中启动最早线程的启动时间； Max：4个回收线程中启动最晚线程的启动时间； Avg：4个回收线程中平均启动时间； 3.Diff：Max -Min差值，越大，说明线程到达安全点晚（如：有可数循环等） 4.意思是：并行线程数（GC Workers）中启动最早、最晚时间，及差值 |
| [Ext Root Scanning (ms): Min: 4.9, Avg: 5.8, Max: 6.3, Diff: 1.4, Sum: 23.4] | Ext Root Scanning：外部根扫描（堆外扫描）耗时，外部根有：JVM系统目录、VM数据结构、JNI线程句柄、硬件寄存器、全局变量、线程堆栈根； |
| [Update RS (ms): Min: 0.9, Avg: 1.1, Max: 1.3, Diff: 0.4, Sum: 4.4] | 1.Update RS：更新记忆集耗时（RSet）； 2.每个Region都维护一个Rset，在有外部Region引用回收的Region内对象时，会记录外部Region的卡表索引，若有，则写入队列后，有单独线程异步处理（并发优化线程），最后原始快照STAB进行更新RSet，来完成最终标记阶段 |
| [Processed Buffers: Min: 1, Avg: 8.8, Max: 25, Diff: 24, Sum: 35] | 1.Processed Buffers：Rset的队列中处理的缓冲数量； 2.队列中那部分没被消费完的变更记录 |
| [Scan RS (ms): Min: 0.1, Avg: 0.2, Max: 0.4, Diff: 0.3, Sum: 1.0] | Scan RS扫描所有Regin的RSet，来确定自己内部的存活对象 |
| [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1] | 1.Code Root Scanning：代码根扫描耗时（JIT引起）； 2.被JIT即时编译器编译后的代码对堆的Region内部对象的引用情况 |
| [Object Copy (ms): Min: 1.6, Avg: 1.7, Max: 1.7, Diff: 0.2, Sum: 6.7] | 1. Object Copy：对象迁移耗时； 2.存活对象迁移到新的Region或晋升到S区或晋升到O区，并回收老的Region |
| [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] | Termination：终止GC工作线程耗时，使GC线程终止 |
| [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4] | Termination Attempts：尝试终止GC线程次数，可发生多次尝试终止 |
| [GC Worker Other (ms): Min: 0.0, Avg: 0.3, Max: 1.1, Diff: 1.0, Sum: 1.4] | 非GC活动的耗时，而是JVM的活动导致占用了GC暂停时间(例如JNI编译) |
| [GC Worker Total (ms): Min: 9.0, Avg: 9.2, Max: 9.4, Diff: 0.4, Sum: 36.9] | GC每个线程总耗时（并行线程数_GC Workers） |
| [GC Worker End (ms): Min: 20548727134.2, Avg: 20548727134.2, Max: 20548727134.2, Diff: 0.0] | 回收线程的结束时间，该值 = JVM进程启动时间点 - 当前时间点； |
| [Code Root Fixup: 0.0 ms] | 1.Code Root Fixup：代码根修正耗时（更新迁移对象的引用耗时）； 2.代码根所引用的存活对象，从一个Region迁移到了另外的Region，更新迁移对象的引用 |
| [Code Root Purge: 0.0 ms] | 代码根清理耗时（清理代码根中不再被使用的代码） |
| [Clear CT: 1.0 ms] | 清理卡表（Card Table），清理全局卡表中的已扫描标志 |
| [Other: 8.2 ms] | 其他操作耗时 |
| [Choose CSet: 0.0 ms] | 1.Choose CSet：选择要回收的集合（回收集 _ CSet）； 2.只有再(mixed)该参数才有意义，若是young gc，是指所有年轻代Region |
| [Ref Proc: 6.1 ms] | 1.Ref Proc：处理引用过程耗时； 2.引用是指：软引用（内存不足才回收）、弱引用（发生gc就可回收）、虚引用、final引用、JNI引用 |
| [Ref Enq: 0.0 ms] | 被回收的引用入队耗时 |
| [Redirty Cards: 0.4 ms] | Ref Enq时，会更新RSet，则需同步标记全局开标中对应的卡表为脏卡片 |
| [Humongous Register: 0.0 ms] | 1.Humongous Register：大对象注册耗时； 2.虽然大对象存储在H区，但是young gc时也会顺带回收一些H区。一旦young gc基于Region的RSet确定外部所对应是一个H区，则又通过逐层引用排查发现该H区已经不再被引用，则回收H区 |
| [Humongous Reclaim: 0.0 ms] | 回收H-Region的耗时 |
| [Free CSet: 1.0 ms] | 回收CSet中Region的空间并重新置为空闲耗时 |
| [Eden: 508.0M(508.0M)->0.0B(509.0M) Survivors: 4096.0K->3072.0K Heap: 596.7M(1024.0M)->87.4M(1024.0M)] | 1.Eden: 508.0M(508.0M)->0.0B(509.0M)： E区: 收回前使用(回收前总E区大小)->收回后使用(回收后总E区大小)； 2.Survivors: 4096.0K->3072.0K： S区: 收回前使用S大小->收回后使用S区大小； 3.Heap: 596.7M(1024.0M)->87.4M(1024.0M)： 整堆: 收回前整堆使用(整堆大小)->收回后整堆使用使用(整堆大小)； |
| [Times: user=0.04 sys=0.00, real=0.02 secs] | 1.Times：GC回收的总时间； 2.user：进程执行用户态(User Mode)所耗费的处理器时间（此进程实际CPU时间、其他进程和此进程阻塞时间不包括）； sys：进程执行核心态(Kernel Mode)所耗费的处理器时间（内核执行系统调用或等待系统事件所使用的CPU时间）； real（优化目标）：执行动作开始到结束耗费的时钟时间，包括其他进程使用的时间片和进程阻塞的时间 |
三、虚拟机性能监控和故障处理工具
1.命令工具
1)：基础工具
基本工具在${JAVA_HOME}/bin目录下的命令，基本是程序创建和运行工具。其主要命令：jar、java、javac、javap、jdeps，如下图所示。
2)：性能监控和故障处理
主要用来监控JVM运行信息、故障排查，其主要命令：jps、jstat、jstatd、jinfo、jmap、jstack。
2.可视化工具
下图是常用JVM监控的可视化工具。
下图是VisualVM的Visual GC插件的监控图。
四、JVM常出现问题
| 常出现问题 | 问题描述 | 优化 |
| 堆大小设置过大 | Full GC时，停顿时间过长； 生成过大堆转储快照无法分析 | 单个大堆调整多个JDK的逻辑集群； 理想：回收速率与对象分配速率相当 |
| 堆外内存溢出 | 堆外内存不能主动触发GC回收，而是Full GC时，顺便回收堆外内存 | 捕获异常，在catch块执行System.gc(); 堆外大小默认与-Xmx相同； 参数-XX:MaxDirectMemorySize调整大小 |
| 不当数据 导致内存过大 | 代码中大对象生成频繁（如：文档、动态JSP等）； 接收大量Mysql数据； HashMap的空间效率 | 直接进入老年代； 避免大量数据； 优化代码 |
| 安全点 导致长时间停顿 | 锁导致线程死锁； 无法达到安全点 | 检查死锁代码并优化； 可数循环设置安全点 (-XX:+UseCountedLoopSafepoints) |
五、参考资料
JVM Xlog 使用方法 - 知乎
JVM调优常用参数_printreferencegc_point-break的博客-CSDN博客
-XX:+PrintGCTimeStamps -XX:+PrintGCDetails 日志分析_lxlmycsdnfree的博客-CSDN博客
为对象分配内存——TLAB_usetlab_chengqiuming的博客-CSDN博客
jvm：jvm GC日志解析：G1日志解析_g1 gc日志_老艮头的博客-CSDN博客
