【业务场景】京东实际场景，频繁GC引起的CPU飙高问题的解决

妖狐艹你老母 2024-05-06 09:37 9阅读 0赞

![773e60d9d07b4cb08bfa2919d1e1808d.png][]

**目录**

1.业务介绍

2.判断任务类型

3.CPU飙高的原因

--------------------

## 1.业务介绍 ##

本文的业务场景是京东零售线公开的一篇文章，文章内容详细介绍了京东零售线如何将广告相关的定时任务从半小时优化到秒级的，原文链接：

[半小时到秒级，京东零售定时任务优化怎么做的？\_业务 定时任务 100万-CSDN博客][_ 100_-CSDN]

原文内容虽然干货满满，但是表达的太跳跃了，读起来很难读懂。本文将基于京东零售线遇到的这一业务场景来聊一聊，在实际业务场景中性能优化的一整套打法。

**业务背景：**

京东零售的广告投放是分时段投放的，以半小时为一个时段，由于是分时段投放的，所以允许广告商控制哪些时段投放广告。

**实现：**

单条广告有以下几个核心字段：

id、startTime、endTime、记录哪些时段投放，哪些时段不投放的一个JSON、是否可被投放的状态字段。

投放的时候只投放状态为可投放的广告。这种设计需要一个定时任务来每半个小时根据JSON的内容来刷一下状态，将各广告商允许在当前时段投放的广告的状态刷为可被投放。

京东就是在这里遇见了问题，表里面有8400万条数据，一次定时任务要半小时才能跑完，刚刚跑完上一次就该跑下一次了，肯定是不行的。接下来我们就按一套思路来解决问题

## 2.判断任务类型 ##

遇见一个性能问题，首先是要判断它是IO密集型任务还是CPU密集型任务。如果是IO密集型任务就要从IO优化上来思考解决方法，如果是CPU密集型任务就要从计算层面来进行优化。所谓的IO优化其实就是减少IO次数，优化IO时的数据大小等。所谓的计算层面优化就是优化算法等。

这种对数据库进行读写的定时任务很明显是IO密集型任务，所以要往IO优化的方向考虑。首先考虑是不是能减少IO次数，8400万条数据是不是都是要用到的？京东的开发人员在这一步发现其实不是所有数据都要用到，广告是分渠道的，有一个type字段用来区分这条广告投放到哪些渠道，是APP，微信小程序，PC端等等。需要进行分时段投放的其实只有其中一个渠道。加上type条件后，数据量瞬间下去四分之三。r然后给所有条件字段建一个联合索引，就搞定了。从减少IO次数，以及利用索引这种空间换时间的方法双管齐下。据京东的开发人员的说法，这一步之后这个定时任务的耗时已经从半小时降到了几分钟，已经可以用了。

## 3.CPU飙高的原因 ##

本来以为上面的IO层面的优化后已经万事大吉了，但是用起来后发现定时任务执行期间，CPU的占用率会飙高，定时任务把CPU资源吃了，对请求的处理任务会受到影响，吞吐量会下跌。这本来是个IO密集型任务，不可能引起CPU飙高的，所以一定是哪里还有问题没被抓出来。这时候就需要监控一下程序了。用JDK自带的JDK监控工具jvisualVM来看看程序内部发生了些什么。JDK调试工具，作者有一篇专门的文章介绍过，可移步：

[详解JAVA程序调优-CSDN博客][JAVA_-CSDN]

通过监控发现JVM在频繁GC。GC时确实会引起CPU飙高，原因如下：

1. 标记和清除过程：垃圾回收需要进行对象的标记和清除工作。标记阶段需要遍历所有对象，确定哪些对象是不可达的（即不再被程序引用），这个过程需要占用一定的CPU时间。清除阶段则需要释放这些不可达对象占用的内存空间，这同样需要CPU的参与。  
2. 暂停其他线程：在进行垃圾回收时，为了保证内存安全，需要“Stop The World”，暂停其他线程的执行。所有的CPU资源都会被用来进行垃圾回收工作，从而导致CPU使用率升高。  
3. 内存碎片整理：在垃圾回收过程中，可能需要对内存碎片进行整理，以提高内存的使用效率。这个过程同样需要CPU的参与。

GC本来就会引起CPU飙高，持续GC，当然就会让CPU持续飙高。持续GC很可能是new了大量对象，导致堆空间频繁到阈值从而引起GC。果然，京东的开发人员通过观察发现定时任务中有大量hu调试日志，logger在打印日志的时候是会new一个日志对象的，随便点开一个logger的info之类的方法进入底层可以看到：

private void buildLoggingEventAndAppend(String localFQCN, Marker marker, Level level, String msg, Object[] params, Throwable t) {
        LoggingEvent le = new LoggingEvent(localFQCN, this, level, msg, t, params);
        le.setMarker(marker);
        this.callAppenders(le);
    }

大量打印日志当然就会new出大量对象，触发GC。下面我们模拟一个过程，new大量日志对象，并结合JvisualVM来定位问题。

测试代码：

import lombok.extern.slf4j.Slf4j;
    
    import java.util.ArrayList;
    import java.util.List;
    
    public class TestClass {
            // 这个静态列表将导致内存持续增长，可能引起频繁的GC
            private static List<LoggingEvent> eventList = new ArrayList<>();
    
            public static void main(String[] args) {
                while (true) {
                    buildLoggingEventAndAppend("com.example.Logger", null, Level.INFO, "A log message", null, null);
                }
            }
    
            private static void buildLoggingEventAndAppend(String localFQCN, Marker marker, Level level, String msg, Object[] params, Throwable t) {
                LoggingEvent le = new LoggingEvent(localFQCN, "LoggerName", level, msg, t, params);
                le.setMarker(marker);
    
                // 将LoggingEvent对象添加到静态列表中，造成内存泄漏
                eventList.add(le);
    
                // 假设的调用方法，实际应用中应替换为正确的日志处理逻辑
                callAppenders(le);
            }
    
            private static void callAppenders(LoggingEvent le) {
                // 这里简化处理，实际应包含向各个Appender发送事件的逻辑
                System.out.println("Logging: " + le.getMessage());
            }
    
            // 为了示例简单，我们模拟一个LoggingEvent类
            static class LoggingEvent {
                private String localFQCN;
                private String loggerName;
                private Level level;
                private String message;
                private Throwable throwable;
                private Object[] parameters;
                private Marker marker;
    
                public LoggingEvent(String localFQCN, String loggerName, Level level, String message, Throwable throwable, Object[] parameters) {
                    this.localFQCN = localFQCN;
                    this.loggerName = loggerName;
                    this.level = level;
                    this.message = message;
                    this.throwable = throwable;
                    this.parameters = parameters;
                }
    
                public void setMarker(Marker marker) {
                    this.marker = marker;
                }
    
                public String getMessage() {
                    return message;
                }
            }
    
            // 简化的Level和Marker类，仅用于示例
            enum Level {DEBUG, INFO, WARN, ERROR}
            static class Marker {}
    }

JvusialVM监控：

![6fd0bf1a5b1840288799cb6f4cde8ab6.png][]

监控中已经显示频繁GC了，堆内存的占用也是持续飙高，这时候抓一个堆的快照观察一下：

![203a24ba24d34dfdb60a325cb0565108.png][]

堆快照显示堆内有大量日志对象：

![7e638e21fd574ca383ea294a19f633eb.png][]

既然找到原因了，把多余的日志打印去掉就行了，自然就解决了问题

[773e60d9d07b4cb08bfa2919d1e1808d.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/05/06/d34137d74c8541ef978876c18b10ebbd.png
[_ 100_-CSDN]: https://blog.csdn.net/zheli1969917/article/details/136315237
[JAVA_-CSDN]: https://blog.csdn.net/Joker_ZJN/article/details/137201622?spm=1001.2014.3001.5501
[6fd0bf1a5b1840288799cb6f4cde8ab6.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/05/06/2218836d749049029030dda602f2ca1f.png
[203a24ba24d34dfdb60a325cb0565108.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/05/06/2f21fac0b2cc4a7c82505629605e824c.png
[7e638e21fd574ca383ea294a19f633eb.png]: https://image.dandelioncloud.cn/pgy_files/images/2024/05/06/b479229f7a4c45fbb0f282c2cb063539.png