【生产问题记录】一次 MQ 堆积的解决 (并发地从数据库中查询出大量数据导致数据库繁忙最终宕机)

这次事故实际的借鉴意义不大, 只是整个解决过程比较有趣, 所以记录一下。

1 背景

为了应对旺季的到来, 加上一些重要的接口的性能未知, 所以决定对这些接口进行压测并优化。

但是生产和测试环境的机器性能等差距很大, 为了准确性, 所以决定在生产环境进行压测。
先通过特定的账号进行压测, 然后删除这批账号产生的数据, 通过这种方式得到最准确的结果。

2 结论

压测的接口中有一个的功能, 高度概括如下:

1. 一次 Http 请求, 会产生 n 条数据库记录, 发送出 n 条 MQ 消息
2. 每条 MQ 消息会从数据库中查询出所有的记录, 然后处理这些记录

对这个接口进行压测时, 随着请求量的增加

1. 数据库记录越来越多
2. MQ 消费时, 查询数据库时越来越慢, 消费能力随之下降, 最终导致 MQ 堆积

发现堆积时, 在不了解具体逻辑时, 本着先解决问题再定位原因的原则, 我们选择了不断提高 MQ 消费能力, 最终导致

1. 数据库的查询压力越来越大, 先是触发了主从切换, 然后没多久整个库还是挂了
2. 应用这边有的卡在等待数据库响应全部数据, 有的是查询到了大量数据, 进入了 GC

3 过程

3.1 反馈

20:00, 测试开始压测。
20:30, 测试说明压测结束。
20:35, 测试反馈生产出现 MQ 堆积。

3.2 解决

3.2.1 启动新的实例, 先解决堆积

这种 MQ 堆积的情况, 个人习惯都会先确定一下对应的消费线程的状态, 确定是消费慢, 还是消费阻塞等原因。

进入到某个生产实例, 执行

## 获取到当前 Java 程序的进程号
jps -l 

## 查看 MQ 消费线程堆栈的情况, ConsumeMessageThread 是我们定义的 MQ 消费线程的名称前缀
jstack 74 | grep "ConsumeMessageThread" -C 50

情况如下:

"ConsumeMessageThread_20" #36030 prio=5 os_prio=@ tid=0x00007f1648035000 nid=®x4b59b waiting on condition (0x00007f1c0e9f0000]
    java. lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park (Native Method)
    - parking to wait for
    <0x00000000c3a23938> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$Condition0bject)
    at java.til. concurrent. locks. LockSupport.park(LockSupport.java:175)
    at java.til. concurrent. locks.AbstractQueuedSynchronizer$Condition0bject.await (AbstractQueuedSynchronizer. java: 2039)
    at java.til. concurrent.LinkedBlockingQueue.take (LinkedBlockingQueue. java:442)
    at java.til. concurrent. ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
    at java.til. concurrent. ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java. lang.Thread.run (Thread.java: 748)

所有的消费线程都是进入 WAITING 状态, 失去了消费能力, 连续抽查了几台生产实例, 都是相同的情况。

这种全局的等待，初步怀疑是全局锁导致的, 比如数据库等 (实际上, 这时应该是在 FullGC, 全部线程都阻塞了)。
本着先解决问题，再定位原因。所以先预发起了另一个版本实例, 然后切换流量过去。

同样通过 jstack 查看, 消费线程都是 Runnable 状态, 默认是解决了, 等消息消费完就行了, 回到旧版本, 定位原因。

3.2.2 加大生产实例, 提高消费能力

20:50, 运维群各种反馈 MQ 堆积。
通过监控平台查看, 发现 MQ 堆积加重 (应该是正常业务的消息 + 重试的消息)

通过 jstack 查看线程有的在 Runable, 有的 WAITING, 而不是一开始的 WAITING。
所以先将应用是实例增加, 从 10 个增加到了 16 个, 提高一些消费能力, 看看能否降下来。

3.2.3 增加堆内存, 防止应用 GC overhead limit exceeded

通过观察监控平台, 堆积的情况没有好转。
这时告警平台不断的提示应用有异常, 进入到实例的日志, 发现

[xxxx-xx-xx 21:05:53.978][ConsumeMessageThread_19][ERROR][com.xxx.qqq.mq.service.TodoSubscriber:49][ConsumeMessageThread_19raceId] TodoSubscriber:onMessage:org.springframework.data.redis.serializer.SerializationException: Cannot serialize; nested exception is org.springframework.core.serializer.support.SerializationFailedException: Failed to serialize object using DefaultSerializer; nested exception is java.lang.OutOfMemoryError: GC overhead limit exceeded
	at org.springframework.data.redis.serializer.JdkSerializationRedisSerializer.serialize(JdkSerializationRedisSerializer.java:93)
	at org.springframework.data.redis.core.AbstractOperations.rawValue(AbstractOperations.java:117)
	at org.springframework.data.redis.core.DefaultValueOperations.set(DefaultValueOperations.java:168)
	at com.xxx.qqq.mq.service.impl.ProtoCacheServiceImpl.addTodoIds(ProtoCacheServiceImpl.kt:154)
	...
Caused by: org.springframework.core.serializer.support.SerializationFailedException: Failed to serialize object using DefaultSerializer; nested exception is java.lang.OutOfMemoryError: GC overhead limit exceeded
	at org.springframework.core.serializer.support.SerializingConverter.convert(SerializingConverter.java:68)
	at org.springframework.core.serializer.support.SerializingConverter.convert(SerializingConverter.java:35)
	at org.springframework.data.redis.serializer.JdkSerializationRedisSerializer.serialize(JdkSerializationRedisSerializer.java:91)
	... 23 more
Caused by: java.lang.OutOfMemoryError: GC overhead limit exceeded	

出现该问题的原因：当 GC 为释放很小空间占用大量时间时会抛出此异常 (Sun 官方对此的定义，超过 98% 的时间用来做 GC 并且回收了不到 2% 的堆内存时会抛出此异常)。
一般是因为堆太小，导致异常的原因：没有足够的内存。

查看堆内存设置为 2G (-Xmx2G, 小堆多实例的配置), 先尝试将堆内存设置为 4G (-Xmx4G), 解决上面的异常, 让应用能够继续消费。

3.2.4 消费能力提高, 数据库压力增大

通过切版本 + 增加实例 + 增加堆内存, 一步步加大了消费能力。

然而没多久, 运维群反馈主库挂了, 从库切换为主库了。
通过运维反馈, 虽然切换了, 但是整个库的查询压力还是很大, 一直在 100%。

同时, 数据库中大量的 SQL 语句处于 SendingData 状态 (这个状态一般是结果集太大, 数据库服务端一直在往客户端推送数据中)。

果然没过多久, 从库也挂了。

3.2.5 减少实例, 删除压测数据

到了这一步, 继续加大消费能力已经没有意义了。消息可以先堆积, 但是数据库影响着整个应用。

所以在重启数据库后, 立即将实例减少到 10 个。

同时从测试获取到涉及压测的用户 id, 查询情况, 一个用户就产生了近 4 万的数据。

因为是测试数据, 直接将所有压测的用户的数据清除。

MQ 消费一波, 就清除一波, 整个堆积的情况也随着下来。

4 回顾

在 MQ 堆积时, 我们的解决方案: 逐渐的增大消费能力。
最终没有解决堆积, 而是导致了数据库的宕机, 应用本身也进入了 GC。