【踩坑日记】Druid连接池在MySQL主备切换时引发高可用问题

背景

由于MySQL供应商内部升级,线上数据库需要主动进行主备切换。切换基于SIP漂移,理论上是毫秒级闪断。但在实际模拟演练的过程中,除了预期内切换瞬间产生的连接异常外,后续半个小时仍不断地产生连接异常,导致问题不可控。

org.springframework.dao.RecoverableDataAccessException:
### Error querying database.  Cause: com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure

The last packet sent successfully to the server was 11,603,448 milliseconds ago.; nested exception is java.lang.Throwable
    at org.springframework.jdbc.support.SQLExceptionSubclassTranslator.doTranslate(SQLExceptionSubclassTranslator.java:100)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81)
    ······

Caused by: java.io.IOException: Socket is closed
    at com.mysql.cj.protocol.AbstractSocketConnection.getMysqlInput(AbstractSocketConnection.java:72)
    at com.mysql.cj.protocol.a.NativeProtocol.clearInputStream(NativeProtocol.java:803)
    ... 130 common frames omitted

【踩坑日记】Druid连接池在MySQL主备切换时引发高可用问题
主备切换后仍有一段时间的报错

分析

排除服务端影响

首先进行一下分析:在报错中显示错误为 CommunicationsException: Communications link failure,并且 Caused by: java.io.IOException: Socket is closed,由此可知此时业务方取出的连接已经关闭了。而 The last packet sent successfully to the server was 11,603,448 milliseconds ago指出上一次成功送出数据包到服务端的时间已经是很久之前了。

为了排除连接在取出后才关闭的可能性,我将连接池的TestOnBorrow开关打开。

testOnBorrow:每次获取连接的时候都会执行validate操作,确保连接取出时有效,对性能有损耗。

在取出前校验,就可以过滤所有取出前就已失效的连接,如果仍有错误,证明MySQL服务端持续有通信问题。

演练结果证明了服务端的清白,报错不再持续出现。

【踩坑日记】Druid连接池在MySQL主备切换时引发高可用问题

虽然TestOnBorrow能解决无效连接,但作为代价,每一条SQL都会PING一次服务端进行校验,这对性能的影响还是不容小觑的,可不能这样简单交差。

在排除服务端的问题后,我们将目光锁定到应用使用的数据库连接池——Druid。

读源码

既然是获取连接时报错,我们就分析一下获取连接的源代码。
以下为 com.alibaba.druid.pool.DruidDataSource#getConnectionDirect的核心逻辑

       for (;;) {
           //省略从连接池中取出poolableConnection的逻辑

            if (testOnBorrow) {
                boolean validate = testConnectionInternal(poolableConnection.holder, poolableConnection.conn);
                if (!validate) {
                    if (LOG.isDebugEnabled()) {
                        LOG.debug("skip not validate connection.");
                    }

                    Connection realConnection = poolableConnection.conn;
                    discardConnection(realConnection);
                    continue;
                }
            } else {
                Connection realConnection = poolableConnection.conn;
                if (poolableConnection.conn.isClosed()) {
                    discardConnection(null); // 传入null,避免重复关闭
                    continue;
                }

                if (testWhileIdle) {
                    final DruidConnectionHolder holder = poolableConnection.holder;
                    long currentTimeMillis             = System.currentTimeMillis();
                    long lastActiveTimeMillis          = holder.lastActiveTimeMillis;
                    long lastKeepTimeMillis            = holder.lastKeepTimeMillis;

                    if (lastKeepTimeMillis > lastActiveTimeMillis) {
                        lastActiveTimeMillis = lastKeepTimeMillis;
                    }

                    long idleMillis                    = currentTimeMillis - lastActiveTimeMillis;

                    long timeBetweenEvictionRunsMillis = this.timeBetweenEvictionRunsMillis;

                    if (timeBetweenEvictionRunsMillis <= 0) { timebetweenevictionrunsmillis="DEFAULT_TIME_BETWEEN_EVICTION_RUNS_MILLIS;" } if (idlemillis>= timeBetweenEvictionRunsMillis
                            || idleMillis < 0 // unexcepted branch
                            ) {
                        boolean validate = testConnectionInternal(poolableConnection.holder, poolableConnection.conn);
                        if (!validate) {
                            if (LOG.isDebugEnabled()) {
                                LOG.debug("skip not validate connection.");
                            }

                            discardConnection(realConnection);
                             continue;
                        }
                    }
                }
            }
        }
</=>

当testOnBorrow开启时,会直接调用 testConnectionInternal进行连接检查,连接失效则直接踢出,进入下一次循环。这是我们刚才验证过的可行路径,而关闭testOnBorrow时失效连接暴露出来了,意味着没有调用 testConnectionInternal。带着这样的假设,我们再看else块。

在else中,首先判断testWhileIdle是否开启,应用配置是开启的(默认也是开启),是则同时取出连接的 lastActiveTimeMillislastKeepTimeMillis,取较大者,与当前时间取差值,如果大于等于 timeBetweenEvictionRunsMillis,则进行 testConnectionInternal校验,同样的,校验不通过则抛弃。

简单讲,在else块中就是durid实现的testWhileIdle机制:在连接取出时,判断如果连接空闲超过指定时间(默认为1分钟),则进行校验,否则直接借出。

在前文中的报错信息里,连接最后一次传输数据是在3个小时前,如此长时间的空闲理应进行校验(校验的正确性我们已在testOnBorrow中验证),然而从现象来看却是没有的,说明计算出的空闲时间没有满足检测门槛。

通过代码分析, lastActiveTimeMillis就是连接使用时间 ,所以应在3个小时前,至此我们的分析剩下了最后一个可变量: lastKeepTimeMillis,这个字段从何而来?

连接保活机制

druid中设计了一种连接保活机制,开启后将定时校验连接的有效性。这个任务由 DruidDataSource.DestroyTask承担,在线程池初始化后通过调度线程池以timeBetweenEvictionRunsMillis为周期定时执行(当前为1分钟)。

以下是连接保活中的校验部分

                try {
                    this.validateConnection(connection);
                    validate = true;
                } catch (Throwable error) {
                    if (LOG.isDebugEnabled()) {
                        LOG.debug("keepAliveErr", error);
                    }
                    // skip
                }

                boolean discard = !validate;
                if (validate) {
                    holer.lastKeepTimeMillis = System.currentTimeMillis();
                    boolean putOk = put(holer);
                    if (!putOk) {
                        discard = true;
                    }
                }

当validate为真(即检查通过)时,前文提到的 lastKeepTimeMillis被刷新为当前时间。

所以保活机制对testWhileIdle形成了一种补充,当连接已在保活任务中被校验过了,即使很久没有被借给业务方,也不会进行冗余的testWhileIdle检查,这也是一种性能优化。

然而问题就出在了validateConnection这个校验方法中…(ps:为何不直接复用前文中的testConnectionInternal呢?)

以下是这个校验方法的核心逻辑,错误就在其中,试着发现一下:

            boolean result = true;
            Exception error = null;
            try {
                result = validConnectionChecker.isValidConnection(conn, validationQuery, validationQueryTimeout);
            } catch (SQLException ex) {
                throw ex;
            } catch (Exception ex) {
                error = ex;
            }

            if (!result) {
                SQLException sqlError = error != null ? //
                    new SQLException("validateConnection false", error) //
                    : new SQLException("validateConnection false");
                throw sqlError;
            }
            return;

问题就在 catch (Exception ex)的处理块中:result没有置为false。
导致非SQLException的错误(例如服务端主动断开导致的IO类异常)没有抛出,从而”躲过”了保活筛查,同时又刷新了 lastKeepTimeMillis,再次”躲过”testWhileIdle检查,最终成功来到了业务方的世界,开始大搞破坏~

结论

解决方案:在catch块内补上 result = false即可,如果你不想自己动手,可以使用最近更新的1.2.6版本,已修复这个issue

升级版本后,不再持续出现连接错误。

【踩坑日记】Druid连接池在MySQL主备切换时引发高可用问题

Original: https://www.cnblogs.com/notayeser/p/15055719.html
Author: d1zzyboy
Title: 【踩坑日记】Druid连接池在MySQL主备切换时引发高可用问题

原创文章受到原创版权保护。转载请注明出处:https://www.johngo689.com/572132/

转载文章受原作者版权保护。转载请注明原作者出处!

(0)

大家都在看

亲爱的 Coder【最近整理,可免费获取】👉 最新必读书单  | 👏 面试题下载  | 🌎 免费的AI知识星球