1、问题描述:
运维监控系统的时候发现RabbitMQ的某个queue下面有消息堆积的情况
进mq的管理界面看到队列的消费情况,消息Unacked的数量2000,Ready:652
2、问题定位
根据队列找到对应的服务和业务代码,根据消费端的日志到kibana查看消息的消费情况:
可以看到在9点20以前消息有正常消费和处理。
进代码定位发现消费者监听的地方设置了containerFactory
batchQueueRabbitListenerContainerFactory 容器工厂中设置了,但是消费处理的代码里面居然没有手动ack!!!!
factory.setAcknowledgeMode(AcknowledgeMode.MANUAL);
public SimpleRabbitListenerContainerFactory batchQueueRabbitListenerContainerFactory(
@Qualifier("primaryConnectionFactory") ConnectionFactory connectionFactory, MessageConverter messageConverter) {
SimpleRabbitListenerContainerFactory factory = new SimpleRabbitListenerContainerFactory();
factory.setConnectionFactory(connectionFactory);
//设置批量
factory.setBatchListener(true);
factory.setConsumerBatchEnabled(true);
factory.setBatchSize(100);
factory.setAcknowledgeMode(AcknowledgeMode.MANUAL);
factory.setMessageConverter(messageConverter);
return factory;
}
为了快速的解决线上消息堆积的问题, 将手动ack改为了自动ack。
上线后诡异的事情又发生了,虽然mq里面的消息很快都消费掉了,而且不再堆积,但是消息处理的buffer表的数据一直在增加,虽然偶尔有几条减少,但是远远比不上增加的速度,很快buffer表的数据快增长到几w了(mq的逻辑是这样的 写buffer表->发mq->消费mq->业务逻辑处理->删除mq)
于是马上去看消费端服务打印的日志:
因为每处理完一条mq消息,buffer表的数据就会删掉,但是观察日志,虽然在消费,但是一分钟才处理几条,有时候间隔几分钟才处理,buffer表数据却一直在堆积,刚开始我们习惯性的猜测肯定是因为消息堆积了所以业务端处理堆积的消息慢了,或者是业务逻辑处理耗时, 但是查看数据的锁等待等情况都没有, 事出反常必有妖,于是重新检查代码, 发现了问题所在。
容器工厂设置的是批量监听, 但是消费端接受通过绑定@RabbitHandler将消息对象反序列化自动处理了,用一个实体对象接收,猜测很有可能是丢消息了, 结合日志的打印情况,很有可能是一批消息过来, 但是只接收了一条进行了处理,但是又自动ack, 那么其他消息可能就丢失了。
根据测试和源码分析,最终确认了是这个原因导致的。
于是重写了代码,还是改为手动ack(当时改为自动ack只是为了快速解决消息积压问题,但是如果对于可靠消息来说,手动ack才比较稳)
@Component
public class OperateHotAccountConsume {
@Autowired
private HotAccountService hotAccountService;
@Autowired
private OperateAccountRemote operateAccountRemote;
@RabbitListener(bindings = @QueueBinding(
value = @Queue(value = "acc_hot_account_queue", durable = "true", autoDelete = "false"),
exchange = @Exchange(value = "acc_hot_account_exchange", type = ExchangeTypes.TOPIC),
key = "acc_hot_account_route_key"), containerFactory = "batchQueueRabbitListenerContainerFactory")
public void process(List<Message> messages, Channel channel) {
log.info("OperateHotAccountConsume_process receive messages size:{}", messages.size());
for (Message message : messages) {
try {
handMessage(message, channel);
} catch (IOException e) {
log.error("OperateHotAccountConsume_process channel communication exception", e);
}
}
}
private void handMessage(Message message, Channel channel) throws IOException {
long deliveryTag = message.getMessageProperties().getDeliveryTag();
String messageBody = new String(message.getBody());
log.info("OperateHotAccountConsume_process record message,messageBody:{},deliverTag:{}", messageBody, deliveryTag);
OperateAccountMsgReq operateAccountMsgReq = null;
try {
operateAccountMsgReq = JSON.parseObject(messageBody, OperateAccountMsgReq.class);
log.info("OperateHotAccountConsume_process record message,operateAccountMsgReq:{}", operateAccountMsgReq);
HotAccountOperateResultBO resultBO = hotAccountService.executeAsyncAccountOperate(operateAccountMsgReq);
if (resultBO.isSuccess()) {
channel.basicAck(deliveryTag, false);
return;
}
if (!Boolean.TRUE.equals(resultBO.getRetry())) {
log.warn("OperateHotAccountConsume_process result_fail_no_retry,operateAccountReq:{},result:{}", operateAccountMsgReq, resultBO);
channel.basicAck(deliveryTag, false);
return;
}
// 失败,重试
log.error("OperateHotAccountConsume_process result_fail_retry,operateAccountReq:{},result:{}", operateAccountMsgReq, resultBO);
operateAccountRemote.sendOperateAccountMsgDelay(operateAccountMsgReq);
channel.basicAck(deliveryTag, false);
} catch (Exception e) {
log.error("OperateHotAccountConsume_process exception, retry,SendOperateAccountMsgReq:{}", operateAccountMsgReq, e);
channel.basicNack(deliveryTag, false, true);
return;
}
}
}
重新上线后,问题解决, mq和buffer表也不再有消息积压。
3、问题复盘
最后分析原因,发现仅仅是因为在@RabbitListener里面加了一个containerFactory配置, 导致的一系列问题,之前没设置的时候,消息监听使用的是默认配置(单条消费,自动ack), 但是设置成了batchQueueRabbitListenerContainerFactory之后,改变了消息消费的模式,造成了一系列的影响,所以经验教训就是修改代码之前一定要仔细分析影响范围(尤其是配置类,影响大,不易发现),修改任何配置之前弄清楚它的作用和可能产生的影响。细心,再细心!!!源码的重要性。还有一点想吐槽一下spring的, 为啥批量的消息,用单个对象接收也不报错,这样误使用的情况下可能直接导致丢消息了。