详尽的Java垃圾回收

最新推荐文章于 2024-08-27 16:02:42 发布

viagra2009100129

最新推荐文章于 2024-08-27 16:02:42 发布

阅读量175

点赞数

分类专栏： JVM垃圾回收文章标签： jvm 垃圾回收

原文链接：https://www.baeldung.com/java-verbose-gc

版权

JVM垃圾回收专栏收录该内容

6 篇文章 0 订阅

订阅专栏

1.总览

这个教程我们将看看详尽的Java垃圾回收。接下来，我们将介绍几个不同的实例，我们将了解可用的不同配置选项。此外，我们还将重点介绍如何解释详细日志的输出。

要了解有关垃圾回收（GC）和可用不同实现的更多信息，请查看我们有关 Java 垃圾回收器的文章。

2.Verbose GC 简介

在调试和分析许多问题（尤其是内存问题时），通常需要打开详细的垃圾回收日志记录。事实上，有些人会认为，为了严格监视我们的应用程序运行状况，我们应该始终监视 JVM 的垃圾回收性能。

正如我们将看到的，GC 日志是一个非常重要的工具，用于揭示对应用程序的堆和 GC 配置的潜在改进。对于发生的每个 GC，GC 日志都提供有关其结果和时间的精确数据。

随着时间的推移，分析这些信息可以帮助我们更好地了解行为或应用程序，并帮助我们调整应用程序的性能。此外，它还可以通过指定最佳堆大小、其他 JVM 选项和备用 GC 算法来帮助优化 GC 频率和收集时间。

2.1 例子

public class Application {
 
    private static Map<String, String> stringContainer = new HashMap<>();
 
    public static void main(String[] args) {
        System.out.println("Start of program!");
        String stringWithPrefix = "stringWithPrefix";
 
        // Load Java Heap with 3 M java.lang.String instances
        for (int i = 0; i < 3000000; i++) {
            String newString = stringWithPrefix + i;
            stringContainer.put(newString, newString);
        }
        System.out.println("MAP size: " + stringContainer.size());
 
        // Explicit GC!
        System.gc();
 
        // Remove 2 M out of 3 M
        for (int i = 0; i < 2000000; i++) {
            String newString = stringWithPrefix + i;
            stringContainer.remove(newString);
        }
 
        System.out.println("MAP size: " + stringContainer.size());
        System.out.println("End of program!");
    }
}

如上例所示，此简单程序将 300 万个 String 实例加载到 Map 对象中。然后，我们使用 System.gc() 对垃圾回收器进行显式调用。

最后，我们从地图中删除 200 万个字符串实例。我们还显式使用 System.out.println() 使解释输出更加容易。

在下一节中，我们将了解如何激活 GC 日志记录。

2.激活GC日志

让我们首先运行我们的程序，并通过我们的 JVM 启动参数启用verbose GC：

-XX:+UseSerialGC -Xms1024m -Xmx1024m -verbose:gc

这里的重要参数是 -verbose：gc，它以最简单的形式激活垃圾回收信息的日志记录。默认情况下，GC 日志写入粗壮，应为每个年轻代 GC 和每个完整 GC 输出一行。

为了我们的示例，我们通过参数-XX：_UseSerialGC 指定了串行垃圾回收器，即最简单的 GC 实现。

我们还设置了最小和最大的堆大小 1024mb，但当然，我们可以调整更多的 JVM 参数。

3.1Verbose GC的输出

Start of program!
[GC (Allocation Failure)  279616K->146232K(1013632K), 0.3318607 secs]
[GC (Allocation Failure)  425848K->295442K(1013632K), 0.4266943 secs]
MAP size: 3000000
[Full GC (System.gc())  434341K->368279K(1013632K), 0.5420611 secs]
[GC (Allocation Failure)  647895K->368280K(1013632K), 0.0075449 secs]
MAP size: 1000000
End of program!

在上面的输出中，我们已经看到了许多有关JVM内部情况的有用信息。

起初，这个输出看起来相当令人害怕的，但现在让我们一步一步地分析它。

首先，我们可以看到，四个集合发生， one Full GC and three cleaning Young generation 。

3.2 verbose GC更详尽的输出

让我们更详细地分解输出行，以准确了解发生了什么：

GC or Full GC - 垃圾回收的类型，用于区分次要或完全垃圾回收的 GC 或完整 GC
(Allocation Failure) or (System.gc()) - 集合的原因 - 分配失败表示Egen去中没有剩余空间来分配我们的对象
279616K->146232K - GC 运行前后占用的堆内存（用箭头分隔）
（1013632K） - 堆的当前容量
0.3318607 秒 - GC 事件的运行时间（以秒为单位）

我们看输出的第一行， 279616K->146232K(1013632K) 表明 GC 把占用的堆内存从 279616K 减少到 146232K，释放了1013632k的空间。GC的时候，堆空间是1013632K，GC耗费了 0.3318607 s。

尽管简单的 GC 日志记录格式可能很有用，它提供了有限的详细信息。但是，我们无法判断 GC 是否将任何对象从新生代移动到老年代，或者每个回收前后新生代的容量是多少。

因此，详细的 GC 日志记录比简单的日志记录更有用。

4.详细的GC日志

-XX:+PrintGCDetails，这个给我们更详细的GC信息，比如：

每次GC前后，新生代和老年代的大小
在新生代和老年代，每次GC消耗的时间
每次GC，提升的对象大小
整个堆内存的大小

5.分析更详尽的GC日志

配置参数：

-XX:+UseSerialGC -Xms1024m -Xmx1024m -verbose:gc -XX:+PrintGCDetails

输出如下：

Start of program!
[GC (Allocation Failure) [DefNew: 279616K->34944K(314560K), 0.3626923 secs] 279616K->146232K(1013632K), 0.3627492 secs] [Times: user=0.33 sys=0.03, real=0.36 secs] 
[GC (Allocation Failure) [DefNew: 314560K->34943K(314560K), 0.4589079 secs] 425848K->295442K(1013632K), 0.4589526 secs] [Times: user=0.41 sys=0.05, real=0.46 secs] 
MAP size: 3000000
[Full GC (System.gc()) [Tenured: 260498K->368281K(699072K), 0.5580183 secs] 434341K->368281K(1013632K), [Metaspace: 2624K->2624K(1056768K)], 0.5580738 secs] [Times: user=0.50 sys=0.06, real=0.56 secs] 
[GC (Allocation Failure) [DefNew: 279616K->0K(314560K), 0.0076722 secs] 647897K->368281K(1013632K), 0.0077169 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 
MAP size: 1000000
End of program!
Heap
 def new generation   total 314560K, used 100261K [0x00000000c0000000, 0x00000000d5550000, 0x00000000d5550000)
  eden space 279616K,  35% used [0x00000000c0000000, 0x00000000c61e9370, 0x00000000d1110000)
  from space 34944K,   0% used [0x00000000d3330000, 0x00000000d3330188, 0x00000000d5550000)
  to   space 34944K,   0% used [0x00000000d1110000, 0x00000000d1110000, 0x00000000d3330000)
 tenured generation   total 699072K, used 368281K [0x00000000d5550000, 0x0000000100000000, 0x0000000100000000)
   the space 699072K,  52% used [0x00000000d5550000, 0x00000000ebcf65e0, 0x00000000ebcf6600, 0x0000000100000000)
 Metaspace       used 2637K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 283K, capacity 386K, committed 512K, reserved 1048576K

我们应该能够识别简单 GC 日志中的所有元素。但有几个新的点。

现在，让我们考虑输出中以蓝色突出显示的新项：

5.1 分析年轻代里的Minor GC

[GC (Allocation Failure) [DefNew: 279616K->34944K(314560K), 0.3626923 secs] 279616K->146232K(1013632K), 0.3627492 secs] [Times: user=0.33 sys=0.03, real=0.36 secs]

我们拆分一下：

GC日志开头的“［GC”和“［Full GC”说明了这次垃圾收集的停顿类型，而不是用来区分新生代GC还是老年代GC的。如果有“Full”，说明这次GC是发生了Stop-The-World的。
DefNew - 垃圾回收使用的名字，这是一个单线程的收集器，发生了 mark-copy stop-the-world ,清理新生代使用的空间。
279616K->34944K – GC前该内存区域已使用容量-> GC后该内存区域已使用容量 (该内存区域总容量)
0.3626923 secs – 表示该内存区域GC所占用的时间，单位是秒
[Times: user=0.33 sys=0.03, real=0.36 secs] – GC 持续的时间，从不同维度统计的。

介绍一下：

user – 进程执行用户态代码（核心之外）所使用的时间。这是执行此进程所使用的实际 CPU 时间，其他进程和此进程阻塞的时间并不包括在内。在垃圾收集的情况下，表示 GC 线程执行所使用的 CPU 总时间。
sys – 进程在内核态消耗的 CPU 时间，即在内核执行系统调用或等待系统事件所使用的 CPU 时间。
real – 程序从开始到结束所用的时钟时间。这个时间包括其他进程使用的时间片和进程阻塞的时间（比如等待 I/O 完成）。

5.2 分析 Full GC

在这个倒数第二个示例中，我们看到，对于由系统调用触发的Full GC，使用的收集器是 Tenured。

我们看到的最后一条信息是元空间的相同模式的细分：

[Metaspace: 2624K->2624K(1056768K)], 0.5580738 secs]

Metaspace - JDK 8.HotSpot JVM开始使用本地化的内存存放类的元数据，这个空间叫做元空间

输出的最后一部分包括堆的细目，包括内存每个部分的内存占用量摘要。

Eden去占用了 35%，Tenured占用了52%. 元数据空间和类空间也被包括了。

从上面的输出，我们能清楚的知道，在JVM内部，GC事件消耗了多少内存。

6.增加日期和时间

没有日期和时间信息，任何好的日志都是不完整的。

当我们需要将 GC 日志数据与其他源的数据关联时，这些额外信息非常有用，或者它只能帮助促进搜索。

当我们运行应用程序以获取显示日志的日期和时间信息时，我们可以添加以下两个参数：

-XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps

现在，每行都以绝对日期和时间开始，写入时跟一个时间戳，反映自 JVM 启动以来以秒为单位的实时传递时间：

2018-12-11T02:55:23.518+0100: 2.601: [GC (Allocation ...

7.存入文件

默认的日志输出是控制台，我们可以存入文件：

我们可以添加参数-Xloggc:<file>

-Xloggc:/path/to/file/gc.log

8.Java 9以上新增的功能

在GC日志过程中，会遇到这么个配置：-XX:+PrintGC。在Java8里面，-verbose:gc和XX:+PrintGC是一样的。

-XX:+PrintGC在Java9被弃用了。-Xlog:gc在JDK9和10中仍然可以使用。

9.分析GC的工具

使用文本编辑器分析 GC 日志可能非常耗时且非常繁琐。根据使用的 JVM 版本和 GC 算法，GC 日志格式可能会有所不同。

有一个非常好的免费图形分析工具，用于分析垃圾回收日志，提供有关潜在垃圾回收问题的许多指标，甚至为这些问题提供潜在的解决方案。

请下载 Universal GC Log Analyzer 。

参考代码

viagra2009100129

关注

0
点赞
踩
0

收藏

觉得还不错? 一键收藏
0
评论
详尽的Java垃圾回收

1.总览这个教程我们将看看详尽的Java垃圾回收。接下来，我们将介绍几个不同的实例，我们将了解可用的不同配置选项。此外，我们还将重点介绍如何解释详细日志的输出。要了解有关垃圾回收（GC）和可用不同实现的更多信息，请查看我们有关 Java 垃圾回收器的文章。2.Verbose GC 简介在调试和分析许多问题（尤其是内存问题时），通常需要打开详细的垃圾回收日志记录。事实上，有些人会认为，为...
复制链接

扫一扫

专栏目录