记录一次concurrent mode failure问题排查过程以及解决思路

本文通过分析GC日志找出定时任务导致的内存问题,并对使用不当的线程池进行了优化。

摘要生成于 C知道 ,由 DeepSeek-R1 满血版支持, 前往体验 >

 

背景:后台定时任务脚本每天凌晨5点30会执行一个批量扫库做业务的逻辑。

 

gc错误日志:

2017-07-05T05:30:54.408+0800: 518534.458: [CMS-concurrent-mark-start]
2017-07-05T05:30:55.279+0800: 518535.329: [GC 518535.329: [ParNew: 838848K->838848K(1118464K), 0.0000270 secs]
[CMS-concurrent-mark: 1.564/1.576 secs] [Times: user=10.88 sys=0.31, real=1.57 secs]
 (concurrent mode failure): 2720535K->2719116K(2796224K), 13.3742340 secs] 
 3559383K->2719116K(3914688K), 
 [CMS Perm : 38833K->38824K(524288K)], 13.3748020 secs] [Times: user=16.19 sys=0.00, real=13.37 secs]
2017-07-05T05:31:08.659+0800: 518548.710: [GC [1 CMS-initial-mark: 2719116K(2796224K)] 2733442K(3914688K), 0.0065150 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2017-07-05T05:31:08.666+0800: 518548.716: [CMS-concurrent-mark-start]
2017-07-05T05:31:09.528+0800: 518549.578: 
[GC 518549.578: [ParNew: 838848K->19737K(1118464K), 0.0055800 secs] 
3557964K->2738853K(3914688K), 0.0060390 secs] [Times: user=0.09 sys=0.00, real=0.01 secs]
[CMS-concurrent-mark: 1.644/1.659 secs] [Times: user=14.15 sys=0.84, real=1.66 secs]
2017-07-05T05:31:10.326+0800: 518550.376: [CMS-concurrent-preclean-start]
2017-07-05T05:31:10.341+0800: 518550.391: [CMS-concurrent-preclean: 0.015/0.015 secs] [Times: user=0.05 sys=0.02, real=0.02 secs]
2017-07-05T05:31:10.341+0800: 518550.391: [CMS-concurrent-abortable-preclean-start]

借鉴于:understanding-cms-gc-logs 

得知导致concurrent mode failure的原因有是: there was not enough space in the CMS generation to promote the worst case surviving young generation objects. We name this failure as “full promotion guarantee failure” 

解决的方案有: The concurrent mode failure can either be avoided increasing the tenured generation size or initiating the CMS collection at a lesser heap occupancy by setting CMSInitiatingOccupancyFraction to a lower value and setting UseCMSInitiatingOccupancyOnly to true.

第二种方案需要综合考虑下,因为如果设置的CMSInitiatingOccupancyFraction过低有可能导致频繁的cms 降低性能。[参考不建议3g下配置cms:why no cms under 3G

 

问题排查:

1 jvm参数配置 -Xmx4096m -Xms2048m   -XX:CMSInitiatingOccupancyFraction=70 -XX:+UseCMSCompactAtFullCollection -XX:MaxTenuringThreshold=10 -XX:-UseAdaptiveSizePolicy -XX:PermSize=512M -XX:MaxPermSize=1024M -XX:SurvivorRatio=3 -XX:NewRatio=2 -XX:+PrintGCDateStamps -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails  几乎没什么问题

2 从报警时间看每天凌晨5点30报警一次, 应该是定时任务的问题。

该问题很容易排查,服务是个脚本服务,线上业务逻辑几乎没有,所以根据时间点找到定时任务的业务逻辑,就可以分析出来问题。

业务代码:

     int batchNumber = 1;
        int realCount = 0;
        int offset = 0;
        int limit = 999;
        int totalCount = 0;
        //初始化20个大小的线程池
        ExecutorService service = Executors.newFixedThreadPool(20);
        while (true) {
            LogUtils.info(logger, "{0},{1}->{2}", batchNumber, offset, (offset + limit));
            try {
                //分页查询
                Set<String> result = query(offset, limit);
                realCount = result.size();
                //将查询出的数据放入线程池执行
                service.execute(new AAAAAAA(result, batchNumber));
            } catch (Exception e) {
                LogUtils.error(logger, e, "exception,batch:{0},offset:{1},count:{2}", batchNumber, offset, limit);
                break;
            }
            totalCount += realCount;
            if (realCount < limit) {
                break;
            }
            batchNumber++;
            offset += limit;
        }
        service.shutdown();

用了一个固定20个线程的线程池,循环执行每次从数据库里面取出来999条数据放到线程池里面去跑

分析

newFixedThreadPool
底层用了一个
LinkedBlockingQueue
无限队列,而我的数据有2kw+条,这样死循环取数据放到队列里面没有把内存撑爆算好的吧???

最后换成
BlockingQueue<Runnable> queue = new ArrayBlockingQueue<Runnable>(20);
ThreadPoolExecutor service = new ThreadPoolExecutor(20, 20, 1, TimeUnit.HOURS, queue, new ThreadPoolExecutor.CallerRunsPolicy());

  用了个固定长度的队列,而且失败策略用的callerruns,可以理解为不能执行并且不能加入等待队列的时候主线程会直接跑run方法,会造成多线程变单线程,降低效率。

明天看看效果如何。

 

 

后记:

  对于线程池阻塞更好的方案在这里: 重写一个拒绝策略,让队列满的时候阻塞主线程,等待队列消费后恢复。

new RejectedExecutionHandler() {
	@Override
	public void rejectedExecution(Runnable r, ThreadPoolExecutor executor) {
		if (!executor.isShutdown()) {
			try {
				executor.getQueue().put(r);
			} catch (InterruptedException e) {
				// should not be interrupted
			}
		}
	}
};

  用put代替offer,前者失败后阻塞,后者失败后直接返回false,线程池的设计还是很有意思的。

 

详见:并发编程网-支持生产阻塞的线程池

 

转载于:https://www.cnblogs.com/Jaxlinda/p/7145912.html

<think>嗯,用户之前问过怎么排查CPU飙升的问题,现在又问如何排查GC的问题。看来他们对系统性能调优比较感兴趣,可能是在实际工作中遇到了相关的问题。我需要先回顾一下之前的回答,确保这次的内容不重复,同时又能深入GC排查的具体步骤。 首先,用户提到“for gc的问题”,可能是指频繁的垃圾回收导致应用性能下降,比如CPU使用率高或者应用暂停时间过长。需要分步骤讲解如何确认GC问题,使用哪些工具,以及常见的GC问题模式。 之前的回答里,在CPU排查部分已经提到过使用jstat检查GC情况,但用户现在专门问GC,需要更详细。可能需要包括确认GC现象、分析GC日志、堆内存分析、常见问题模式、工具使用、案例和优化建议。 要注意用户可能对GC机制不太熟悉,所以需要解释一些术语,比如Full GC,Young GC,STW等。同时,考虑到用户可能是在生产环境操作,需要提醒他们谨慎使用一些命令,避免影响服务。 另外,用户可能使用的是Java应用,所以工具方面要围绕JDK自带的工具,如jstat、jmap、jcmd,以及常用的图形化工具如MAT。还要提到开启GC日志的重要性,因为这是事后分析的关键。 需要结构清晰,分步骤说明,每一步给出命令示例和解释。比如先确认是否是GC导致的问题,然后查看GC日志,分析内存使用情况,最后给出优化建议。常见问题模式可以用表格形式,方便用户对照。 还要注意用户可能的误区,比如以为GC频率高就一定是问题,其实需要结合应用的具体情况。比如高吞吐量应用可能会有较多的Young GC,这是正常的。而Full GC频繁则需要重点关注。 最后,提醒用户在进行内存dump时,考虑文件大小和系统负载,建议在低峰期操作。同时,给出参数调整的例子,如调整堆大小、选择合适的GC算法等。</think>以下是排查GC问题的详细指南(针对Java应用): --- ### 一、现象确认阶段 ```bash # 1. 实时监控GC活动 jstat -gcutil <pid> 1000 # 每秒刷新GC数据 # 2. 查看内存整体占用 jmap -heap <pid> # 堆内存分布概览 ``` **关键指标判断**: - **FGC**列:Full GC次数快速增加(如5秒内+3次) - **GCT**列:GC总耗时占比超过5%(如运行10分钟,GC耗时30秒) - **O**列(Old区):持续接近100%时触发Full GC --- ### 二、GC日志分析(必须开启) 1. **启动参数添加**: ```bash -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/path/to/gc.log ``` 2. **日志特征分析**: ```java // 正常Young GC(耗时可控) 2023-08-01T14:22:33.123+0800: [GC (Allocation Failure) [PSYoungGen: 614400K->51200K(650240K)] 819200K->307200K(1048576K), 0.0357233 secs] // 危险Full GC(STW时间过长) 2023-08-01T14:23:01.456+0800: [Full GC (Ergonomics) [PSOldGen: 398000K->396000K(409600K)] 602300K->599800K(1048576K), 3.452 secs] ``` **异常模式识别**: - `Allocation Failure`:年轻代空间不足 - `Metadata GC Threshold`:元空间溢出 - `Ergonomics`:JVM自动触发的GC - `System.gc()`:代码中手动触发GC --- ### 三、内存分析三板斧 1. **堆内存直方图** ```bash jmap -histo:live <pid> | head -n 20 # 显示对象数量TOP20 ``` 2. **堆转储分析** ```bash jmap -dump:format=b,file=heapdump.hprof <pid> ``` **推荐工具**:Eclipse MAT(分析内存泄漏对象) 3. **元空间检查** ```bash jstat -gcmetacapacity <pid> # 关注MCMN/MCMX列 ``` --- ### 四、常见GC问题模式 | 现象 | 诊断线索 | 解决方案 | |--------------------------|--------------------------|----------------------------| | 频繁Young GC | 年轻代过小/短生命周期对象过多 | 增大-Xmn/-XX:NewSize | | Full GC后内存不释放 | 内存泄漏(对象被强引用) | MAT分析GC Roots引用链 | | CMS并发模式失败 | 日志出现`Concurrent Mode Failure` | 增大老年代空间/降低对象提升速率 | | G1 Evacuation Failure | 日志出现`to-space exhausted` | 增大堆内存/调整-XX:G1ReservePercent | | 元空间OOM | Metaspace使用率持续100% | 增大-XX:MaxMetaspaceSize | --- ### 五、高级诊断工具 1. **GC可视化分析** ```bash # 使用gceasy.io在线分析GC日志 上传gc.log后自动生成报告 ``` 2. **JVM内置诊断** ```bash jcmd <pid> GC.class_histogram # 替代jmap -histo ``` 3. **动态观察分配速率** ```bash # 使用vjtools的vjmap工具 ./vjmap.sh -all <pid> > allocation.txt ``` --- ### 六、经典案例处理流程 **案例1:内存泄漏** 1. 现象:每小时Full GC次数从10次上升到200次 2. 分析: - `jstat`显示Old区使用率95%以上 - `jmap`发现HashMap$Node对象异常增长 3. 定位:缓存组件未设置TTL,导致数据无限累积 **案例2:元空间溢出** 1. 现象:频繁Full GC伴随`Metaspace`错误 2. 分析: - `-XX:MaxMetaspaceSize=256m`设置过小 - 使用CGLIB动态生成类未及时回收 3. 解决:增加元空间大小,修复类加载器泄漏 --- ### 七、参数调优建议 1. **基础参数模板**: ```bash -Xmx4g -Xms4g -XX:NewRatio=2 -XX:+UseG1GC -XX:MaxGCPauseMillis=200 ``` 2. **关键参数说明**: - `-XX:SurvivorRatio=8`:调整Eden与Survivor区比例 - `-XX:MaxTenuringThreshold=15`:控制对象晋升阈值 - `-XX:+ParallelRefProcEnabled`:加速引用处理 --- ### 八、注意事项 1. **生产环境操作规范**: - `jmap -dump`可能导致应用暂停(建议在流量低谷期执行) - 优先使用`-histo:live`替代全量dump - 容器环境需确保有足够权限执行命令 2. **防御性编码建议**: ```java // 避免大对象长期存活示例 void processRequest() { byte[] buffer = new byte[10 * 1024 * 1024]; // 10MB临时对象 // 使用后及时置空(非必须,但有助于GC识别) buffer = null; } ``` 建议按照`监控发现 -> 日志分析 -> 内存快照 -> 代码定位`的流程排查。如果使用云服务,可配合APM工具(如ARMS)实现GC异常自动告警。
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

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

抵扣说明:

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

余额充值