PRECONDITION_FAILED - delivery acknowledgement on channel 1 timed out. 一次线上项目消息队列异常问题

背景:

公司的一个线上项目运行一段时间后, rabbitmq 消息队列就会出现消费异常, 无法正常消费消息, 每次重启之后, 就可以正常消费了

问题分析

consumer 报错信息

查看 rabbitmq consumer 的报错信息显示
PRECONDITION_FAILED - delivery acknowledgement on channel 1 timed out. Timeout value used: 1800000 ms. This timeout value can be configured, see consumers doc guide to learn moreover
根据这个报错信息, 百度搜索结果大多都是指向官方的 消息确认超时的间隔, 我不看就知道不是这个原因, 我们那项目我很清楚, 根本没有什么并发, 也没有耗时的后端逻辑, 所以不可能是因为消息积压导致的超时未 ack.

consumer 端优化

结合前几次出现这个问题的情况, 每次都是消息队列服务启动后消费者端正常消费消息, 运行一段时间才出现这个问题, 考虑是不是 consumer 运行一段时间后与rabbitmq服务器端断开了连接, 基于此, 在连接rabbitmq 的时候加上了 heartbeat 心跳检测, 并且在消费者端增加断开连接重连处理, 但是隔一段时间问题仍旧出现

rabbitmq heartbeat 心跳时间, 官方推荐设置为60秒, 每30秒向客户端发送一次心跳包, 如果服务器超过两次没有接收到客户端回应则断开tcp连接

业务端 报错分析

既然不是上面的原因, 只能继续排查, 经同事 大哥 提醒发现, 每次出现
PRECONDITION_FAILED - delivery acknowledgement on channel 1 timed out
这个问题, 后端业务的错误日志里都会出现
SQLSTATE[HY000]: General error: 2006 MySQL server has gone away
而且这个数据库的错误日志时间间隔是 30 min,跟 consumer 的ack响应超时时间间隔一致,
思考了一下, 问题应该就是跟后端 MySQL 连接丢失有关.

问题确定

consumer 消费端从rabbitmq的消息队列里取到消息后, 会连接 MySQL 数据库进行一些业务处理, 但是由于consumer 是持久运行的, 在consumer里建立MySQL 连接处理完业务逻辑后, 这个连接没有被关闭, 这样这个mysql connection会被后续的消息复用;
但是 MySQL 服务对于每个 connection 都有一个等待超时时间: wait_timeout

show variables like "wait_timeout"

默认是 28800秒,也就是如果 connection 建立之后没有使用 8小时后会被强制关闭, 此时有新的查询使用这个 connection 的话就会出现 SQLSTATE[HY000]: General error: 2006 MySQL server has gone away

问题解决

了解了问题原因, 就知道了解决办法了, 这里有三种解决办法:

• consumer 端业务处理完毕主动关闭 MySQL connection
• consumer 端业务刚处理前,设置此次的MySQL的等待超时时间

db.query("set session wait_timeout=35,964,000")

• consumer 端业务处理中 检查 MySQL的链接状态，使其重新链接