背景

某日晚上9点钟，收到大量告警通知与邮件，反应线上服务有大量延迟与异常。经过简单定位，发现是我负责的服务出现的异常。因此开始了紧张刺激的bug排查之旅...

BUG排查过程

初见端倪——临时方案快速解决

首先我看了下服务的CPU与内存，发现都出现了激增的情况。观察异常日志时，发现有很多数据库操作的异常，经过确定发现是消费某个MQ的异常。

同时同事也反馈MQ出现了大量堆积现象。经询问得知当天晚上有账号迁移任务，导致有数万条请求会被放入消息队列中。
既然核心的原因是它，因此快速的将该队列与交换机的绑定关系解除并重启服务，果然延迟与异常都没有了，问题得到了临时性的解决。然后也就安心的去睡觉了（实在太累了...不想继续查了...）

疑云重重——深入考察原因

第二天来到公司通过日志开始深入排查。通过慢查询日志发现了有一个更新SQL执行的时间平均长达40多秒。

仔细一看...果然,没加索引!好吧，非常尴尬，这个方法也确实是消费MQ时需要调用的方法，问题似乎找到了？等等似乎还是有哪里不太对。

因为没加索引的这张表是一张不算很重要的表，其他很多的写操作都不涉及该表，为啥这些请求都超时异常了呢？
虽然update会锁表，但是由于InnoDB的快照读以及MVCC机制，不应该查询也出现异常。
MQ的消费没有配置成多线程消费，慢更新的操作最多让消费的速度变慢，但是不应该影响到整个服务异常。

好吧...事情似乎并不简单...好像思路也都堵住了？我陷入了疑惑。

峰回路转——找出真相

在我疑惑时，突然想到项目是接入skywalking的，看看skywalking说不定能找到答案？

可以看到由于没加索引，Sql的执行时长高达20s。不过这不是关键，令我震惊的是上边的 SpringAsync。这个慢查询操作竟然是异步的？！跟着代码我终于找到了罪魁祸首...

这个操作使用了 @Async 注解，如果不指定线程池，@Async会使用默认的线程池 SimpleAsyncTaskExecutor ,于是我去翻了下源码：

	public void execute(Runnable task, long startTimeout) {
		Assert.notNull(task, "Runnable must not be null");
·               // 如果进入节流状态
		if (isThrottleActive() && startTimeout > TIMEOUT_IMMEDIATE) {
			this.concurrencyThrottle.beforeAccess();
			doExecute(new ConcurrencyThrottlingRunnable(task));
		}
               // 默认执行任务
		else {
			doExecute(task);
		}
	}

	protected void doExecute(Runnable task) {
                // 每个任务都会创建一个线程
		Thread thread = (this.threadFactory != null ? this.threadFactory.newThread(task) : createThread(task));
		thread.start();
	}

可以看到SimpleAsyncTaskExecutor会为每个任务都创建一个线程，当时MQ堆积了上万的请求，每次消费都会开启一个线程去执行慢查询。因此也就导致了线程数激增，内存消耗变大。

虽然如此，但是服务也并没有OOM呀(估计再运行一段时间就会了)。那为什么整个服务都会崩溃呢？其实也很简单...服务的数据库连接池默认最大活跃线程池数为100，由于源源不断的有线程再执行慢更新的操作，因此正常的Sql全部受到了影响。日志也的确验证了我的这个猜想：

根据日志我们可以看到由于长时间未响应结果(慢查的时间太长了)，数据库连接池直接断开了连接。