JVM之GC日志解读

简介: JVM之GC日志解读

通过阅读Gc日志,我们可以了解Java虚拟机内存分配与回收策略。 内存分配与垃圾回收的参数列表

  • -XX:+PrintGC 输出GC日志。类似:-verbose:gc
  • -XX:+PrintGCDetails 输出GC的详细日志
  • -XX:+PrintGCTimestamps 输出GC的时间戳(以基准时间的形式)
  • -XX:+PrintGCDatestamps 输出GcC的时间戳(以日期的形式,如2013-05-04T21:53:59.234+0800)
  • -XX:+PrintHeapAtGC 在进行GC的前后打印出堆的信息
  • -Xloggc:../logs/gc.log 日志文件的输出路径

打开GC日志

-verbose:gc

这个只会显示总的GC堆的变化,如下:

[GC (Allocation Failure) 80832K->19298K(227840K),0.0084018 secs]
[GC (Metadata GC Threshold) 109499K->21465K(228352K),0.0184066 secs]
[Full GC (Metadata GC Threshold) 21465K->16716K(201728K),0.0619261 secs]

参数解析

GC、Full GC:GC的类型,GC只在新生代上进行,Full GC包括永生代,新生代,老年代。
Allocation Failure:GC发生的原因。
80832K->19298K:堆在GC前的大小和GC后的大小。
228840k:现在的堆大小。
0.0084018 secs:GC持续的时间。

打开GC日志

-verbose:gc -XX:+PrintGCDetails

[GC (Allocation Failure) [PSYoungGen:70640K->10116K(141312K)] 80541K->20017K(227328K),0.0172573 secs] [Times:user=0.03 sys=0.00,real=0.02 secs]

[GC (Metadata GC Threshold) [PSYoungGen:98859K->8154K(142336K)] 108760K->21261K(228352K),0.0151573 secs] [Times:user=0.00 sys=0.01,real=0.02 secs]

[Full GC (Metadata GC Threshold)[PSYoungGen:8154K->0K(142336K)]

[ParOldGen:13107K->16809K(62464K)] 21261K->16809K(204800K)]

[Metaspace:20599K->20599K(1067008K)],0.0639732 secs]
[Times:user=0.14 sys=0.00,real=0.06 secs]

参数解析

GC,Full FC:同样是GC的类型
Allocation Failure:GC原因
PSYoungGen:使用了Parallel Scavenge并行垃圾收集器的新生代GC前后大小的变化
ParOldGen:使用了Parallel Old并行垃圾收集器的老年代GC前后大小的变化
Metaspace: 元数据区GC前后大小的变化,JDK1.8中引入了元数据区以替代永久代
xxx secs:指GC花费的时间
Times:user:指的是垃圾收集器花费的所有CPU时间,sys:花费在等待系统调用或系统事件的时间,real:GC从开始到结束的时间,包括其他进程占用时间片的实际时间。

打开GC日志

-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimestamps -XX:+PrintGCDatestamps

2023-03-12T22:15:24.518+0800: 3.287: [GC (Allocation Failure) [PSYoungGen:136162K->5113K(136192K)] 141425K->17632K(222208K),0.0248249 secs] [Times:user=0.05 sys=0.00,real=0.03 secs]

2023-03-12T22:15:25.559+0800: 4.329: [GC (Metadata GC Threshold) [PSYoungGen:97578K->10068K(274944K)] 110096K->22658K(360960K),0.0094071 secs] [Times: user=0.00 sys=0.00,real=0.01 secs]

2023-03-12T22:15:25.569+0800: 4.338: [Full GC (Metadata GC Threshold) [PSYoungGen:10068K->0K(274944K)][ParoldGen:12590K->13564K(56320K)] 22658K->13564K(331264K),[Metaspace:20590K->20590K(1067008K)],0.0494875 secs] [Times: user=0.17 sys=0.02,real=0.05 secs]

说明:带上了日期和实践

如果想把GC日志存到文件的话,是下面的参数:

-Xloggc:/path/to/gc.log

日志补充说明

  • "[GC"和"[Full GC"说明了这次垃圾收集的停顿类型,如果有"Full"则说明GC发生了"Stop The World"
  • 使用Serial收集器在新生代的名字是Default New Generation,因此显示的是"[DefNew"
  • 使用ParNew收集器在新生代的名字会变成"[ParNew",意思是"Parallel New Generation"
  • 使用Parallel scavenge收集器在新生代的名字是”[PSYoungGen"
  • 老年代的收集和新生代道理一样,名字也是收集器决定的
  • 使用G1收集器的话,会显示为"garbage-first heap"
  • Allocation Failure
    表明本次引起GC的原因是因为在年轻代中没有足够的空间能够存储新的数据了。
  • [PSYoungGen:5986K->696K(8704K) ]  5986K->704K(9216K)
    中括号内:GC回收前年轻代大小,回收后大小,(年轻代总大小)
    括号外:GC回收前年轻代和老年代大小,回收后大小,(年轻代和老年代总大小)
  • user代表用户态回收耗时,sys内核态回收耗时,rea实际耗时。由于多核的原因,时间总和可能会超过real时间

Heap(堆)

PSYoungGen(Parallel Scavenge收集器新生代)total 9216K,used 6234K [0x00000000ff600000,0x0000000100000000,0x0000000100000000)

eden space(堆中的Eden区默认占比是8)8192K,768 used [0x00000000ff600000,0x00000000ffc16b08,0x00000000ffe00000)

from space(堆中的Survivor,这里是From Survivor区默认占比是1)1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)

to space(堆中的Survivor,这里是to Survivor区默认占比是1,需要先了解一下堆的分配策略)1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000)

                                                                       

ParOldGen(老年代总大小和使用大小)total 10240K, used 7001K [0x00000000fec00000,0x00000000ff600000,0x00000000ff600000)

object space(显示个使用百分比)10240K,688 used [0x00000000fec00000,0x00000000ff2d6630,0x00000000ff600000)

PSPermGen(永久代总大小和使用大小)total 21504K, used 4949K [0x00000000f9a00000,0x00000000faf00000,0x00000000fec00000)

object space(显示个使用百分比,自己能算出来)21504K, 238 used [0x00000000f9a00000,0x00000000f9ed55e0,0x00000000faf00000)


相关实践学习
【涂鸦即艺术】基于云应用开发平台CAP部署AI实时生图绘板
【涂鸦即艺术】基于云应用开发平台CAP部署AI实时生图绘板
相关文章
|
存储 监控 Java
G1原理—7.G1的GC日志分析解读
本文进行了TLAB的GC日志解读、YGC的GC日志解读、模拟YGC(单次GC及多次GC的不同场景)、打开实验选项查看YGC的详情日志信息、Mixed GC日志信息之初始标记过程、Mixed GC日志信息之混合回收过程。
|
算法 网络协议 Java
【JVM】——GC垃圾回收机制(图解通俗易懂)
GC垃圾回收,标识出垃圾(计数机制、可达性分析)内存释放机制(标记清除、复制算法、标记整理、分代回收)
|
存储 监控 Java
JVM进阶调优系列(8)如何手把手,逐行教她看懂GC日志?| IT男的专属浪漫
本文介绍了如何通过JVM参数打印GC日志,并通过示例代码展示了频繁YGC和FGC的场景。文章首先讲解了常见的GC日志参数,如`-XX:+PrintGCDetails`、`-XX:+PrintGCDateStamps`等,然后通过具体的JVM参数和代码示例,模拟了不同内存分配情况下的GC行为。最后,详细解析了GC日志的内容,帮助读者理解GC的执行过程和GC处理机制。
|
Arthas 监控 Java
JVM知识体系学习七:了解JVM常用命令行参数、GC日志详解、调优三大方面(JVM规划和预调优、优化JVM环境、JVM运行出现的各种问题)、Arthas
这篇文章全面介绍了JVM的命令行参数、GC日志分析以及性能调优的各个方面,包括监控工具使用和实际案例分析。
2042 3
|
XML 安全 Java
【日志框架整合】Slf4j、Log4j、Log4j2、Logback配置模板
本文介绍了Java日志框架的基本概念和使用方法,重点讨论了SLF4J、Log4j、Logback和Log4j2之间的关系及其性能对比。SLF4J作为一个日志抽象层,允许开发者使用统一的日志接口,而Log4j、Logback和Log4j2则是具体的日志实现框架。Log4j2在性能上优于Logback,推荐在新项目中使用。文章还详细说明了如何在Spring Boot项目中配置Log4j2和Logback,以及如何使用Lombok简化日志记录。最后,提供了一些日志配置的最佳实践,包括滚动日志、统一日志格式和提高日志性能的方法。
5373 32
【日志框架整合】Slf4j、Log4j、Log4j2、Logback配置模板
|
监控 安全 Apache
什么是Apache日志?为什么Apache日志分析很重要?
Apache是全球广泛使用的Web服务器软件,支持超过30%的活跃网站。它通过接收和处理HTTP请求,与后端服务器通信,返回响应并记录日志,确保网页请求的快速准确处理。Apache日志分为访问日志和错误日志,对提升用户体验、保障安全及优化性能至关重要。EventLog Analyzer等工具可有效管理和分析这些日志,增强Web服务的安全性和可靠性。
839 9
|
监控 容灾 算法
阿里云 SLS 多云日志接入最佳实践:链路、成本与高可用性优化
本文探讨了如何高效、经济且可靠地将海外应用与基础设施日志统一采集至阿里云日志服务(SLS),解决全球化业务扩展中的关键挑战。重点介绍了高性能日志采集Agent(iLogtail/LoongCollector)在海外场景的应用,推荐使用LoongCollector以获得更优的稳定性和网络容错能力。同时分析了多种网络接入方案,包括公网直连、全球加速优化、阿里云内网及专线/CEN/VPN接入等,并提供了成本优化策略和多目标发送配置指导,帮助企业构建稳定、低成本、高可用的全球日志系统。
1685 55
|
存储 缓存 关系型数据库
图解MySQL【日志】——Redo Log
Redo Log(重做日志)是数据库中用于记录数据页修改的物理日志,确保事务的持久性和一致性。其主要作用包括崩溃恢复、提高性能和保证事务一致性。Redo Log 通过先写日志的方式,在内存中缓存修改操作,并在适当时候刷入磁盘,减少随机写入带来的性能损耗。WAL(Write-Ahead Logging)技术的核心思想是先将修改操作记录到日志文件中,再择机写入磁盘,从而实现高效且安全的数据持久化。Redo Log 的持久化过程涉及 Redo Log Buffer 和不同刷盘时机的控制参数(如 `innodb_flush_log_at_trx_commit`),以平衡性能与数据安全性。
1211 5
图解MySQL【日志】——Redo Log