一次线上OOM与RocketMQ消费者源码分析1、背景介绍

1、背景介绍

这是一个临时文件的清洗服务,主要使用消费者生产者模型

清洗方式为分段清洗,因为清洗数据量过大,所以需要对数据进行分段以方便容错处理。

清洗服务模型如图:

image.png
每个消费者实例中一个消费者进程执行一段的清洗任务需要的时间大约为15分钟

生产者生产消息的速度远大于消费速度。

2、问题出现

清洗程序在凌晨启动,但是启动没几分钟后便收到疯狂告警:
image.png

看日志信息来说,就是疯狂GC但是回收不到垃圾,堆内存不够了。

那接下来就看看JVM的监控情况:

image.png

image.png

确实堆内存不够用了,那为什么不够用呢?

3、问题定位与解决

1)堆内存dump

在设置了 -XX:HeapDumpPath=/app/logs -XX:+HeapDumpOnOutOfMemoryError 后,JVM会在发生OOM的时候将当时的内存状况dump下来。

那接下来我们就分析一波内存情况

使用工具:jvisualvm

2)出现问题的线程

image.png
image.png
看样子就是在拷贝byte数组时候出现了内存不够用。

那接下来看看堆中是哪些实例占用了过多的内存

3)堆分析

先按照大小排序:

image.png
这个byte数组大概占用了93%的内存,那问题差不多就出在这儿了。

点进去看看这个实例的引用是什么:

image.png
按照从大到小排序,看到这个MessageClientExt就基本上可以猜到,是不是消息体过多导致的?

下面我们去源码分析一波,这个消息体到底是如何存在与消失的。

4)RocketMQ消费者源码分析(rocketmq-client:4.3.2)

在这之前,我们先看看RocketMQ的一些关键模型图:

Topic与Queue的关系:

每个Topic在不同的Broker内可以有不同数量的Queue,这全部的Queue都需要被消费者连接。

生产者投递消息会根据策略选择Queue进行投递,具体什么策略大家可以自行Google一下,这里不过多介绍。

image.png
目前我们线上设置的是10个broker,每个broker有16个queue。

Queue与消费者实例的关系:

这里为了简单起见,将所有的Broker合并为一个。

根据RebalanceService的策略,会把Broker的Queue与消费者实例中本地的ProcessQueue一一对应。

image.png

消费逻辑

这里重点关注消息何时被拉到本地,忽略offset怎么更新、顺序消费、消费失败等情况。

image.png

消息体流转源码分析

1、消息拉取到后存放在哪儿?

org.apache.rocketmq.client.impl.consumer.DefaultMQPushConsumerImpl#pullMessage

// 首先进行一些限制性的校验,重点关注defaultMQPushConsumer.pullThresholdForQueue和defaultMQPushConsumer.pullThresholdSizeForQueue
// 获取本地消息队列中当前存在的消息数量
long cachedMessageCount = processQueue.getMsgCount().get();
// 获取本地消息队列消息体总大小(单位:MB)
long cachedMessageSizeInMiB = processQueue.getMsgSize().get() / (1024 * 1024);

// 判断消息数量是否超过限制(默认为1000),超过则本次不请求拉取消息,提交延迟任务请求
if (cachedMessageCount > this.defaultMQPushConsumer.getPullThresholdForQueue()) {
    this.executePullRequestLater(pullRequest, PULL_TIME_DELAY_MILLS_WHEN_FLOW_CONTROL);
    if ((queueFlowControlTimes++ % 1000) == 0) {
        log.warn(
            "the cached message count exceeds the threshold {}, so do flow control, minOffset={}, maxOffset={}, count={}, size={} MiB, pullRequest={}, flowControlTimes={}",
            this.defaultMQPushConsumer.getPullThresholdForQueue(), processQueue.getMsgTreeMap().firstKey(), processQueue.getMsgTreeMap().lastKey(), cachedMessageCount, cachedMessageSizeInMiB, pullRequest, queueFlowControlTimes);
    }
    return;
}
// 判断消息大小是否超过限制(默认为100M),超过则本次不请求拉取消息,提交延迟任务请求
if (cachedMessageSizeInMiB > this.defaultMQPushConsumer.getPullThresholdSizeForQueue()) {
    ......
    return;
}
......
// PullCallback中的onSuccess()方法,重点关注一下这段拉取消息成功后执行的动作:
// 提交拉取到的消息到本地消息处理队列
boolean dispatchToConsume = processQueue.putMessage(pullResult.getMsgFoundList());
// 提交消费请求
DefaultMQPushConsumerImpl.this.consumeMessageService.submitConsumeRequest(
    pullResult.getMsgFoundList(),
    processQueue,
    pullRequest.getMessageQueue(),
    dispatchToConsume);
// 提交下次拉取消息请求
if (DefaultMQPushConsumerImpl.this.defaultMQPushConsumer.getPullInterval() > 0) {
    DefaultMQPushConsumerImpl.this.executePullRequestLater(pullRequest,
        DefaultMQPushConsumerImpl.this.defaultMQPushConsumer.getPullInterval());
} else {
    DefaultMQPushConsumerImpl.this.executePullRequestImmediately(pullRequest);
}
复制代码

在消息拉取到之后,就调用了processQueue.putMessage()方法,接下来我们来看看这个方法:

// 添加消息到processQueue中的msgTreeMap
public boolean putMessage(final List<MessageExt> msgs) {
    boolean dispatchToConsume = false;
    try {
        this.lockTreeMap.writeLock().lockInterruptibly();
        try {
            int validMsgCnt = 0;
            // 循环添加消息
            for (MessageExt msg : msgs) {
                MessageExt old = msgTreeMap.put(msg.getQueueOffset(), msg);
                if (null == old) {
                    validMsgCnt++;
                    this.queueOffsetMax = msg.getQueueOffset();
                    // 更新消息总大小的计数
                    msgSize.addAndGet(msg.getBody().length);
                }
            }
            // 原子类,计数新增了多少消息体,用于之前的限制判断
            msgCount.addAndGet(validMsgCnt);

            ......
        } finally {
            this.lockTreeMap.writeLock().unlock();
        }
    } catch (InterruptedException e) {
        log.error("putMessage exception", e);
    }

    return dispatchToConsume;
}
复制代码

划重点:消息体被拉取到了之后,放在了processQueue方法中的msgTreeMap里面

2、然后怎么消费和删除呢?

回到PullCallback中的onSuccess()方法,有这么一句:

DefaultMQPushConsumerImpl.this.consumeMessageService.submitConsumeRequest

这就是提交给线程池一个任务:执行具体的消息消费逻辑,这里略微过一下这个线程池

ConsumeMessageConcurrentlyService这个类里面有一个用于消费消息的线程池consumeExecutor

看这个类的构造方法:

public ConsumeMessageConcurrentlyService(DefaultMQPushConsumerImpl defaultMQPushConsumerImpl,
    MessageListenerConcurrently messageListener) {
    this.defaultMQPushConsumerImpl = defaultMQPushConsumerImpl;
    this.messageListener = messageListener;

    this.defaultMQPushConsumer = this.defaultMQPushConsumerImpl.getDefaultMQPushConsumer();
    this.consumerGroup = this.defaultMQPushConsumer.getConsumerGroup();
    this.consumeRequestQueue = new LinkedBlockingQueue<Runnable>();

    // 在这里初始化了这个线程池,核心线程和最大线程就是我们设置的consumeThreadMin和consumeThreadMax
    this.consumeExecutor = new ThreadPoolExecutor(
        this.defaultMQPushConsumer.getConsumeThreadMin(),
        this.defaultMQPushConsumer.getConsumeThreadMax(),
        1000 * 60,
        TimeUnit.MILLISECONDS,
        this.consumeRequestQueue,
        new ThreadFactoryImpl("ConsumeMessageThread_"));

    this.scheduledExecutorService = Executors.newSingleThreadScheduledExecutor(new ThreadFactoryImpl("ConsumeMessageScheduledThread_"));
    this.cleanExpireMsgExecutors = Executors.newSingleThreadScheduledExecutor(new ThreadFactoryImpl("CleanExpireMsgScheduledThread_"));
}
复制代码

接下来看看这个提交任务的方法:

public void submitConsumeRequest(
    final List<MessageExt> msgs,
    final ProcessQueue processQueue,
    final MessageQueue messageQueue,
    final boolean dispatchToConsume) {
    final int consumeBatchSize = this.defaultMQPushConsumer.getConsumeMessageBatchMaxSize();
    if (msgs.size() <= consumeBatchSize) { // 提交消息小于批量消息数,直接提交消费请求
        ConsumeRequest consumeRequest = new ConsumeRequest(msgs, processQueue, messageQueue);
        try {
            this.consumeExecutor.submit(consumeRequest);
        } catch (RejectedExecutionException e) {
            // 线程池出现拒绝异常则等会再提交
            this.submitConsumeRequestLater(consumeRequest);
        }
    } else { // 提交消息大于批量消息数,拆成多个消费请求
        for (int total = 0; total < msgs.size(); ) {
            List<MessageExt> msgThis = new ArrayList<MessageExt>(consumeBatchSize);
            for (int i = 0; i < consumeBatchSize; i++, total++) {
                if (total < msgs.size()) {
                    msgThis.add(msgs.get(total));
                } else {
                    break;
                }
            }

            ConsumeRequest consumeRequest = new ConsumeRequest(msgThis, processQueue, messageQueue);
            try {
                this.consumeExecutor.submit(consumeRequest);
            } catch (RejectedExecutionException e) {
                for (; total < msgs.size(); total++) {
                    msgThis.add(msgs.get(total));
                }

                this.submitConsumeRequestLater(consumeRequest);
            }
        }
    }
}
复制代码

既然都看到这里了,再看一眼ConsumeRequestrun方法不过分吧

我们就重点看看,我们自己定义的消费逻辑是怎么被调用的?消息消费完成后是怎么处理的?

public void run() {
    if (this.processQueue.isDropped()) {
        log.info("the message queue not be able to consume, because it's dropped. group={} {}", ConsumeMessageConcurrentlyService.this.consumerGroup, this.messageQueue);
        return;
    }
    // 在这里获取到我们自定义的消费逻辑
    MessageListenerConcurrently listener = ConsumeMessageConcurrentlyService.this.messageListener;
    ConsumeConcurrentlyContext context = new ConsumeConcurrentlyContext(messageQueue);
    ConsumeConcurrentlyStatus status = null;

    ......

    long beginTimestamp = System.currentTimeMillis();
    boolean hasException = false;
    ConsumeReturnType returnType = ConsumeReturnType.SUCCESS;
    try {
        ConsumeMessageConcurrentlyService.this.resetRetryTopic(msgs);
        if (msgs != null && !msgs.isEmpty()) {
            for (MessageExt msg : msgs) {
                MessageAccessor.setConsumeStartTimeStamp(msg, String.valueOf(System.currentTimeMillis()));
            }
        }
        // 在这里执行我们的逻辑,拿到一个执行后的状态(成功 || 失败)
        status = listener.consumeMessage(Collections.unmodifiableList(msgs), context);
    } catch (Throwable e) {
        log.warn("consumeMessage exception: {} Group: {} Msgs: {} MQ: {}",
            RemotingHelper.exceptionSimpleDesc(e),
            ConsumeMessageConcurrentlyService.this.consumerGroup,
            msgs,
            messageQueue);
        hasException = true;
    }
    ......
    // 处理消费结果
    if (!processQueue.isDropped()) {
        // 调用processQueue.removeMessage()方法将消费完成的消息干掉
        ConsumeMessageConcurrentlyService.this.processConsumeResult(status, context, this);
    } else {
        log.warn("processQueue is dropped without process consume result. messageQueue={}, msgs={}", messageQueue, msgs);
    }
}
复制代码

这段代码:

ConsumeMessageConcurrentlyService.this.processConsumeResult(status, context, this);

就将消息体干掉啦。

消费者源码总结

在来到源码之前,我们希望知道一个消息体是怎么在消费者端流转的,现在通过流程图和源码我们大致上就明白了。

对于我们设置的参数:pullThresholdForQueuepullThresholdSizeForQueueconsumeThreadMinconsumeThreadMax也知道了究竟是如何起作用的。

6)OOM问题解决

通过上面一顿操作,我们知道了具体的消息体是存在processQueue中的msgTreeMap里面,存储的内容是MessageExt,它有一个子类,也就是MessageClientExt

首先我们先怀疑一下是不是内存泄露?分析一波,其实应该不是,内存泄露的话,应该是消息体疯狂被拉取下来,但是消费完成后却没有被干掉,这个时候可能会内存泄露,但是RocketMQ我们在线上其他应用已经运行很久很久,如果是内存泄露,那线上服务应该是个个都OOM才对,这应该算MQ重大BUG了。

回到我们堆分析中看到的数据,略微查看和计算一下:

image.png
内存中有55个ProcessQueue实例,也就是说,这个消费者实例连接了55个MessageQueue。

我们设置的消费者实例相关的参数是这样的:
image.png

粗略计算一下:55(ProcessQueue) * 100(队列容量:pullThresholdForQueue) * 428311(消息体大小,单位:字节) = 2246MB

也就是说,如果按照我们现在的设置,所有的消息体被拉下来,需要2246MB内存。

再看一眼目前内存中MessageClientExt的个数:

image.png

显然,这就很容易造成内存不够。

那问题就很好解决了呀,按照计算调整一下参数即可。

附:定位参数设置不成功的问题

在第一次遇到OOM问题的时候,就其实已经怀疑是消息体过大过多,也对pullThresholdForQueue这个参数做了设置,但是OOM问题依然存在,当时就特别困惑,后来观察堆内存中的pullThresholdForQueue值为100,就很奇怪,明明我们设置的是40。

于是就跟踪了一下这个值的变动过程:

image.png
在属性前面打上断点,Debug启动:

第一次进入这个地方,置为0,没毛病,初始化嘛

image.png

第二次进入,置为40,也没问题

image.png

哦豁,又来一次,置为100,这就不能忍了

image.png

翻到是一个进入这儿的方法,果不其然:

image.png
有BUG嘛,公司封装的组件的一个小BUG,难顶。

问题总结

如果不去分析一波源码很难知道这个pullThresholdForQueue参数的意思是单个本地队列的容量,但是一个消费者实例中不可能只有一个本地队列。

这样的话,在生产者很快,消费者很慢,消息体很大的情况下,那就会比较容易OOM。

小问题以及猜想

再来看一波pullThresholdForQueue设置为10后,内存状态如何:

image.png

随便找一个ProcessQueue实例,观察到这个msgCount值其实不是严格的小于10,而是会大一点。

这是为什么呢?

有一个不太成熟猜想:

processQueue.putMessage()方法,拉取消息是一次拉取多个,而且增加这个值的时候其实是没有对是否已超过限制进行判断的,似乎也不能进行判断。
只有在准备拉消息体之前,进行了一次判断,如果超过则不拉。

所以就导致了msgCount这个值不完全精确。