通常，我们在了解应用服务的性能时，都会去在所定义的垃圾收集日志文件中去分析GC活动轨迹，在gc.log文件中，我们经常会看到每个GC事件所打印的三种时间类型：
“ User ”、“ Sys ”及“ Real ”，它们分别表示什么呢？具有哪些象征性意义呢？本文将结合作者的相关实际经验进行简要解析，希望阅读完本篇文章后对大家在GC Log这块的问题定位与分析有所帮助。
以下为基于G 1垃圾回收策略的GC Log内容，因篇幅有限，仅显示局部内容：
代码语言：javascript复制[administrator@JavaLangOutOfMemory luga %]less echo-admin-gc.log
... ...
2015-09-14T12:32:24.398-0700: 0.356: [GC pause (G1 Evacuation Pause) (young), 0.0215287 secs]
[Parallel Time: 20.0 ms, GC Workers: 8]
[GC Worker Start (ms): Min: 355.9, Avg: 356.3, Max: 358.4, Diff: 2.4]
[Ext Root Scanning (ms): Min: 0.0, Avg: 6.4, Max: 16.7, Diff: 16.7, Sum: 51.4]
[Update RS (ms): Min: 0.0, Avg: 1.0, Max: 2.5, Diff: 2.5, Sum: 8.2]
[Processed Buffers: Min: 0, Avg: 1.1, Max: 5, Diff: 5, Sum: 9]
[Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1]
[Object Copy (ms): Min: 2.9, Avg: 11.9, Max: 17.5, Diff: 14.6, Sum: 95.3]
[Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.9]
[Termination Attempts: Min: 1, Avg: 2.5, Max: 5, Diff: 4, Sum: 20]
[GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.5]
[GC Worker Total (ms): Min: 17.5, Avg: 19.6, Max: 19.9, Diff: 2.4, Sum: 156.5]
[GC Worker End (ms): Min: 375.8, Avg: 375.9, Max: 375.9, Diff: 0.1]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.5 ms]
[Other: 1.0 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.4 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.4 ms]
[Humongous Register: 0.0 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.0 ms]
[Eden: 12.0M(12.0M)->0.0B(14.0M) Survivors: 0.0B->2048.0K Heap: 12.6M(252.0M)->7848.3K(252.0M)]
[Times: user=0.08 sys=0.00, real=0.02 secs]
2015-09-14T12:32:24.932-0700: 0.889: [GC pause (G1 Evacuation Pause) (young), 0.0469650 secs]从上述的输出文件中，我们可以看到在年轻代GC 事件后面有3种不同时间的详细打印：
[Times: user=0.08 sys=0.00, real=0.02 secs] 。如何在应用程序运行过程中输出GC Log？可参考之前的文章：Java虚拟机三件套解析。
当拿到这份GC 日志文件，我们会遇到很多很多问题：每个单个GC事件花费的时间都会在GC日志中报告。在每个GC事件中，都有“用户”，“ 系统”和“实时”。这些时间是代表什么意思？它们之间究竟有什么本质区别？我们如何去打印，什么时间去监控？
在我们了解GC Time之前，我们花几分钟时间来了解Linux / Unix命令的“时间”。具体如下操作：
代码语言：javascript复制[administrator@JavaLangOutOfMemory ~ %] time ls
Desktop Movies activemq gateway luga
Documents Music cpu go monitoring-micrometer
Downloads Pictures curl-format.txt goPro nacos-docker
IdeaProjects Public deploy-demo.yaml java openshift
Library SpringCloud2.x docker k8s
real 0m0.003s
user 0m0.000s
sys 0m0.001s通过time ls命令，我们看到这样的输出：
“ time ls” 命令首先显示“ ls”命令的执行输出，其中列出了当前目录中的所有目录/文件：
接下来，我们看到执行“ ls”所花费的时间，即：“真实”，“用户”，“ 系统” 时间。这是我们在GC日志中看到的相同数据。
下面是在每种情况下StackOverflow中提供的一个很好的定义：
Real（实际时间）是挂钟时间-从事件开始到结束的时间。这是所有经过的时间，包括其他进程使用的时间片以及该进程花费的时间被阻塞（例如，如果它正在等待I / O完成）。
User（用户时间）是进程中用户模式代码（内核外部）所花费的CPU时间片。这只是执行过程中使用的实际CPU时间。该进程花费的其他进程和时间不计入该数字。
Sys（系统时间）是进程中在内核中花费的CPU时间量。这意味着在内核内部执行系统调用所花费的CPU时间，而不是库代码仍在用户空间中运行。就像“用户”一样，这只是进程使用的CPU时间。
User Sys将告诉我们：我们的进程使用了多少实际CPU时间。请注意，这涉及所有CPU，因此，如果该进程具有多个线程，则有可能超过Real Times的挂钟时间。
刚才我们讲到了Linux/Unix时间概念，现在我们着重看下Java GC Times。这与GC日志记录中应用的概念相同。
在Java GC Times概念中，每个单个GC事件花费的时间都会在GC日志中报告。在每个GC事件中，都有“user”，“ sys”和“real”。这些时间是什么意思？它们之间有什么区别？
Real（实际时间）指GC事件的总经过时间。这基本上是您在时钟中看到的时间。
User（用户时间）指用户模式代码（内核外部）所花费的CPU时间。
Sys（系统时间）指内核中花费的CPU时间。这意味着在内核内部执行系统调用所花费的CPU时间，而不是库代码仍在用户空间中运行。
让我们看几个简单示例，以便更好地理解这个概念。
示例1:
代码语言：javascript复制[Times: user=12.93 sys=2.01, real=1.03 secs]在此示例中：“user” “sys”远大于“real”。这是因为此日志时间是从JVM收集的，在JVM中，多核/多处理器服务器上配置了多个GC线程。当多个线程并行执行GC时，工作负载将在这些线程之间共享。因此，实际时钟时间（“real”）比CPU总时间（“user” “ sys”）少得多。
示例2：
代码语言：javascript复制[Times: user=0.12 sys=0.00, real=0.12 secs]上面是从串行垃圾收集器收集的GC时间的示例。由于串行垃圾收集器始终仅使用单个线程，因此实时等于用户和系统时间的总和。
在实际的业务场景中，考虑性能优化时，我们主要偏向在为客户优化响应时间。客户不在乎我们使用多少GC线程或拥有多少处理器。因此，我们需要重点关注“real”时间，但这并不意味着“ sys”或“ user”时间并不重要。它们对于查看是否要增加GC线程数或CPU处理器数以减少GC暂停时间也很重要。
在正常的（所有）GC事件中，Real Time将小于（User Sys）Time。这是因为多个GC线程同时工作以分担工作量，因此实时时间将少于用户 系统时间。假设（User Sys）Time为2秒。如果5个GC线程同时工作，则实时应该在400毫秒左右（2秒/ 5个GC线程）附近。但是在某些情况下，我们可能会看到Real Time >（User Sys）Time。
我们看一下示例：
代码语言：javascript复制[Times: user=0.80 sys=0.05, real=20.37 secs]如果我们在GC日志中发现多次出现此情况（Real Time明显大于User Time与Sys Time之和），则可能表明存在以下问题之一：
1、I / O繁忙
2、CPU不足
下面我们针对出现的性能问题进行分析：
I / O繁忙
当服务器上发生大量I / O活动（即网络/磁盘访问/用户交互）时，实时性往往会在很大程度上飙升。作为GC日志记录的一部分，我们的应用程序进行磁盘访问。如果服务器上的I / O活动繁重，则GC事件可能会搁浅，从而导致实时峰值。
注意：即使我们的应用程序没有引起繁重的I / O活动，服务器上的其他进程也可能导致繁重的I / O活动，从而导致较高的实时性。
我们可以在Linux/Unix中使用sar（系统活动报告）监视服务器上的I / O活动。具体为：
代码语言：javascript复制[administrator@JavaLangOutOfMemory ~ %]sar -d -p 1上面的命令每1秒报告一次对设备的读取/秒和写入/秒。有关“ sar”命令的更多详细信息，请参官网教程。
如果我们发现服务器上的I / O活动很高，则可以执行以下任一操作来解决此问题：
1、如果我们的应用程序引起了较高的I / O活动，请优化应用程序的I / O活动。
2、消除导致服务器上大量I / O活动的进程
3、将我们的应用程序移到I / O活动较少的其他服务器上
CPU不足
如果我们的服务器上正在运行多个进程，并且我们的应用程序没有足够的CPU周期来运行，它将开始等待。当应用程序开始等待时，实时将大大高于用户 系统时间。
我们可以使用“ top”之类的命令或监视工具（nagios，newRelic，AppDynamics…）来观察服务器上的CPU利用率。如果我们发现CPU使用率很高，并且进程没有足够的周期来运行，则可以执行以下一项操作来解决此问题：
1、减少服务器上正在运行的进程数，以便我们的应用程序有运行的资源空间。
2、增加CPU容量，将应用服务移至具有更多CPU核心的更大实例类型。
3、将我们的应用程序移到具有足够CPU容量的新服务器上。
基于以上的解析过程，希望本文对大家有所帮助，使得我们能够熟悉GC Log里面的奥秘，以便我们的应用程序在运行过程中以获得最佳性能表现。
