1 前言
前几天我们又遇到了一个Netty
报从连接池获取连接超时异常从而导致整个服务不可用的异常,报的具体异常信息是Exception accurred when acquire channel from channel pool:TimeoutException
。当时自己看了这个异常信息,有种似曾相识的感觉,印象中自己第一次接触到该异常是不久前也遇到了Netty
报超时错误导致整个服务不可用的问题,最终只能重启服务器来解决。于是自己去翻看了之前的异常消息,发现报的错误果真同样是从连接池获取连接超时的异常!印象中前段时间Netty报这个错误时是刚好相关网络部门做过网络调整,当时我们就认为可能是由于网络原因导致Netty获取连接超时,但是至于为啥会因为网络原因导致获取Netty连接超时后从而导致服务不可用就还是一无所知,因此,这个“幽灵”Bug暂时对我们来说成了一团谜。
2 “幽灵”Bug得以复现给了我们解决这个Bug的希望
万幸的是,这次相关同事复现了这个Bug,然后对方说只要在并发量大一点且后台业务逻辑处理时间久的话这个Bug就会复现,且这个Bug是伴随前台线程请求后台超时(这个是请求超时异常,而非获取连接超时异常,注意区分)后报出来的。于是自己提高并发量且在后台模拟业务超时进行测试,果真“幽灵”Bug得以复现了,且这个Bug导致后面整个服务都不可用了,报错如下截图:
这个“幽灵”Bug的复现给我们带来了解决它的希望,那么是什么原因导致在并发量一上来且前台请求后台超时后就会导致从Netty连接池获取连接超时了呢?
注意: 这里有两个超时异常,请注意区分:一个是从连接池获取连接超时异常;令一个是从连接池成功获取连接后,前台请求后台,由于后台业务逻辑执行时间过长导致抛出的请求超时异常
我们无从而知,只能去翻看抛异常的代码,我们编写的Netty连接池实现大概如下:
// CustomChannelPool.java
public class CustomChannelPool {
private ChannelHealthChecker healthCheck = ChannelHealthChecker.ACTIVE;
acquireTimeoutAction = null;
acquireTimeoutMillis = -1;
maxConnect = 8;
maxPendingAcquires = Integer.MAX_VALUE
releaseHealthCheck=true
//...省略无关属性
static ChannelPool fixpool =
new FixedChannelPool(b, handler, healthCheck, acquireTimeoutAction,
acquireTimeoutMillis, maxConnect, maxPendingAcquires, releaseHealthCheck, lastRecentUsed); // 【0】
// 获取连接
public Channel acquire(int timeoutMillis) throws Exception {
try {
Future<Channel> fch = fixpool.acquire(); // 【1】
Channel ch = fch.get(timeoutMillis, TimeUnit.MILLISECONDS);// 【2】
return ch;
} catch (Exception e) {
logger.error("Exception accurred when acquire channel from channel pool.", e);//【3】
throw e; //【4】
}
}
// 释放连接
public void release(Channel channel) {
try {
if (channel != null) {
fixpool.release(channel);
}
} catch (Exception e) {
e.printStackTrace();
}
}
}
然后业务获取连接的代码大概如下:
// BusineseService.java
public class BusineseService {
public Response rpcCall() throw Exception{
// 获取连接
Channel channel = CustomChannelPool.fixpool.acquire(10000); // 【5】
try {
// ...省略相关业务逻辑
// 最终进行底层远程调用
channel.writeAndFlush(data);
// ...省略相关业务逻辑
} finally {
// 释放连接
// 若前台请求后台超时后,是有释放连接的
CustomChannelPool.fixpool.release(channel); // 【6】
}
}
}
根据报的异常信息可用判断是在进行远程调用前调用CustomChannelPool.acquire
方法的Channel ch = fch.get(timeoutMillis, TimeUnit.MILLISECONDS);
这句代码从Netty
连接池获取连接超时(即10秒后),然后抛出TimeoutException
,最后再在CustomChannelPool.acquire
方法的catch
代码块打印出Exception accurred when acquire channel from channel pool:TimeoutException
异常信息,然后再把该异常往外抛出去,即最后会在BusineseService
的标号【5】处的代码Channel channel = CustomChannelPool.fixpool.acquire(10000);
抛出了一个TimeoutException
异常,又因为标号【5】处的代码没有包含在try
块内,因此不会执行标号【6】处的finally
块释放连接的逻辑。
分析到这里,我们松了一口气,原来导致该“幽灵”Bug的原因就是因为获取连接的这决代码Channel channel = CustomChannelPool.fixpool.acquire(10000);
没有被try
块包围住,才导致没有执行finlly
块的释放连接逻辑!!!
Please calm down here!
即使我们将获取连接的这决代码Channel channel = CustomChannelPool.fixpool.acquire(10000);
用try
块包围住,最终在执行finally
块释放连接的逻辑时等待我们的将会是什么呢?显然,等待我们的是一个空指针异常!为啥呢?因为执行Channel channel = CustomChannelPool.fixpool.acquire(10000);
这句代码抛出TimeoutException
异常后,拿到的channel
将为null
,然后我们再用结果为null
的channel
去释放连接,自然会抛出一个NPE
.
之前燃起的一线希望又被NPE
扑灭了,出现幽灵Bug
的原因依然没找到!此时我们又失去了方向!
既然选择了远方,便只顾风雨兼程,嘿嘿,这里我们自我励志下,别灰心,努力了总能解决它,不就是一个小小的bug么。
于是我们又冷静分析了下出问题的两句问题代码上来:
Future<Channel> fch = fixpool.acquire(); // 【1】
Channel ch = fch.get(timeoutMillis, TimeUnit.MILLISECONDS);// 【2】
【1】处代码调用fixpool.acquire()
方法去获取一个连接然后马上返回一个Future<Channel>
对象fch
,紧接着我们再调用【2】处代码fch.get(timeoutMillis, TimeUnit.MILLISECONDS);
方法来等待连接池的可用连接返回,一直阻塞直至超时,超时后就抛出了TimeoutException
异常。
从这里初步分析可以看到Netty
获取连接是异步进行的,当获取到一个连接后再唤醒调用fch.get(timeoutMillis, TimeUnit.MILLISECONDS);
代码后正在阻塞等待的线程。
我们再回想下,复现该bug的前提条件是抛出该异常的前提是并发量大且会伴随着大量前台请求后台的线程请求超时后出现。这里请求后台超时的线程是已经成功从连接池获得连接的线程,且超时抛出请求超时异常后也有执行finally
块的释放(归还)连接回连接池的操作的!
那么是什么原因会导致抛出从连接池获取连接超时异常呢?于是我们不禁有以下猜测:
猜测1: 瞬间高并发的请求导致连接池资源耗尽,从而导致大量获取连接超时,这种情况是可能出现的,但是高并发过后,整个服务就不可用了(这里的服务不可用不是指应用宕掉,而是总是报获取连接超时)!按理说高并发过后应该归还连接到连接池了,因此肯定不会出现服务不可用的情况。因此这个猜测可以排除了,唯一的原因就是连接没能正常归还到连接池!!!
至于为啥连接没能正常归还到连接池,我们又有以下猜测:
猜测2: 请求后台超时的channel
连接不能正常归还到连接池,channel
连接请求后台超时后,这个连接不能正常放回连接池,导致channel
连接池可用连接耗尽,最终导致其他线程从连接池获取连接超时?如果是这样,那么为啥请求后台超时的连接不能正常放回连接池呢?
猜测3: 请求后台超时channel
连接能正常归还到连接池,此时又因为从连接池获取channel
连接是异步的,当获取连接超时后,我们关心的是获取连接的异步线程最终有无从连接池成功获取到一个连接呢?这里有两种可能:1)获取连接超时后不能从连接池获取到一个连接,即使前面实现的代码中获取连接超时的话没有释放连接也不影响,因为这种情况根本就没有获取到连接;1)获取连接超时后仍能成功获取到一个连接,但从前面实现代码的分析过程中可以知道,获取连接超时的话,这个获取到的连接是没有被释放的,如果是这种情况,那么就会导致连接池资源耗尽从而导致服务不可用了!
显然,我们要朝着猜测2和猜测3的方向去排查问题,至于哪种原因导致连接没能正常归还到连接池呢?我们依然百思不得其解!因为此时Netty连接池对于我们来说是一个黑盒,此时是时候去打开这个黑盒一探究竟了!
3 Netty连接池FixedChannelPool获取和释放连接源码分析
来到这里我们就要打开Netty
的channel
连接池源码看一下了,前面导致问题的代码无非就是连接池的acquire
和release
两个方法,相信我们能从连接池的这两个方法的源码中找到导致Exception accurred when acquire channel from channel pool:TimeoutException
异常即获取连接超时异常的原因。
3.1 连接池整体类结构的理解
这里用到的是Netty
的FixedChannelPool
连接池,同时FixedChannelPool
继承了SimpleChannelPool
,而SimpleChannelPool
又实现了ChannelPool
接口,如下图: