您现在的位置是:网站首页> 编程资料编程资料

详解MySQL连接挂死的原因_Mysql_

2023-05-27 382人已围观

简介 详解MySQL连接挂死的原因_Mysql_

一、背景

近期由测试反馈的问题有点多,其中关于系统可靠性测试提出的问题令人感到头疼,一来这类问题有时候属于“偶发”现象,难以在环境上快速复现;二来则是可靠性问题的定位链条有时候变得很长,极端情况下可能要从 A 服务追踪到 Z 服务,或者是从应用代码追溯到硬件层面。

本次分享的是一次关于 MySQL 高可用问题的定位过程,其中曲折颇多但问题本身却比较有些代表性,遂将其记录以供参考。

架构

首先,本系统以 MySQL 作为主要的数据存储部件。整一个是典型的微服务架构(SpringBoot + SpringCloud),持久层则采用了如下几个组件:

mybatis,实现 SQL <-> Method 的映射

hikaricp,实现数据库连接池

mariadb-java-client,实现 JDBC 驱动

在 MySQL 服务端部分,后端采用了双主架构,前端以 keepalived 结合浮动IP(VIP)做一层高可用。如下:

说明

  • MySQL 部署两台实例,设定为互为主备的关系。
  • 为每台 MySQL 实例部署一个 keepalived 进程,由 keepalived 提供 VIP 高可用的故障切换。实际上,keepalived 和 MySQL 都实现了容器化,而 VIP 端口则映射到 VM 上的 nodePort 服务端口上。
  • 业务服务一律使用 VIP 进行数据库访问。

Keepalived 是基于 VRRP 协议实现了路由层转换的,在同一时刻,VIP 只会指向其中的一个虚拟机(master)。当主节点发生故障时,其他的 keepalived 会检测到问题并重新选举出新的 master,此后 VIP 将切换到另一个可用的 MySQL 实例节点上。这样一来,MySQL 数据库就拥有了基础的高可用能力。

另外一点,Keepalived 还会对 MySQL 实例进行定时的健康检查,一旦发现 MySQL 实例不可用会将自身进程杀死,进而再触发 VIP 的切换动作。

问题现象

本次的测试用例也是基于虚拟机故障的场景来设计的:

持续以较小的压力向业务服务发起访问,随后将其中一台 MySQL 的容器实例(master)重启。按照原有的评估,业务可能会产生很小的抖动,但其中断时间应该保持在秒级。

然而经过多次的测试后发现,在重启 MySQL 主节点容器之后,有一定的概率会出现业务却再也无法访问的情况!

二、分析过程

在发生问题之后,开发同学的第一反应是 MySQL 的高可用机制出了问题。由于此前曾经出现过由于 keepalived 配置不当导致 VIP 未能及时切换的问题,因此对其已经有所戒备。

先是经过一通的排查,然后并没有找到 keepalived 任何配置上的毛病。

然后在没有办法的情况下,重新测试了几次,问题又复现了。

紧接着,我们提出了几个疑点:

1.Keepalived 会根据 MySQL 实例的可达性进行判断,会不会是健康检查出了问题?

但在本次测试场景中,MySQL 容器销毁会导致 keepalived 的端口探测产生失败,这同样会导致 keepalived 失效。如果 keepalived 也发生了中止,那么 VIP 应该能自动发生抢占。而通过对比两台虚拟机节点的信息后,发现 VIP 的确发生了切换。

2. 业务进程所在的容器是否发生了网络不可达的问题?

尝试进入容器,对当前发生切换后的浮动IP、端口执行 telnet 测试,发现仍然能访问成功。

连接池

在排查前面两个疑点之后,我们只能将目光转向了业务服务的DB客户端上。

从日志上看,在产生故障的时刻,业务侧的确出现了一些异常,如下:

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!/:?] 

    ...

这里提示的是业务操作获取连接超时了(超过了30秒)。那么,会不会是连接数不够用呢?

业务接入采用的是 hikariCP 连接池,这也是市面上流行度很高的一款组件了。

我们随即检查了当前的连接池配置,如下:

 //最小空闲连接数 spring.datasource.hikari.minimum-idle=10 //连接池最大大小 spring.datasource.hikari.maximum-pool-size=50 //连接最大空闲时长 spring.datasource.hikari.idle-timeout=60000 //连接生命时长 spring.datasource.hikari.max-lifetime=1800000 //获取连接的超时时长 spring.datasource.hikari.connection-timeout=30000

其中 注意到 hikari 连接池配置了 minimum-idle = 10,也就是说,就算在没有任何业务的情况下,连接池应该保证有 10 个连接。更何况当前的业务访问量极低,不应该存在连接数不够使用的情况。

除此之外,另外一种可能性则可能是出现了“僵尸连接”,也就是说在重启的过程中,连接池一直没有释放这些不可用的连接,最终造成没有可用连接的结果。

开发同学对"僵尸链接"的说法深信不疑,倾向性的认为这很可能是来自于 HikariCP 组件的某个 BUG…

于是开始走读 HikariCP 的源码,发现应用层向连接池请求连接的一处代码如下:

 public class HikariPool{ //获取连接对象入口 public Connection getConnection(final long hardTimeout) throws SQLException { suspendResumeLock.acquire(); final long startTime = currentTime(); try { //使用预设的30s 超时时间 long timeout = hardTimeout; do { //进入循环,在指定时间内获取可用连接 //从 connectionBag 中获取连接 PoolEntry poolEntry = connectionBag.borrow(timeout, MILLISECONDS); if (poolEntry == null) { break; // We timed out... break and throw exception } final long now = currentTime(); //连接对象被标记清除或不满足存活条件时,关闭该连接 if (poolEntry.isMarkedEvicted() || (elapsedMillis(poolEntry.lastAccessed, now) > aliveBypassWindowMs && !isConnectionAlive(poolEntry.connection))) { closeConnection(poolEntry, poolEntry.isMarkedEvicted() ? EVICTED_CONNECTION_MESSAGE : DEAD_CONNECTION_MESSAGE); timeout = hardTimeout - elapsedMillis(startTime); } //成功获得连接对象 else { metricsTracker.recordBorrowStats(poolEntry, startTime); return poolEntry.createProxyConnection(leakTaskFactory.schedule(poolEntry), now); } } while (timeout > 0L); //超时了,抛出异常 metricsTracker.recordBorrowTimeoutStats(startTime); throw createTimeoutException(startTime); } catch (InterruptedException e) { Thread.currentThread().interrupt(); throw new SQLException(poolName + " - Interrupted during connection acquisition", e); } finally { suspendResumeLock.release(); } } }

getConnection() 方法展示了获取连接的整个流程,其中 connectionBag 是用于存放连接对象的容器对象。如果从 connectionBag 获得的连接不再满足存活条件,那么会将其手动关闭,代码如下:

 void closeConnection(final PoolEntry poolEntry, final String closureReason) { //移除连接对象 if (connectionBag.remove(poolEntry)) { final Connection connection = poolEntry.close(); //异步关闭连接 closeConnectionExecutor.execute(() -> { quietlyCloseConnection(connection, closureReason); //由于可用连接变少,将触发填充连接池的任务 if (poolState == POOL_NORMAL) { fillPool(); } }); } }

注意到,只有当连接满足下面条件中的其中一个时,会被执行 close。

  • isMarkedEvicted() 的返回结果是 true,即标记为清除,如果连接存活时间超出最大生存时间(maxLifeTime),或者距离上一次使用超过了idleTimeout,会被定时任务标记为清除状态,清除状态的连接在获取的时候才真正 close。
  • 500ms 内没有被使用,且连接已经不再存活,即 isConnectionAlive() 返回 false

由于我们把 idleTimeout 和 maxLifeTime 都设置得非常大,因此需重点检查 isConnectionAlive 方法中的判断,如下:

 public class PoolBase{ //判断连接是否存活 boolean isConnectionAlive(final Connection connection) { try { try { //设置 JDBC 连接的执行超时 setNetworkTimeout(connection, validationTimeout); final int validationSeconds = (int) Math.max(1000L, validationTimeout) / 1000; //如果没有设置 TestQuery,使用 JDBC4 的校验接口 if (isUseJdbc4Validation) { return connection.isValid(validationSeconds); } //使用 TestQuery(如 select 1)语句对连接进行探测 try (Statement statement = connection.createStatement()) { if (isNetworkTimeoutSupported != TRUE) { setQueryTimeout(statement, validationSeconds); } statement.execute(config.getConnectionTestQuery()); } } finally { setNetworkTimeout(connection, networkTimeout); if (isIsolateInternalQueries && !isAutoCommit) { connection.rollback(); } } return true; } catch (Exception e) { //发生异常时,将失败信息记录到上下文 lastConnectionFailure.set(e); logger.warn("{} - Failed to validate connection {} ({}). Possibly consider using a shorter maxLifetime value.", poolName, connection, e.getMessage()); return false; } } }

我们看到,在PoolBase.isConnectionAlive 方法中对连接执行了一系列的探测,如果发生异常还会将异常信息记录到当前的线程上下文中。随后,在 HikariPool 抛出异常时会将最后一次检测失败的异常也一同收集,如下:

 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 动作将其从连接池中移除,因此也不应该存在僵尸连接对象的问题。

那么,我们之前的推测应该就是错误的!

陷入焦灼

在代码分析之余,开发同学也注意到当前使用的 hikariCP 版本为 3.4.5,而环境上出问题的业务服务却是 2.7.9 版本,这仿佛预示着什么… 让我们再次假设 hikariCP 2.7.9 版本存在某种未知的 BUG,导致了问题的产生。

为了进一步分析连接池对于服务端故障的行为处理,我们尝试在本地机器上进行模拟,这一次使用了 hikariCP 2.7.9 版本进行测试,并同时将 hikariCP 的日志级别设置为 DEBUG。

模拟场景中,会由 由本地应用程序连接本机的 MySQL 数据库进行操作,步骤如下:

1. 初始化数据源,此时连接池 min-idle 设置为 10;

2. 每隔50ms 执行一次SQL操作,查询当前的元数据表;

3. 将 MySQL 服务停止一段时间,观察业务表现;

4. 将 My

-六神源码网