【Java】GC Logging – user, sys, real – which time to use

Source

GC Logging – user, sys, real – which time to use? & Gandhi

In the Garbage Collection log file, 3 types of time are reported for every single GC event:

在垃圾回收日志文件中，每个 GC 事件都会报告 3 种类型的时间：

• ‘user’
• ‘sys’
• ‘real’

Example: [Times: user=11.53 sys=1.38, real=1.03 secs].

For any engineer who is analyzing the GC logs will have following two questions:

任何工程师在分析 GC 日志时都会遇到以下两个问题：

1. What is the difference between ‘user’, ‘sys’, and ‘real’ times?
2. Which time should I use for measurement?
3. 用户"、"系统 "和 "实际 "时间有什么区别？
4. 我应该使用哪个时间进行测量？

When I started with Garbage Collection I had question #1. However, this knowledge, which I have shared below, was easy to gain.

刚开始学习垃圾回收时，我遇到了第 1 个问题。不过，我在下面分享的这些知识很容易获得。

However as the author of http://gceasy.io/ (a universal garbage collection log analysis tool), I was constantly asking myself question #2. Since http://gceasy.io reports several insightful metrics and graphs, on which time should I standardize? Now that http://gceasy.io is widely adopted, there is a great responsibility to represent the facts accurately.

But Mahatma Gandhi helped me to clarify question #2. Really he did help me. You might wonder what Mahatma Gandhi has to do with Garbage collection logging times. Am I making any sense here?

My wife keeps saying I talk non-sense most of the time (which is true as well). But in this case, I might be able to convenience you, my friend.

不过，作为 http://gceasy.io/（一款通用的垃圾收集日志分析工具）的作者，我一直在问自己第二个问题。既然 http://gceasy.io 报告了多个有洞察力的指标和图表，

我应该在哪个时间段进行标准化呢？现在，http://gceasy.io 已被广泛采用，我有责任准确地反映事实。但圣雄甘地（？）帮我澄清了第 2 个问题。实际上，他确实帮了我。你可能会问圣雄甘地和垃圾收集记录时间有什么关系？我说的有道理吗？

作者从吐槽：我妻子一直说我经常胡说八道（这也是事实）。但在这种情况下，我也许能为你提供方便，我的朋友。

History

Before even getting into GC Time, let’s just take couple minutes to learn about the Unix command “time.”

在了解 GC Time 之前，我们先花几分钟了解一下 Unix 命令 "time"。

When you issue the below UNIX command:

当您发出以下 UNIX 命令时：

time ls

You are going to see output like this:

您将看到这样的输出结果：

个人机器输出结果如下：

[alexxander@localhost ~]$ time ls
get-docker.sh  hello.lua

real    0m0.016s
user    0m0.001s
sys    0m0.005s

The ‘time ls’ command first displays the output of execution of the “ls” command, which lists all the directories/files in the current directory:

time ls "命令首先显示 "ls "命令的执行输出，该命令列出了当前目录下的所有目录/文件：

Next you see the amount of time it’s taken to execute “ls”, which is:

接下来你会看到执行 "ls "所花费的时间，即ls这个命令的总体执行时长：

Note here “real”, “user”, “sys” times are displayed. This is the same data that we see in GC logs.

注意这里显示的是 "real"、"user "和 "sys "时间。这与我们在 GC 日志中看到的数据相同。

Below is a great definition provided in StackOverflow for each of these times:

下面是 StackOverflow 提供的关于这些时间的定义：

Real is wall clock time – time from start to finish of the call. This is all elapsed time including time slices used by other processes and time the process spends blocked (for example if it is waiting for I/O to complete).

User is the amount of CPU time spent in user-mode code (outside the kernel) within the process. This is only actual CPU time used in executing the process. Other processes and time the process spends blocked do not count towards this figure.

Sys is the amount of CPU time spent in the kernel within the process. This means executing CPU time spent in system calls within the kernel, as opposed to library code, which is still running in user-space. Like ‘user’, this is only CPU time used by the process.

Real 是时钟时间：从调用开始到结束的时间。这是所有已耗费的时间，包括其他进程使用的时间片和进程被阻塞的时间（例如等待 I/O 完成的时间）。

User是进程内用户模式代码（内核外）所用的 CPU 时间。这只是执行进程时实际使用的 CPU 时间。其他进程和进程被阻塞的时间不计算在内。

Sys 是进程在内核中花费的 CPU 时间。这意味着在内核中执行系统调用所耗费的 CPU 时间，而不是仍在用户空间运行的库代码。与 "用户 "一样，这只是进程使用的 CPU 时间。

User+Sys will tell you how much actual CPU time your process used. Note that this is across all CPUs, so if the process has multiple threads it could potentially exceed the wall clock time reported by Real.

User+Sys 将告诉你，进程实际使用了多少 CPU 时间。请注意，这是在所有 CPU 上使用的时间，因此如果进程有多个线程，就有可能超过 Real 报告的挂钟时间。

Java GC Times

This is the same concept that is applied in GC logging as well. Let’s look at couple examples to understand this concept better.

这个概念同样适用于 GC 日志。让我们看几个例子来更好地理解这个概念。

Example 1:

[Times: user=11.53 sys=1.38, real=1.03 secs]

 In this example: ‘user’ + ‘sys’ is much greater than ‘real’ time. That’s because this log time is collected from the JVM, where multiple GC threads are configured on a multi-core/multi-processors server. As multiple threads execute GC in parallel, the workload is shared amongst these threads, thus actual clock time (‘real’) is much less than total CPU time (‘user’ + ‘sys’).

在本例中，"用户 "+"系统 "时间远远大于 "实际 "时间。这是因为日志时间是从 JVM 收集的，在多核/多处理器服务器上配置了多个 GC 线程。由于多个线程并行执行 GC，工作量由这些线程分担，因此实际时钟时间 (‘real’)）远少于 CPU 总时间 (‘user’ + ‘sys’).。

Example 2:

[Times: user=0.09 sys=0.00, real=0.09 secs]

 Above is an example of GC Times collected from a Serial Garbage Collector. As Serial Garbage collector always uses a single thread only, real time is equal to the sum of user and system times.

How Mahatma Gandhi Helped Me

I still haven’t answered the question how Mahatma Gandhi helped me. Following was one of his immortal quote on customers:

我还没有回答圣雄甘地是如何帮助我的这个问题。以下是他关于客户的不朽名言之一：

a customer is the most important visitor, on our premise, he is not dependent upon us we are dependant upon him he is not interruption on work he is the purpose of it he is not an outsider to our businesse he is part of it we are not doing him a favor by serving him... he is doing us a favor by swing us the opportunity to-do-it mahatma gandhi

顾客是我们最重要的访客，他不依赖于我们，我们依赖于他，他不是工作的干扰，他是工作的目的，他不是我们业务的局外人，他是我们业务的一部分，我们为他服务不是帮他的忙......他为我们提供机会，让我们去做，才是帮我们的忙。

According to Gandhi, the Customer is the primary focus. Similarly, when you are looking at performance optimization, you are primarily optimizing response time for your customer. The customer doesn’t care how many GC threads you use or how many processors you have. What matters is how many seconds he has to wait before he sees his screen painted with data. For that reason, I have used “real” time, which is basically the “clock time” for all the metrics and graphs in thehttp://gceasy.io/ (universal garbage collection log analysis tool).

甘地认为，客户是首要关注点。同样，当你考虑性能优化时，你主要是在为你的客户优化响应时间。客户并不关心你使用了多少个 GC 线程，也不关心你有多少个处理器。重要的是，他需要等待多少秒才能看到屏幕上的数据。因此，我使用了 "实时 "时间，它基本上是http://gceasy.io/（通用垃圾收集日志分析工具）中所有指标和图表的 "时钟时间"。

But it doesn’t mean ‘sys’ or ‘user’ times are not important. They are also important to see whether you want to increase your GC thread count or CPU processor count, to reduce your GC pause times.

但这并不意味着 "系统 "或 "用户 "时间不重要。它们对于确定是否要增加 GC 线程数或 CPU 处理器数以减少 GC 暂停时间也很重要。