JVM GC日志分析

最新推荐文章于 2024-04-13 13:47:55 发布
最新推荐文章于 2024-04-13 13:47:55 发布
阅读量191 收藏
点赞数
分类专栏： JVM 文章标签： jvm jvm.gc
版权声明：本文为博主原创文章，遵循 CC 4.0 BY-SA 版权协议，转载请附上原文出处链接和本声明。
本文链接：https://blog.csdn.net/foolishboy_w/article/details/116179399
版权

JVM GC日志分析

文章目录


GC日志是处理JVM相关问题的重要根据，所以看懂并分析GC日志是一项必须可少的技能。

GC相关的JVM参数设置

-XX:PrintGC				输出GC日志
-XX:PrintGCDetails		输出GC的详细日志
-XX:PrintGCTimeStamps	输出GC的时间戳
-XX:PrintGCDateStamps	输出GC的详细时间信息(格式为2021-04-26T23:00:18.288+0800)
-XX:PrintHeapAtGC		在GC发生的前后打印出堆的信息
-Xloggc:../logs/gc.log	生成GC日志文件的路径

GC日志的含义

  • 使用的命令行参数如下

    -XX:+UseParallelGC 
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-XX:+PrintHeapAtGC
-Xloggc:gc.log

  • GC日志样例

    Java HotSpot(TM) 64-Bit Server VM (25.151-b12) for windows-amd64 JRE (1.8.0_151-b12), built on Sep  5 2017 19:33:46 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 16711680k(10587452k free), swap 17760256k(9790820k free)
CommandLine flags: -XX:InitialHeapSize=267386880 -XX:MaxHeapSize=4278190080 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 
{Heap before GC invocations=1 (full 0):
 PSYoungGen      total 76288K, used 3932K [0x000000076b000000, 0x0000000770500000, 0x00000007c0000000)
  eden space 65536K, 6% used [0x000000076b000000,0x000000076b3d70e0,0x000000076f000000)
  from space 10752K, 0% used [0x000000076fa80000,0x000000076fa80000,0x0000000770500000)
  to   space 10752K, 0% used [0x000000076f000000,0x000000076f000000,0x000000076fa80000)
 ParOldGen       total 2785280K, used 2097152K [0x00000006c1000000, 0x000000076b000000, 0x000000076b000000)
  object space 2785280K, 75% used [0x00000006c1000000,0x0000000741000020,0x000000076b000000)
 Metaspace       used 2760K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 302K, capacity 386K, committed 512K, reserved 1048576K
2021-04-27T00:29:10.817+0800: 1.389: [GC (Allocation Failure) [PSYoungGen: 3932K->752K(76288K)] 2101084K->2097912K(2861568K), 0.0261894 secs] [Times: user=0.13 sys=0.00, real=0.03 secs] 
Heap after GC invocations=1 (full 0):
 PSYoungGen      total 76288K, used 752K [0x000000076b000000, 0x0000000774500000, 0x00000007c0000000)
  eden space 65536K, 0% used [0x000000076b000000,0x000000076b000000,0x000000076f000000)
  from space 10752K, 6% used [0x000000076f000000,0x000000076f0bc020,0x000000076fa80000)
  to   space 10752K, 0% used [0x0000000773a80000,0x0000000773a80000,0x0000000774500000)
 ParOldGen       total 2785280K, used 2097160K [0x00000006c1000000, 0x000000076b000000, 0x000000076b000000)
  object space 2785280K, 75% used [0x00000006c1000000,0x0000000741002020,0x000000076b000000)
 Metaspace       used 2760K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 302K, capacity 386K, committed 512K, reserved 1048576K
}
...
{Heap before GC invocations=3 (full 1):
 PSYoungGen      total 141824K, used 712K [0x000000076b000000, 0x0000000774500000, 0x00000007c0000000)
  eden space 131072K, 0% used [0x000000076b000000,0x000000076b000000,0x0000000773000000)
  from space 10752K, 6% used [0x0000000773a80000,0x0000000773b32020,0x0000000774500000)
  to   space 10752K, 0% used [0x0000000773000000,0x0000000773000000,0x0000000773a80000)
 ParOldGen       total 2785280K, used 2097160K [0x00000006c1000000, 0x000000076b000000, 0x000000076b000000)
  object space 2785280K, 75% used [0x00000006c1000000,0x0000000741002020,0x000000076b000000)
 Metaspace       used 2760K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 302K, capacity 386K, committed 512K, reserved 1048576K
2021-04-27T00:29:10.867+0800: 1.438: [Full GC (Allocation Failure) [PSYoungGen: 712K->0K(141824K)] [ParOldGen: 2097160K->561K(201728K)] 2097872K->561K(343552K), [Metaspace: 2760K->2760K(1056768K)], 0.1741962 secs] [Times: user=0.14 sys=0.14, real=0.17 secs] 
Heap after GC invocations=3 (full 1):
 PSYoungGen      total 141824K, used 0K [0x000000076b000000, 0x0000000774500000, 0x00000007c0000000)
  eden space 131072K, 0% used [0x000000076b000000,0x000000076b000000,0x0000000773000000)
  from space 10752K, 0% used [0x0000000773a80000,0x0000000773a80000,0x0000000774500000)
  to   space 10752K, 0% used [0x0000000773000000,0x0000000773000000,0x0000000773a80000)
 ParOldGen       total 201728K, used 561K [0x00000006c1000000, 0x00000006cd500000, 0x000000076b000000)
  object space 201728K, 0% used [0x00000006c1000000,0x00000006c108c620,0x00000006cd500000)
 Metaspace       used 2760K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 302K, capacity 386K, committed 512K, reserved 1048576K
}

    GC前后打印的堆信息分别是GC前后堆内存的快照信息，其中，Heap before GC invocations=1 (full 0):部分是GC前的堆信息；Heap after GC invocations=1 (full 0):是GC后的堆信息；两者之间的是本次GC的详细信息。

  • Minor GC日志分析

    2021-04-27T00:29:10.817+0800: 1.389: [GC (Allocation Failure) [PSYoungGen: 3932K->752K(76288K)] 2101084K->2097912K(2861568K), 0.0261894 secs] [Times: user=0.13 sys=0.00, real=0.03 secs]
    1. "2021-04-27T00:29:10.817+0800"是GC发生的详细时间节点，"1.389"是从JVM启动以来经过的秒数。
    2. "PSYoungGen"是GC类型，用来区分是新生代GC还是老年代GC，PSYoungGen代表是新生代GC。
    3. aK->bK(cK)　的形式表示的含义是GC前该区域已使用的空间容量为a，GC后该区域的使用容量为b，该区域的总容量为c。相应地，"3932K"是GC前该区域已使用的空间容量，752K是GC后该区域的使用容量，76288K是该区域的总容量；2101084K是GC前Java堆已使用的空间容量，2097912K是GC后Java堆已使用的空间容量，2861568K是Java堆的总容量。
    4. Times部分代表该内存本次GC相关的耗时，单位是秒。user代表用户态消耗CPU的时间；sys代表内核消耗的CPU时间；real代表GC操作从开始到结束所经过的墙钟时间。

  • Full GC日志分析

    2021-04-27T00:29:10.867+0800: 1.438: [Full GC (Allocation Failure) [PSYoungGen: 712K->0K(141824K)] [ParOldGen: 2097160K->561K(201728K)] 2097872K->561K(343552K), [Metaspace: 2760K->2760K(1056768K)], 0.1741962 secs] [Times: user=0.14 sys=0.14, real=0.17 secs]

    1. PSYoungGen代表是新生代GC；ParOldGen代表是老年代GC

    2. Metaspace代表是元空间的GC，0.1741962 secs代表元空间GC操作的耗时

GC时间分析

墙钟时间包括各种非运算的等待耗时，例如等待磁盘IO、等待线程阻塞等，而CPU时间不包含这些，但是当系统有多CPU或者多核的时候 ，多线程操作会叠加这些CPU时间，所以有时候会出现user或sys的时间超过real时间的现象。

  1. 通常情况下，垃圾回收的过程是并发执行的，一般都会是user+sys>real

  2. 当使用了串行垃圾回收器时，正常情况下应该是user+sys=real

  3. 当出现real远大于user+sys时，可能是由于频繁的IO（网络IO或磁盘IO）操作或者缺乏CPU资源引起的

  • IO密集型

    因为记录GC日志也是磁盘读写，当同一时间其它IO操作比较多，会导致GC事件延迟，从而影响最后的real时间。程序本身的IO或者同一机器上其它进程的频繁IO都会影响最终的real值，当频繁的IO操作确实存在时，可以采用以下两种方式改进：一是优化程序本身的IO逻辑；二是消除其它进程IO对当前程序的影响。

  • CPU密集型

    当程序本身是CPU密集型应用或者同一机器上其它进程占用了大量的CPU资源，有可能会出现当前程序分配不到CPU资源的情况，会导致real值远大于user+sys。可以采用以下方式改进：一是优化程序内部的线程使用，确保无冗余线程；二是增加虚拟机或者容器本身的CPU配置，提升机器总的计算能力。

参考文献

深入理解Java虚拟机

foolishboy_w
关注
专栏目录
JVM面试与调优教程(10)-GC日志案例分析
鸟哥哥的专栏
08-01 870
JVM GC日志案例分析
linux jvm gc日志分析,JVM GC 日志详解
weixin_29711471的博客
05-01 1132
本文采用的JDK版本：java version "1.8.0_144"Java(TM) SE Runtime Environment (build 1.8.0_144-b01)Java HotSpot(TM) 64-Bit Server VM (build 25.144-b01, mixed mode)一、GC 日志参数设置JVM GC格式日志的主要参数包括如下8个：-XX:+PrintGC 输出...
JVM的GC日志分析
泡^泡
02-22 520
JVM的GC日志分析
JVM 分析GC日志
weixin_43967582的博客
12-17 392
5.分析GC日志 一、GC日志格式 1.GC分类 针对HotSpot VM的实现，它里面的GC按照回收区域又分为两大种类型：一种是部分收集（Partial GC），一种是整堆收集（Full GC） 部分收集（Partial GC）：不是完整收集整个Java堆的垃圾收集。其中又分为： 新生代收集（Minor GC / Young GC）：只是新生代（Eden / S0, S1）的垃圾收集 老年代收集（Major GC / Old GC）：只是老年代的垃圾收集。目前，只有CMS GC会有单独收
jvm的GC日志分析
Flyer的后花园
08-09 777
M的GC日志的主要参数包括如下几个： -XX:+PrintGC 输出GC日志 -XX:+PrintGCDetails 输出GC的详细日志 -XX:+PrintGCTimeStamps 输出GC的时间戳（以基准时间的形式） -XX:+PrintGCDateStamps 输出GC的时间戳（以日期的形式，如 2013-05-04T21:53:59.234+0800） -XX
JVM性能调优——GC日志分析
最新发布
码说芯语的博客
04-13 2967
生成GC日志、Parallel垃圾收集器日志解析、G1垃圾收集器日志解析、CMS垃圾收集器日志解析、日志解析工具
jvmgc日志分析工具
03-20
"jvmgc日志分析工具"专为解析和可视化JVM生成的GC日志而设计，帮助开发者识别内存瓶颈，调整内存设置，以及诊断可能的性能问题。 GC日志是JVM在运行过程中记录的关于垃圾收集活动的详细信息，包括垃圾收集的起始...
linux jvm gc日志分析,JVM之GC统计以及日志分析
weixin_39634985的博客
05-01 1029
环境&准备代码JDK环境openjdk version "1.8.0_191"编写一段代码，循环声明对象，并分配 10MB 堆空间，暴露web接口多次调用。for (int i = 0; i < 100; i++) {byte[] b1 = new byte[1024 * 1024 * 10];byte[] b2 = new byte[1024 * 1024 * 10];byte[]...
JVM系列之：日志分析工具：GCViewer、VisualVM、GCeasy
weixin_45987961的博客
04-01 1576
GCViewer GCViewer 是一个可以将 JVM 中的 gc log 可视化的工具，使用该工具可以帮助你充分的发现 JVM 垃圾回收中的潜在问题，让你可以更加准确的做出关于 JVM GC 优化的决策。 安装并启动 git clone https://github.com/chewiebug/GCViewer.git //或者用 IDEA打开项目后，用 maven进行打包 mvn clean pacakge //得到一个 jar包 cd target java -jar gcvie...
JVM性能调优之GC日志分析
qq_39093474的博客
09-01 2498
1.为什么需要GC日志 Java虚拟机GC日志是用于定位问题重要的日志信息，频繁的GC可能导致应用吞吐量下降，响应时间增加，甚至导致服务不可用。所以需要我们对GC日志进行分析并优化。 2. 如何开启GC日志 我们可以在JVM中设置参数-XX:+PrintGC或者-verbose:gc，默认GC日志是关闭的，但是如果想输出GC详细的日志，可以增加其他的辅助参数。可以根据自己的需求增加。 注意：GC的日志是以替换的方式(>)写入的，而不是追加(>>)，如果下次写入到同一个文件中的话，以前
【JVM】七、JVM 之 GC日志分析
qwertyuiopasdfghjklzxcvbnm
08-11 886
垃圾回收器的可用组合: ParNew and CMS “Concurrent Mark and Sweep” 是CMS的全称，官方给予的名称是：“Mostly Concurrent Mark and Sweep Garbage Collector”; 年轻代：采用 stop-the-world mark-copy 算法； 年老代：采用 Mostly Concurrent mark-...
JVM gc日志分析
shengpli′s blog
04-28 420
一、常用gc日志配置参数 -XX:+PrintGC #输出GC日志 -XX:+PrintGCDetails #输出GC的详细日志 -XX:+PrintGCTimeStamps #输出GC的时间戳（代表了GC发生的时间，这个数字的含义是从Java 虚拟机启动以来经过的秒数） -XX:+PrintGCDateStamps #输出GC的时间戳（以日期的形式，如 2013-05-04T21:53:59....
JVM之GC日志
weixin_44742132的博客
07-18 148
出自抽象写实派大作家本人之手：happy 2nd anniversary ~happy？happy个狗~❝JVM 相关的理论知识网上已经被讲的比较详细了，但是，不管是日常工作或是面试考察...
JVM 配置GC日志
egegerhn的博客
08-18 2150
通过-XX:+UseGCLogfileRotation -XX:NumberOfGCLogfiles=N -XX:GCLogfileSize=N标志可以控制日志文件的循环。多种方法都能开启GC的日志功能，其中包括：使用-verbose:gc或-XX:+PrintGC这两个标志中的任意一个能创建基本的GC日志。除了使用详细的GC日志，我们还推荐使用-XX:+PrintGCTimeStamps或者-XX:+PrintGCDateStamps，由于日期戳需要进行格式化，所以它的效率可能会受轻微的影响，...
JVM-GC日志详细分析
流浪的喵的博客
11-21 1883
JVM-GC日志详细分析 1.打印GC日志参数 1.3 基本JVM参数 参数示例 描述说明 -verbose:gc 控制台打印GC参数 -Xms20M 初始堆大小 20M -Xmx20M 最大堆大小20M 一般情况下-Xms和-Xmx这两个值设为相同大小 -Xmn10M 新生代最大可用值10M -XX:+PrintGC 触发GC时日志打印 -XX:+PrintGCDetails 触发GC时日志打印详细 –XX:UseSerialGC 串行回收 -XX:Surviv
jvm gc日志分析
赶路人儿
05-31 890
JVM的GC日志的主要参数包括如下几个： -XX:+PrintGC 输出GC日志 -XX:+PrintGCDetails 输出GC的详细日志 -XX:+PrintGCTimeStamps 输出GC的时间戳（以基准时间的形式） -XX:+PrintGCDateStamps 输出GC的时间戳（以日期的形式，如 2013-05-04T21:53:59.234+0800） -XX:+PrintH
JVM中GC的日志分析
sober
08-22 261
通过阅读GC日志，我们可以了解Java虛拟机内存分配与回收策略。内存分配与垃圾回收的参数列表 一XX： +PrintGC 输出Gc日志。类似： 一verbose：gc 一XX： +PrintGCDetails 输出GC的详细日志 一XX： +PrintGCTimeStamps 输出GC的时间戳（以基准时间的形式） 一XX： +PrintGCDateStamps输出GC的时间戳（以日期的形式，如2013一05一04T21 ： 53：59.234+0800 ） 一XX： +PrintHeapAtGC 在进行G
Jvm GC日志测试分析
ll910280793的博客
02-25 670
设置idea java启动参数 设置 堆内存200M 新生代50M 并打印GC日志 -XX:+PrintGCDetails -Xmx200M -Xms200M -Xmn50M -XX:+PrintTenuringDistribution -XX:+PrintGCDateStamps 单独运行main方法查看程序本身所占用的内存 默认Eden区使用3898k 10% 测试GC过程 public class test { public static void main(String[].
评论
添加红包

请填写红包祝福语或标题

个

红包个数最小为10个

元

红包金额最低5元

当前余额3.43元 前往充值 >
需支付：10.00元
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付元
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明：

1.余额是钱包充值的虚拟货币，按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载，可以购买VIP、付费专栏及课程。

余额充值