GC问题
线上常出现的GC问题一般分为以下三种：
- GC 时间过长。这种会影响用户的体验，这个时候就需要观察日志，调整某些 JVM 参数。
- 发生了OOM。这种情况就比较严重了，服务阻塞，我们要寻找背后的原因。
- 占用大量系统资源（主要探讨堆外内存溢出），服务进程被killer。这种情况就更严重了，服务直接被动停机，连异常日志都不留下。
下手解决思路
想要下手解决 GC 问题，我们以三个篇章来逐步讨论。
- 压测观察并调试GC-JVisualVM
- 线上OOM异常处理-dump堆信息+MAT
- 程序被动停机（堆外内存排查）
上线前压测并观察调试GC情况
我们可以想到的优化手段，包括代码优化、扩容、参数优化，甚至我们的估算，都需要一些支撑信息加以判断。这时候就需要一些信息收集手段。
JVisualVM 工具使用
JDK自带JVM监控工具，可以实时观察JVM进程相关情况。但因为远程连接JVM进程的话，需要远程进程启动JMX服务，故不适合线上环境JVM观察，比较适合测试环境搭配压测调试使用。
JDK6之后就在JDK中自带了，工具启动路径 jdk*/bin/jvisualvm.exe
一般还需安装一个插件Visual GC（官网下载 http://visualvm.github.io/ ---> Plugins）
visual gc 指数图示
命令行指令
当然直接使用JDK命令行指令也可做到JVM实时观察。
- jps：查看正在运行JVM相关进程信息
- jstat：查看指定JVM的运行状态信息（类加载，内存，垃圾回收，即时编译）
- jinfo：查看/调整指定JVM的各项参数
- jmap：生成指定JVM堆转储快照（dump），及查询堆与方法区的信息
- jstack：生成指定JVM栈（线程）快照
// TODO 后续补充
GC 日志输出
你可能感受到，最近几年 Java 的版本更新速度是很快的，JVM 的参数配置其实变化也很大。就拿 GC 日志这一块来说，Java 9 几乎是推翻重来。网络上的一些文章，把这些参数写的乱七八糟，根本不能投入生产。如果你碰到不能被识别的参数，先确认一下自己的 Java 版本。
在事故出现的时候，通常并不是那么温柔。你可能在半夜里就能接到报警电话，这是因为很多定时任务都设定在夜深人静的时候执行。
这个时候，再去看 jstat 已经来不及了，我们需要保留现场。这个便是看门狗的工作，看门狗可以通过设置一些 JVM 参数进行配置。
那在实践中，要怎么用呢？请看下面命令行。
Java 8
我们先看一下 JDK8 中的使用。
#!/bin/sh
LOG_DIR="/tmp/logs"
JAVA_OPT_LOG=" -verbose:gc"
JAVA_OPT_LOG="${JAVA_OPT_LOG} -XX:+PrintGCDetails"
JAVA_OPT_LOG="${JAVA_OPT_LOG} -XX:+PrintGCDateStamps"
JAVA_OPT_LOG="${JAVA_OPT_LOG} -XX:+PrintGCApplicationStoppedTime"
JAVA_OPT_LOG="${JAVA_OPT_LOG} -XX:+PrintTenuringDistribution"
JAVA_OPT_LOG="${JAVA_OPT_LOG} -Xloggc:${LOG_DIR}/gc_%p.log"
JAVA_OPT_OOM=" -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=${LOG_DIR} -XX:ErrorFile=${LOG_DIR}/hs_error_pid%p.log "
JAVA_OPT="${JAVA_OPT_LOG} ${JAVA_OPT_OOM}"
JAVA_OPT="${JAVA_OPT} -XX:-OmitStackTraceInFastThrow"
合成一行。
-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps
-XX:+PrintGCApplicationStoppedTime -XX:+PrintTenuringDistribution
-Xloggc:/tmp/logs/gc_%p.log -XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/tmp/logs -XX:ErrorFile=/tmp/logs/hs_error_pid%p.log
-XX:-OmitStackTraceInFastThrow
然后我们来解释一下这些参数：
| 参数 | 意义 |
|---|---|
| -verbose:gc | 打印 GC 日志 |
| PrintGCDetails | 打印详细 GC 日志 |
| PrintGCDateStamps | 系统时间，更加可读，PrintGCTimeStamps 是 JVM 启动时间 |
| PrintGCApplicationStoppedTime | 打印 STW 时间 |
| PrintTenuringDistribution | 打印对象年龄分布，对调优 MaxTenuringThreshold 参数帮助很大 |
| loggc | 将以上 GC 内容输出到文件中 |
OOM相关参数：
| 参数 | 意义 |
|---|---|
| HeapDumpOnOutOfMemoryError | OOM 时 Dump 信息，非常有用 |
| HeapDumpPath | Dump 文件保存路径 |
| ErrorFile | 错误日志存放路径 |
注意到我们还设置了一个参数 OmitStackTraceInFastThrow，这是 JVM 用来缩简日志输出的。
开启这个参数之后，如果你多次发生了空指针异常，将会打印以下信息。
java.lang.NullPointerException
java.lang.NullPointerException
java.lang.NullPointerException
java.lang.NullPointerException
在实际生产中，这个参数是默认开启的，这样就导致有时候排查问题非常不方便（很多研发对此无能为力），我们这里把它关闭，但这样它会输出所有的异常堆栈，日志会多很多。
Java 13
再看下 JDK 13 中的使用。
从 Java 9 开始，移除了 40 多个 GC 日志相关的参数。具体参见 JEP 158。所以这部分的日志配置有很大的变化。
我们同样看一下它的生成脚本。
#!/bin/sh
LOG_DIR="/tmp/logs"
JAVA_OPT_LOG=" -verbose:gc"
JAVA_OPT_LOG="${JAVA_OPT_LOG} -Xlog:gc,gc+ref=debug,gc+heap=debug,gc+age=trace:file=${LOG_DIR}/gc_%p.log:tags,uptime,time,level"
JAVA_OPT_LOG="${JAVA_OPT_LOG} -Xlog:safepoint:file=${LOG_DIR}/safepoint_%p.log:tags,uptime,time,level"
JAVA_OPT_OOM=" -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=${LOG_DIR} -XX:ErrorFile=${LOG_DIR}/hs_error_pid%p.log "
JAVA_OPT="${JAVA_OPT_LOG} ${JAVA_OPT_OOM}"
JAVA_OPT="${JAVA_OPT} -XX:-OmitStackTraceInFastThrow"
echo $JAVA_OPT
合成一行展示。
-verbose:gc -Xlog:gc,gc+ref=debug,gc+heap=debug,gc+age=trace:file
=/tmp/logs/gc_%p.log:tags,uptime,time,level -Xlog:safepoint:file=/tmp
/logs/safepoint_%p.log:tags,uptime,time,level -XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/tmp/logs -XX:ErrorFile=/tmp/logs/hs_error_pid%p.log
-XX:-OmitStackTraceInFastThrow
可以看到 GC 日志的打印方式，已经完全不一样，但是比以前的日志参数规整了许多。
我们除了输出 GC 日志，还输出了 safepoint 的日志。这个日志对我们分析问题也很重要，那什么叫 safepoint 呢？
safepoint 是 JVM 中非常重要的一个概念，指的是可以安全地暂停线程的点。
当发生 GC 时，用户线程必须全部停下来，才可以进行垃圾回收，这个状态我们可以认为 JVM 是安全的（safe），整个堆的状态是稳定的。
如果在 GC 前，有线程迟迟进入不了 safepoint，那么整个 JVM 都在等待这个阻塞的线程，会造成了整体 GC 的时间变长。
所以呢，并不是只有 GC 会挂起 JVM，进入 safepoint 的过程也会。这个概念，如果你有兴趣可以自行深挖一下，一般是不会出问题的。
如果有人问起你在项目中都使用了哪些打印 GC 日志的参数，上面这些信息肯定是不很好记忆。你需要进行以下总结。比如：
“我一般在项目中输出详细的 GC 日志，并加上可读性强的 GC 日志的时间戳。特别情况下我还会追加一些反映对象晋升情况和堆详细信息的日志，用来排查问题。另外，OOM 时自动 Dump 堆栈，我一般也会进行配置。”
GC 日志的意义
我们首先看一段日志，然后简要看一下各个阶段的意义。
- 表示 GC 发生的时间，一般使用可读的方式打印；
- 表示日志表明是 G1 的“转移暂停: 混合模式”，停顿了约 223ms；
- 表明由 8 个 Worker 线程并行执行，消耗了 214ms；
- 表示 Diff 越小越好，说明每个工作线程的速度都很均匀；
- 表示外部根区扫描，外部根是堆外区。JNI 引用，JVM 系统目录，Classloaders 等；
- 表示更新 RSet 的时间信息；
- 表示该任务主要是对 CSet 中存活对象进行转移（复制）；
- 表示花在 GC 之外的工作线程的时间；
- 表示并行阶段的 GC 总时间；
- 表示其他清理活动；
- 表示收集结果统计；
- 表示时间花费统计。
