记一次GC 排查及优化

已于 2023-12-15 14:14:16 修改
阅读量1.3k 收藏
点赞数
分类专栏： java相关 文章标签： java jvm.gc java虚拟机
于 2021-06-28 00:54:46 首次发布
版权声明：本文为博主原创文章，遵循 CC 4.0 BY-SA 版权协议，转载请附上原文出处链接和本声明。
本文链接：https://blog.csdn.net/qq_20340547/article/details/118102297
版权

GC日志详情

Java HotSpot(TM) 64-Bit Server VM (25.25-b02) for linux-amd64 JRE (1.8.0_25-b17), built on Sep 17 2014 17:32:11 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 32779816k(1555852k free), swap 0k(0k free)
CommandLine flags: -XX:InitialHeapSize=4294967296 -XX:MaxHeapSize=4294967296 -XX:+PrintClassHistogram -XX:+PrintGC -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution -XX:ThreadStackSize=512 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC 
2021-06-22T16:04:47.326+0800: 2.223: Total time for which application threads were stopped: 0.0002528 seconds
2021-06-22T16:04:47.352+0800: 2.249: Total time for which application threads were stopped: 0.0001974 seconds
{Heap before GC invocations=1 (full 0):
 PSYoungGen      total 1223168K, used 796938K [0x000000076ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 1048576K, 76% used [0x000000076ab00000,0x000000079b542b78,0x00000007aab00000)
  from space 174592K, 0% used [0x00000007b5580000,0x00000007b5580000,0x00000007c0000000)
  to   space 174592K, 0% used [0x00000007aab00000,0x00000007aab00000,0x00000007b5580000)
 ParOldGen       total 2796544K, used 0K [0x00000006c0000000, 0x000000076ab00000, 0x000000076ab00000)
  object space 2796544K, 0% used [0x00000006c0000000,0x00000006c0000000,0x000000076ab00000)
 Metaspace       used 20827K, capacity 21114K, committed 21248K, reserved 1067008K
  class space    used 2916K, capacity 3027K, committed 3072K, reserved 1048576K
2021-06-22T16:04:51.184+0800: 6.081: [GC (Metadata GC Threshold) 
Desired survivor size 178782208 bytes, new threshold 7 (max 15)
[PSYoungGen: 796938K->23321K(1223168K)] 796938K->23337K(4019712K), 0.0630982 secs] [Times: user=0.06 sys=0.01, real=0.06 secs] 
Heap after GC invocations=1 (full 0):
 PSYoungGen      total 1223168K, used 23321K [0x000000076ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 1048576K, 0% used [0x000000076ab00000,0x000000076ab00000,0x00000007aab00000)
  from space 174592K, 13% used [0x00000007aab00000,0x00000007ac1c6498,0x00000007b5580000)
  to   space 174592K, 0% used [0x00000007b5580000,0x00000007b5580000,0x00000007c0000000)
 ParOldGen       total 2796544K, used 16K [0x00000006c0000000, 0x000000076ab00000, 0x000000076ab00000)
  object space 2796544K, 0% used [0x00000006c0000000,0x00000006c0004000,0x000000076ab00000)
 Metaspace       used 20827K, capacity 21114K, committed 21248K, reserved 1067008K
  class space    used 2916K, capacity 3027K, committed 3072K, reserved 1048576K
}
{Heap before GC invocations=2 (full 1):
 PSYoungGen      total 1223168K, used 23321K [0x000000076ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 1048576K, 0% used [0x000000076ab00000,0x000000076ab00000,0x00000007aab00000)
  from space 174592K, 13% used [0x00000007aab00000,0x00000007ac1c6498,0x00000007b5580000)
  to   space 174592K, 0% used [0x00000007b5580000,0x00000007b5580000,0x00000007c0000000)
 ParOldGen       total 2796544K, used 16K [0x00000006c0000000, 0x000000076ab00000, 0x000000076ab00000)
  object space 2796544K, 0% used [0x00000006c0000000,0x00000006c0004000,0x000000076ab00000)
 Metaspace       used 20827K, capacity 21114K, committed 21248K, reserved 1067008K
  class space    used 2916K, capacity 3027K, committed 3072K, reserved 1048576K
2021-06-22T16:04:51.247+0800: 6.144: [Full GC (Metadata GC Threshold) [PSYoungGen: 23321K->0K(1223168K)] [ParOldGen: 16K->22263K(2796544K)] 23337K->22263K(4019712K), [Metaspace: 20827K->20826K(1067008K)], 0.0839136 secs] [Times: user=0.17 sys=0.03, real=0.08 secs] 
Heap after GC invocations=2 (full 1):
 PSYoungGen      total 1223168K, used 0K [0x000000076ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 1048576K, 0% used [0x000000076ab00000,0x000000076ab00000,0x00000007aab00000)
  from space 174592K, 0% used [0x00000007aab00000,0x00000007aab00000,0x00000007b5580000)
  to   space 174592K, 0% used [0x00000007b5580000,0x00000007b5580000,0x00000007c0000000)
 ParOldGen       total 2796544K, used 22263K [0x00000006c0000000, 0x000000076ab00000, 0x000000076ab00000)
  object space 2796544K, 0% used [0x00000006c0000000,0x00000006c15bdf88,0x000000076ab00000)
 Metaspace       used 20826K, capacity 21112K, committed 21248K, reserved 1067008K
  class space    used 2916K, capacity 3026K, committed 3072K, reserved 1048576K
}

日志参数说明

  • CommandLine flags：命令行标识（构建代码Java 命令行参数）
  • -XX:InitialHeapSize=4294967296 默认初始化堆内存
  • -XX:MaxHeapSize=4294967296 最大堆内存大小 -XX:InitialHeapSize and -XX:MaxHeapSize are often set to the same value. 最好设置同样大小，详情见官文：http://docs.oracle.com/javase/8/docs/technotes/guides/vm/gctuning/index.html.
  • -XX:+PrintClassHistogram 按Ctrl+c 打印印类实例直方图
  • -XX:+PrintGC 打印每一次gc信息
  • -XX:+PrintGCApplicationStoppedTime 允许打印暂停（例如GC暂停）持续的时间（eg信息：2021-06-21T22:16:40.590+0800: 4.801: Total time for which application threads were stopped: 0.0004071 seconds）
  • -XX:+PrintGCDateStamps 允许在每个GC打印日期戳
  • -XX:+PrintGCDetails 支持在每个GC打印详细消息
  • -XX:+PrintGCTimeStamps允许在每个GC打印时间戳
  • -XX:+PrintHeapAtGC 在进行GC的前后打印出堆的信息
  • -XX:+PrintTenuringDistribution 允许打印使用年限信息,可见官方文档(eg信息:Desired survivor size 178782208 bytes, new threshold 7 (max 15)，所需幸存者大小178782208字节，新阈值7（最大15)
  • -XX:ThreadStackSize=512 设置线程栈大小
  • -XX:+UseCompressedClassPointers
  • -XX:+UseCompressedOops禁止使用压缩指针。默认情况下，此选项处于启用状态，当Java堆大小小于32gb时，将使用压缩指针。启用此选项后，对象引用将表示为32位偏移量，而不是64位指针，这通常会在Java堆大小小于32 GB的情况下运行应用程序时提高性能。此选项仅适用于64位JVM**-XX:+UseParallelGC** 允许使用并行清除垃圾收集器(Parallel Scavenge收集器)（也称为吞吐量收集器）通过利用多个处理器来提高应用程序的性能

JVM参数官方说明文档

https://docs.oracle.com/javase/8/docs/technotes/tools/unix/java.html

GC发生前的堆内存参数解读

{Heap before GC invocations=1 (full 0): #GC发生前的堆内存信息,调用一次 full GC 0次

PSYoungGen PS(Parallel Scavenge收集器)新生代内存大小

eden 伊甸园区内存大小

from from区内存大小

to to区内存大小

ParOldGen Par(Parallel Old收集器)老年代内存大小

Metaspace 元空间内存

class space Java中压缩指针（Compressed pointers）的含义是允许在64bit的平台上用32bit地址来引用对象，其实现原理是64bit的基址加上32bit的偏移地址，最终生成64bit的虚拟地址，然后操作系统页表寻址找到64bit的物理地址完成寻址

used 2916K,apacity 21112K, committed 21248K, reserved 1067008K
其中used和capacity是从类加载器的角度来衡量的，而committed和reserved是从操作系统地址空间的角度来衡量的：

  • used：是分配给所有类加载器的metachunk中用来存储元数据的部分的大
  • capacity：分配给所有类加载器的metachunk的大小，包含每个metachunk的head、used、wasted和current metachunk的free部分
  • committed：向OS申请的内存中已经分配物理内存的大小，包含VirtualSpaceList中所有node已经commit的部分（也就是非当前node+当前node commit的部分），或者说所有类加载器的capacity+全局空闲链表Chunk Manager+硬件预留HWM margin
  • reserved： JVM进程虚拟地址空间的部分，像class metaspace默认CompressedClassSpaceSize是1GB，所以reserved就是1GB

[0x000000076ab00000,0x000000076ab00000,0x00000007aab00000)
三个数字在HotSpot里分别称为low_boundary、high、high_boundary。

  • low_boundary: reserved space的最低地址边界；通常也跟“low”相等，这是commited space的最低地址边界
  • high: commited space的最高地址边界
  • high_boundary: reserved space的最高地址边界。

GC详细信息

[PSYoungGen: 796938K->23321K(1223168K)] 796938K->23337K(4019712K), 0.0630982 secs] [Times: user=0.06 sys=0.01, real=0.06 secs]

GC说明
参考链接：Java8GC类型

  1. 年轻代发生一次Minor GC ，这里我们要知道Minor GC的触发条件：
    Minor GC/Young GC的触发条件: 年轻代空间不足,触发Minor GC,具体就是指的是年轻代的Eden区满了,Survivor区满了不会触发GC,每次触发Minor GC,都会顺带处理Survivor区,复制调配from-to区。
    Minor GC的特点:非常频繁切速度快,会引发STW(Stop the World),暂停用户线程,等待GC结束之后用户线程恢复运行

  2. 紧接着发生第二次Full GC

2021-06-22T16:04:51.247+0800: 6.144: [Full GC (Metadata GC Threshold) [PSYoungGen: 23321K->0K(1223168K)] [ParOldGen: 16K->22263K(2796544K)] 23337K->22263K(4019712K), [Metaspace: 20827K->20826K(1067008K)], 0.0839136 secs] [Times: user=0.17 sys=0.03, real=0.08 secs]

GC说明

Major GC/Old GC的触发条件: 对象从老年代消失则产生了Major GC/Old GC,老年代空间不足,则先触发Minor GC ,空间仍然不足则触发Major GC

Major GC的特点:比Minor GC慢十倍以上,STW时间更长

Full GC的触发条件:

  • 显示调用System.gc,系统建议执行GC,但是不会必然执行;
  • 老年代空间不足;
  • 方法区空间不足Minor GC晋升老年代的对象大小大于老年代的可用内存大小
  • minor gc之后进入老年代的平均大小大于老年代的可用内存
  • minor gc时，向to区复制对象内存大于to区内存，直接向老年代转移，老年代内存任然不能装下该对象

结论：

  1. 首先查看gc之前的堆内存（如下图），存在Young GC之后存在大量对象晋升到老年代
    在这里插入图片描述

  2. 并且Full GC 发生之后,回收老年代内存数量很小的情况出现（如下图），说明存在大量的对象引用没有释放，或者大量的对象晋升到老年代在这里插入图片描述在这里插入图片描述

  3. 在年轻代触发GC之后，又有大量的内存被占用，说明说明代码中具有较大的内存占用对象被创建（eg:查询大数据量的数据）在这里插入图片描述

  4. 并且老年代GC之后也是回收效率很低，有两种情况：大量老年代对象未释放；新的对象晋升到老年代，并且从日志中GC之后年轻代大量晋升到老代(晋升老年代的条件只有两种情况：达到晋升年龄（看日志代码对应不具备这样的条件），大数据对象直接晋升老年代 )推断代码中应该是存在大数据对象被创建，代码存在中大量查询大量数据的操作，结果查看代码确实存在这样的问题在这里插入图片描述

  5. 但是发生Full GC的日志后面显示Metadata GC Threshold，有想过是否是对象达到元空间的阈值触发老了Full GC，首先放到元空间的数据我们需要清除是那些数据（存储每个类的信息（包括类的名称、方法信息、字段信息）、静态变量、常量、运行时常量池(Runtime Constant Pool)以及编译器编译后的代码等）,推断有可能是加载类中存在占用较大内存的字段，或则大字符串常量，反查代码确实存在大量的sql拼接操作（此处还需考证）在这里插入图片描述

  6. 随后再开heaphero 分析文件，以及Jprofile 分析的dump 文件，基本能和以上推断吻合，所以就此展开代码优化在这里插入图片描述在这里插入图片描述
    在这里插入图片描述

在这里插入图片描述
在排查问题过程中用到的工具：

  • Jprofile 强大的java性能分析工具（付费的，但是你懂的）
  • gceasy 一个在线分析gc 日志的网站
  • heaphero 一个在线分析GC dump文件的网站

其他常用的GC分析工具:

  • GCViewer
  • GCHisto
  • GCLogViewer
  • Hpjmeter
  • garbagecat
不懂事的小流氓
关注
  • 0
    点赞
  • 踩
  • 0
    收藏
    觉得还不错? 一键收藏
  • 1
    评论
专栏目录
一次 Java 内存泄漏的排查解决过程详解
08-25
本文将详细介绍一次 Java 内存泄漏的排查解决过程，通过示例代码和实际案例，帮助读者更好地理解和排查 Java 内存泄漏。 一、问题描述 在本次值班中，我们的探测服务突然出现了大量的超时报警邮件，多数执行栈都在...
Linux 状态命令之内存状态 free
fenglepeng的博客
05-28 1002
简介 free指令会显示内存的使用情况，包括实体内存，虚拟的交换文件内存，共享内存区段，以及系统核心使用的缓冲区等。 语法 free [-bkmotV][-s <间隔秒数>] 参数说明： -b 　以Byte为单位显示内存使用情况。 -k 　以KB为单位显示内存使用情况。 -m 　以MB为单位显示内存使用情况。 -h 　以合适的单位显示内存使用情况，最大为三位数，自动计算对应的单位值。单位有： B = bytes K = kilos
OOM内存溢出汇总
maso88的专栏
03-27 7256
OOM内存溢出汇总 http://hellojava.info/?p=319 CASE1 一.出现问题 在前一段时间日常环境很不稳定，前端调用接口会出网络异常或服务不存在的异常。查询了服务器上的服务会有偶尔挂死的情况，服务器上的接口服务都不可用。于是我们对服务器上的状况进行了排查。 二.排查问题的过程 三.排查问题的步骤 1.查看服务器大概情况 首先最容易想到的是top命令，...
java垃圾回收（GC）
最新发布
km_bandits的博客
06-23 1060
G1 垃圾收集器将堆内存划分为若干个 Region，每个 Region 分区只能是一种角色，Eden区、S区、老年代区的其中一个，空白区域代表的是未分配的内存，最后还有个特殊的区域H（Humongous），专门用于存放巨型对象，如果一个对象的大小超过Region容量的50%以上，G1 就认为这是个巨型对象。在其他垃圾收集器中，这些巨型对象默认会被分配在老年代，但如果它是一个短期存活的巨型对象，放入老年代就会对垃圾收集器造成负面影响，触发老年代频繁GC。
docker-compose 运行kafka内存饱满
只想买把蝴蝶knife
04-26 1317
Java HotSpot(TM) 64-Bit Server VM warning: INFO: os::commit_memory(0x00000000c0000000, 1073741824, 0) failed; error='Cannot allocate memory' (errno=12) # # There is insufficient memory for the Java Runtime Environment to continue. # Native memory allocatio
hortonworks-registry-0.5.4 : Memory: 4k page, physical 3880928k(308720k free), swap 0k(0k free)
九师兄
07-04 9226
1. 背景 linux安装registry ，这个是一个schema管理服务 版本：hortonworks-registry-0.5.4 启动的时候报错 [deploy@deploy registy]$ ll total 232 drwxrwxr-x 2 deploy deploy 4096 Jul 31 21:06 bin drwxrwxr-x 4 deploy deploy 4096 Au...
JVM致命错误日志（hs_err_pid.log）解读
四火专栏
06-27 1150
致命错误出现的时候，JVM生成了hs_err_pid&lt;pid&gt;.log这样的文件，其中往往包含了虚拟机崩溃原因的重要信息。因为经常遇到，在这篇文章里，我挑选了一个，并且逐段分析它包含的内容（文件可以在文章最后下载）。默认情况下文件是创建在工作目录下的（如果没权限创建的话JVM会尝试把文件写到/tmp这样的临时目录下面去），当然，文件格式和路径也可以通过参数指定，比如： ...
linux 中swap 原理简介
私房菜
11-22 9863
1.什么是swap 从功能上讲，交换分区主要是在内存不够用的时候，将部分内存上的数据交换到 swap空间上，以便让系统不会因内存不够用而导致oom或者更致命的情况出现。 也就是说，当内存不够用时，我们使用 swap 分区来临时顶替。这种“拆东墙，补西墙”的方式应用于几乎所有的操作系统中。 使用 swap 交换分区，显著的优点是，通过操作系统的调度，应用程序实际可以使用的内存空间将远远超过系统的物理内存。由于硬盘空间的价格远比 RAM 要低，因此这种方式无疑是经济实惠的。当然，频繁地读写硬盘，会显著降.
【案例】记一次线上内存报警排查过程1
08-03
12. **问题总结**：案例引发了关于Java内存管理的一系列问题，如GC机制、内存回收策略以及如何优化内存使用等。 通过以上知识点，我们可以理解到线上服务内存问题的排查流程，以及如何有效地进行Java内存管理和优化...
记一次tomcat进程cpu占用过高的问题排查记录
09-29
这篇文章主要记录了一次排查Tomcat进程CPU占用过高的问题的过程。问题发生在Linux环境下，一个Tomcat Web服务的CPU占用率超过200%，导致请求无法响应。在排查过程中，作者首先通过`jps`命令找到JVM进程，接着使用`...
一次宕机后的网关性能优化.pdf
10-22
文档"一次宕机后的网关性能优化.pdf"主要探讨了在经历一次宕机事件后，如何对API网关进行性能优化以防止类似问题再次发生。本文将深入解析文档中的四个关键部分：PART ONE、PART TWO、PART THREE和PART FOUR，并提取...
VisualGC 内存监控工具
12-19
VisualGC是一款强大的内存监控工具，它作为JDK1.8中jvisualvm的插件，为Java开发者提供了直观且详细的内存使用情况分析。通过安装并使用VisualGC，我们可以更好地理解和优化Java应用程序的内存管理，从而提升程序...
JVM调优实战
想吃大盘鸡
09-03 1453
1，分析GC日志 Java HotSpot(TM) 64-Bit Server VM (25.40-b25) for windows-amd64 JRE (1.8.0_40-b26), built on Mar 7 2015 13:51:59 by "java_re" with MS VC++ 10.0 (VS2010) Memory: 4k page, physical 16632032k(7656916k free), swap 23447776k(8228024k free) CommandLi
【线上GC问题】-新生代设置过小且并发高的排查
泰山与水
08-04 1136
一、现象描述 1.线上系统aa出现大量的FullGC，差不多每5分钟左右就来一次 2.堆的总内存频繁的波动 3. 堆新生代的Eden区内存波动 4.新生代S区的内存波动图 5.老年代内存波动 二、系统参数配置 -Xms2g -Xmx2g -XX:MetaspaceSize=128m -XX:MaxMetaspaceSize=256m -XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled -XX:+UseCMSCo...
top-命令详解
06-23 3548
最近使用top命令进行系统cpu和memory的监控，发现top的命令还是很强大的# toptop - 05:47:41 up  3:03,  2 users,  load average: 1.24, 1.39, 1.26Tasks:  67 total,   1 running,  66 sleeping,   0 stopped,   0 zombieCpu(s):  0.7%us, 
tomcat启动时报swap空间用尽问题解决
01-26 1094
下午，同事在linux应用服务器重启tomcat的时候，一直启动不起来，后来用free命令查看系统资源的时候发现swap的free资源是0，（下图是问题处理之后的情况） 于是就想着查看下到底是哪些进程在占用资源，用如下命令进行查看 linux下获取占用CPU资源最多的10个进程，可以使用如下命令组合： ps aux|head -1;ps aux|grep -v PID|sort -rn
课堂笔记：JVM（四）JVM调优实战
沮丧的南瓜
05-31 801
四、GC调优实战 JVM调优主要就是调整下面两个指标 停顿时间：垃圾收集器做垃圾回收中断应用执行的时间。-XX:MaxGCPauseMillis 吞吐量：垃圾收集的时间和总时间的占比：1/(1+n),吞吐量为1-1/(1+n)。-XX:GCTimeRatio=n GC调优步骤 1.打印GC日志（后面是日志文件的输出路径） -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:D:/gc.log Tomcat可以直
linux显示swap空间为0,Linux查看Swap内存使用情况
weixin_39992199的博客
05-09 1557
查看指定进程swap使用情况# cat /proc/3315/smaps | grep Swap | moreSwap: 0 kBSwapPss: 0 kBSwap: 4 kBSwapPss: 4 kB编写脚本getswap.sh，查看所有进程的swap，并排序echo...
遇到swap free memory为0怎么办？
热门推荐
yupei6699的专栏
10-23 1万+
转载地址：https://blog.csdn.net/licanhua/article/details/7057143 遇到swap free memory为0怎么办？ 在实时系统中，一般swap都使用比较少，最佳状态就是used一直为0，但是 在工作中，我们遇到一个问题，swap的free空间正在不断变小。如果从top结果来看，我们能找出哪些process使用VSZ和RSS比较多，但是并不能确定...
评论 1
添加红包

请填写红包祝福语或标题

个

红包个数最小为10个

元

红包金额最低5元

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

抵扣说明：

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

余额充值