问题解决:Full GC固定10小时执行一次问题解决记录

一.问题描述

环境:JDK1.8、CentOS 6.9、容器undertow、Spring boot 1.5.8

最近线上运维,发现gclog里打印了很多Full GC的日志,通关gclog前面的时间可以看到间隔时间都是在10小时左右。

在这里插入图片描述

大概看了一下都是调用了System.gc()产生的Full GC,然后查看堆栈信息还远远没到Full GC的条件。

二.问题排查

以下源码均只写出相关部分,其他省略。

1.问题猜测

以前应用都是正常GC,想到最近一次上线代码中引入了apache的cxf包,版本为2.7.6。找到其中一段代码:

package org.apache.cxf.common.logging;

public class JDKBugHacks{
   
   
	public static void doHacks(){
   
   
        //省略前面代码...
		Method = method;
    	Class policyClass;
		try{
   
   
			if(!skipHack("org.apache.cxf.JDKBugHacks.gcRequestLatency")){
   
   
				policyClass = Class.forName("sum.misc.GC");
				method = policyClass.getDeclaredMethod("currentLatencyTarget");
				Long l = (Long)mehtod.invoke((Object)null);
				if(l != null && l.longValue() == 0L){
   
   
					method = policyClass.getDeclaredMethod("requestLatency",Long.TYPE);
					method.invoke((Object)null,36000000L);
					}
			}
		}catch(Throwable var16){
   
   
		    ;
		}
        //省略后面代码...
	}
}

这段代码在不同条件下利用反射调用了sun.misc.GC中的currentLatencyTarget方法或者requestLatency方法。而且刚好可以看到在进行requestLatency方法调用时,传入的第二个参数如果单位是毫秒的话,刚好是10小时。现在就是要看一下GC这个类中的方法。

GC类中相关的源码:

package sum.misc;

### Java服务在特定内存配置下的Full GC影响及持续时间 #### Full GC 的定义及其影响 Full GC 是指针对整个堆内存(包括年轻代和老年代)的一次完整的垃圾回收操作。由于其涉及范围广,通常会对应用程序性能造成显著影响[^3]。 对于指定的 JVM 参数 `-Xms4g` 和 `-Xmx4g`,意味着堆内存固定为 4GB;而新老年代的比例设置为 `2` 表明年轻代占总堆内存的 \( \frac{1}{3} \),即约 1.33GB,老年代则占据剩余部分约为 2.67GB。在这种情况下,如果发生频繁的 Full GC,则可能表明存在以下几种情况之一: - **内存分配不足**:当前堆大小不足以满足应用需求。 - **对象晋升过快**:大量短期存活的对象被快速提升到老年代,导致老年代空间迅速填满。 - **内存泄漏**:某些长期存在的对象未能释放,占用过多的老年代资源[^4]。 这些因素都会增加 Full GC 发生的概率,并延长每次 Full GC 执行时间长度。 #### Prometheus 和 Grafana 对 Full GC 的监控 Prometheus 结合 Grafana 提供了一种强大的方式来跟踪和可视化 JVM 性能数据。通过上述提到的 cadvisor jobname 配置[^2],可以实现对 RocketMQ 或其他基于 JVM 应用的服务进行详细的指标采集与展示。具体来说,在 Grafana 中利用预设好的模板 ID (`10477`)——名为 “Rocketmq_dashboard”,能够直观查看如下几个重要维度的信息: - **Full GC 频率**:衡量单位时间内发生的 Full GC 数量,帮助识别是否存在异常高的收集活动。 - **Full GC 时间消耗**:记录单次或累积的停顿时间(STW),用于评估整体系统延迟表现。 例如,日志片段显示一次典型的 Full GC 过程耗时大约为 `0.0078362 seconds`[^5]。然而实际生产环境中因工作负载差异较大,具体的 STW 时间可能会有所不同。当观察到较高的 TP99 响应时间时,往往暗示着背后隐藏有较长的 Full GC 暂停事件正在干扰正常请求处理流程。 #### 接口响应时间Full GC 关系分析 接口响应时间直接受制于后台线程执行期间遇到的各种阻塞现象,其中包括但不限于由 Full GC 引发的应用暂停状况。一旦进入 Stop-The-World (STW)阶段,所有非必要的计算都将被迫中断直至完成相应的清理动作为止。因此即使平均来看某个 API 请求仅需几十毫秒即可返回结果,但如果恰逢此时发生了较久的全局同步操作比如前述案例中的那种程度(`~7 ms`),那么最终呈现出来的用户体验就会显得非常糟糕甚至不可接受。 以下是简化版模拟代码示例,演示如何捕获并报告此类关键性能统计数值: ```java public class GCMonitor { public static void main(String[] args) throws InterruptedException { long start = System.currentTimeMillis(); Runtime.getRuntime().addShutdownHook(new Thread(() -> { System.out.println("Total runtime: " + (System.currentTimeMillis() - start)); })); while(true){ Object o = new byte[1_024 * 1_024]; // Allocate memory continuously. try {Thread.sleep(1);} catch(Exception e){} } } } ``` 以上脚本不断创建新的大尺寸数组实例填充可用堆区直到触发必要级别的清扫机制为止。借助外部工具链如 VisualVM 或者 jstat 等命令行实用程序配合内部 MBean 数据源共同作用下可进一步深入剖析潜在瓶颈所在位置。 ---
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

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

抵扣说明:

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

余额充值