@SentinelResource(blockHandler = "blockHandlerForGetUser")
public User getUserById(String id) {
throw new RuntimeException("getUserById command failed");
}
// blockHandler 函数,原方法调用被限流/降级/系统保护的时候调用
public User blockHandlerForGetUser(String id, BlockException ex) {
return new User("admin");
}
public class Manager implements ReimbursementHandler {
private ReimbursementHandler nextHandler;
@Override
public void handleRequest(ReimbursementRequest request) {
if (request.getAmount() <= 1000) {
System.out.println("经理审批通过,报销金额:" + request.getAmount());
} else {
if (nextHandler != null) {
nextHandler.handleRequest(request);
} else {
System.out.println("无法处理该报销申请");
}
}
}
@Override
public void setNextHandler(ReimbursementHandler nextHandler) {
this.nextHandler = nextHandler;
}
}
public class FinanceDepartment implements ReimbursementHandler {
private ReimbursementHandler nextHandler;
@Override
public void handleRequest(ReimbursementRequest request) {
if (request.getAmount() <= 5000) {
System.out.println("财务部门审批通过,报销金额:" + request.getAmount());
} else {
if (nextHandler != null) {
nextHandler.handleRequest(request);
} else {
System.out.println("无法处理该报销申请");
}
}
}
@Override
public void setNextHandler(ReimbursementHandler nextHandler) {
this.nextHandler = nextHandler;
}
}
public class CEO implements ReimbursementHandler {
@Override
public void handleRequest(ReimbursementRequest request) {
System.out.println("CEO审批通过,报销金额:" + request.getAmount());
}
@Override
public void setNextHandler(ReimbursementHandler nextHandler) {
// CEO是责任链中的最后一个处理对象,不需要设置下一个处理对象
}
}
最后,我们可以创建一个责任链并测试它:
public class Main {
public static void main(String[] args) {
ReimbursementHandler manager = new Manager();
ReimbursementHandler finance = new FinanceDepartment();
ReimbursementHandler ceo = new CEO();
// 构建责任链
manager.setNextHandler(finance);
finance.setNextHandler(ceo);
// 创建报销请求
ReimbursementRequest request1 = new ReimbursementRequest(800);
ReimbursementRequest request2 = new ReimbursementRequest(3500);
ReimbursementRequest request3 = new ReimbursementRequest(10000);
// 发送请求
manager.handleRequest(request1);
manager.handleRequest(request2);
manager.handleRequest(request3);
}
}
Unable to acquire JDBC Connection [n/a] java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms. at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:669) ~[HikariCP-2.7.9.jar!/:?] at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:183) ~[HikariCP-2.7.9.jar!/:?] ...
private SQLException createTimeoutException(long startTime)
{
logPoolState("Timeout failure ");
metricsTracker.recordConnectionTimeout();
String sqlState = null;
//获取最后一次连接失败的异常
final Throwable originalException = getLastConnectionFailure();
if (originalException instanceof SQLException) {
sqlState = ((SQLException) originalException).getSQLState();
}
//抛出异常
final SQLException connectionException = new SQLTransientConnectionException(poolName + " - Connection is not available, request timed out after " + elapsedMillis(startTime) + "ms.", sqlState, originalException);
if (originalException instanceof SQLException) {
connectionException.setNextException((SQLException) originalException);
}
return connectionException;
}
这里的异常消息和我们在业务服务中看到的异常日志基本上是吻合的,即除了超时产生的 “Connection is not available, request timed out after xxxms” 消息之外,日志中还伴随输出了校验失败的信息:
Caused by: java.sql.SQLException: Connection.setNetworkTimeout cannot be called on a closed connection at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getSqlException(ExceptionMapper.java:211) ~[mariadb-java-client-2.2.6.jar!/:?] at org.mariadb.jdbc.MariaDbConnection.setNetworkTimeout(MariaDbConnection.java:1632) ~[mariadb-java-client-2.2.6.jar!/:?] at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:541) ~[HikariCP-2.7.9.jar!/:?] at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:162) ~[HikariCP-2.7.9.jar!/:?] at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:172) ~[HikariCP-2.7.9.jar!/:?] at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:148) ~[HikariCP-2.7.9.jar!/:?] at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128) ~[HikariCP-2.7.9.jar!/:?]
到这里,我们已经将应用获得连接的代码大致梳理了一遍,整个过程如下图所示:
从执行逻辑上看,连接池的处理并没有问题,相反其在许多细节上都考虑到位了。在对非存活连接执行 close 时,同样调用了 removeFromBag 动作将其从连接池中移除,因此也不应该存在僵尸连接对象的问题。
"HikariPool-1 connection adder" #121 daemon prio=5 os_prio=0 tid=0x00007f1300021800 nid=0xad runnable [0x00007f12d82e5000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:171) at java.net.SocketInputStream.read(SocketInputStream.java:141) at java.io.FilterInputStream.read(FilterInputStream.java:133) at org.mariadb.jdbc.internal.io.input.ReadAheadBufferedStream.fillBuffer(ReadAheadBufferedStream.java:129) at org.mariadb.jdbc.internal.io.input.ReadAheadBufferedStream.read(ReadAheadBufferedStream.java:102) - locked <0x00000000d7f5b480> (a org.mariadb.jdbc.internal.io.input.ReadAheadBufferedStream) at org.mariadb.jdbc.internal.io.input.StandardPacketInputStream.getPacketArray(StandardPacketInputStream.java:241) at org.mariadb.jdbc.internal.io.input.StandardPacketInputStream.getPacket(StandardPacketInputStream.java:212) at org.mariadb.jdbc.internal.com.read.ReadInitialHandShakePacket.<init>(ReadInitialHandShakePacket.java:90) at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.createConnection(AbstractConnectProtocol.java:480) at org.mariadb.jdbc.internal.protocol.AbstractConnectProtocol.connectWithoutProxy(AbstractConnectProtocol.java:1236) at org.mariadb.jdbc.internal.util.Utils.retrieveProxy(Utils.java:610) at org.mariadb.jdbc.MariaDbConnection.newConnection(MariaDbConnection.java:142) at org.mariadb.jdbc.Driver.connect(Driver.java:86) at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:138) at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:358) at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:206) at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:477)
这里显示 HikariPool-1 connection adder 这个线程一直处于 socketRead 的可执行状态。从命名上看该线程应该是 HikariCP 连接池用于建立连接的任务线程,socket 读操作则来自于 MariaDbConnection.newConnection() 这个方法,即 mariadb-java-client 驱动层建立 MySQL 连接的一个操作,其中 ReadInitialHandShakePacket 初始化则属于 MySQL 建链协议中的一个环节。
简而言之,上面的线程刚好处于建链的一个过程态,关于 mariadb 驱动和 MySQL 建链的过程大致如下:
MySQL 建链首先是建立 TCP 连接(三次握手),客户端会读取 MySQL 协议的一个初始化握手消息包,内部包含 MySQL 版本号,鉴权算法等等信息,之后再进入身份鉴权的环节。
public void addBagItem(final int waiting)
{
final boolean shouldAdd = waiting - addConnectionQueueReadOnlyView.size() >= 0; // Yes, >= is intentional.
if (shouldAdd) {
//调用 AddConnectionExecutor 提交创建连接的任务
addConnectionExecutor.submit(poolEntryCreator);
}
else {
logger.debug("{} - Add connection elided, waiting {}, queue {}", poolName, waiting, addConnectionQueueReadOnlyView.size());
}
}
PoolEntryCreator 则实现了创建连接的具体逻辑,如下:
public class PoolEntryCreator{
@Override
public Boolean call()
{
long sleepBackoff = 250L;
//判断是否需要建立连接
while (poolState == POOL_NORMAL && shouldCreateAnotherConnection()) {
//创建 MySQL 连接
final PoolEntry poolEntry = createPoolEntry();
if (poolEntry != null) {
//建立连接成功,直接返回。
connectionBag.add(poolEntry);
logger.debug("{} - Added connection {}", poolName, poolEntry.connection);
if (loggingPrefix != null) {
logPoolState(loggingPrefix);
}
return Boolean.TRUE;
}
...
}
// Pool is suspended or shutdown or at max size
return Boolean.FALSE;
}
}
由此可见,AddConnectionExecutor 采用了单线程的设计,当产生新连接需求时,会异步触发 PoolEntryCreator 任务进行补充。其中 PoolEntryCreator. createPoolEntry() 会完成 MySQL 驱动连接建立的所有事情,而我们的情况则恰恰是 MySQL 建链过程产生了永久性阻塞。因此无论后面怎么获取连接,新来的建链任务都会一直排队等待,这便导致了业务上一直没有连接可用。
下面这个图说明了 hikariCP 的建链过程:
好了,让我们在回顾一下前面关于可靠性测试的场景:
首先,MySQL 主实例发生故障,而紧接着 hikariCP 则检测到了坏的连接(connection is dead)并将其释放,在释放关闭连接的同时又发现连接数需要补充,进而立即触发了新的建链请求。 而问题就刚好出在这一次建链请求上,TCP 握手的部分是成功了(客户端和 MySQL VM 上 nodePort 完成连接),但在接下来由于当前的 MySQL 容器已经停止(此时 VIP 也切换到了另一台 MySQL 实例上),因此客户端再也无法获得原 MySQL 实例的握手包响应(该握手属于MySQL应用层的协议),此时便陷入了长时间的阻塞式 socketRead 操作。而建链请求任务恰恰好采用了单线程运作,进一步则导致了所有业务的阻塞。
本次分享了一次关于 MySQL 连接挂死问题排查的心路历程,由于环境搭建的工作量巨大,而且该问题复现存在偶然性,整个分析过程还是有些坎坷的(其中也踩了坑)。的确,我们很容易被一些表面的现象所迷惑,而觉得问题很难解决时,更容易带着偏向性思维去处理问题。例如本例中曾一致认为连接池出现了问题,但实际上却是由于 MySQL JDBC 驱动(mariadb driver)的一个不严谨的配置所导致。