[alibaba/druid]version 1.2.12 偶发 com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure

2025-11-10 610 views
5

连接池版本为:1.2.12 配置: druid:

主库数据源
  master:
    url: jdbc:mysql://:3306/db?serverTimezone=Asia/Shanghai&characterEncoding=utf8&useSSL=false&zeroDateTimeBehavior=convertToNull
    username: 
    password: 
  # 从库数据源
  slave:
    # 从数据源开关/默认关闭
    enabled: false
    url:
    username:
    password:
  # 初始连接数
  initialSize: 5
  # 最小连接池数量
  minIdle: 10
  # 最大连接池数量
  maxActive: 20
  # 配置获取连接等待超时的时间
  maxWait: 60000
  # 配置间隔多久才进行一次检测,检测需要关闭的空闲连接,单位是毫秒
  timeBetweenEvictionRunsMillis: 60000
  # 配置一个连接在池中最小生存的时间,单位是毫秒
  minEvictableIdleTimeMillis: 300000
  # 配置一个连接在池中最大生存的时间,单位是毫秒
  maxEvictableIdleTimeMillis: 900000
  # 配置检测连接是否有效
  validationQuery: SELECT 1 FROM DUAL
  testWhileIdle: true
  testOnBorrow: false
  testOnReturn: false
  statViewServlet:
    enabled: true
    url-pattern: /monitor/druid/*
  filter:
    stat:
      # 慢SQL记录
      log-slow-sql: true
      slow-sql-millis: 1000
      merge-sql: true
    wall:
      config:
        multi-statement-allow: true

错误日志: 2023-08-13 03:32:55.676 ERROR 31468 --- [XNIO-1 task-13] c.a.druid.pool.DruidPooledStatement : <0><13165708290316032> CommunicationsException, druid version 1.2.12, jdbcUrl : jdbc:mysql://localhost:3306/db?serverTimezone=Asia/Shanghai&characterEncoding=utf8&useSSL=false&zeroDateTimeBehavior=convertToNull, testWhileIdle true, idle millis 10013, minIdle 10, poolingCount 2, timeBetweenEvictionRunsMillis 60000, lastValidIdleMillis 10013, driver com.mysql.cj.jdbc.Driver, exceptionSorter com.alibaba.druid.pool.vendor.MySqlExceptionSorter 2023-08-13 03:32:55.677 ERROR 31468 --- [XNIO-1 task-13] com.alibaba.druid.pool.DruidDataSource : <0><13165708290316032> {conn-10210} discard

com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure

The last packet successfully received from the server was 10,011 milliseconds ago. The last packet sent successfully to the server was 10,011 milliseconds ago.

报这个错是在执行一个update sql 语句的时候。

回答

5

1.2.17 同样的问题。

3

每天凌晨3点33前后一分钟准时出现,没定位到问题

2

我们部分场景有类似问题,初步看是mysql服务端针对超长实际没有使用的连接进行了主动关闭。 但是连接池为何会有连接长时间没有被取出来使用,还有待分析。 这几天正在分析,有可能跟参数配置有关。

0

我们部分场景有类似问题,初步看是mysql服务端针对超长实际没有使用的连接进行了主动关闭。 但是连接池为何会有连接长时间没有被取出来使用,还有待分析。 这几天正在分析,有可能跟参数配置有关。

我也碰到过 分析出啥情况没

1

我们部分场景有类似问题,初步看是mysql服务端针对超长实际没有使用的连接进行了主动关闭。 但是连接池为何会有连接长时间没有被取出来使用,还有待分析。 这几天正在分析,有可能跟参数配置有关。

我们服务器的场景是:每天凌晨3点33前后一分钟准时出现,没定位到问题,不知道升级或者降级包有没有用

8

我们部分场景有类似问题,初步看是mysql服务端针对超长实际没有使用的连接进行了主动关闭。 但是连接池为何会有连接长时间没有被取出来使用,还有待分析。 这几天正在分析,有可能跟参数配置有关。

我们服务器的场景是:每天凌晨3点33前后一分钟准时出现,没定位到问题,不知道升级或者降级包有没有用

1.2.18也出现了 只要如删除的表数据很大 几十万 就报这个错

8

我们部分场景有类似问题,初步看是mysql服务端针对超长实际没有使用的连接进行了主动关闭。 但是连接池为何会有连接长时间没有被取出来使用,还有待分析。 这几天正在分析,有可能跟参数配置有关。

我们服务器的场景是:每天凌晨3点33前后一分钟准时出现,没定位到问题,不知道升级或者降级包有没有用

1.2.18也出现了 只要如删除的表数据很大 几十万 就报这个错

删除的几十万条的数据吗?我们服务器没有,删除了几条数据或者新增的几条数据,但表都是大表

6

我们部分场景有类似问题,初步看是mysql服务端针对超长实际没有使用的连接进行了主动关闭。 但是连接池为何会有连接长时间没有被取出来使用,还有待分析。 这几天正在分析,有可能跟参数配置有关。

我们服务器的场景是:每天凌晨3点33前后一分钟准时出现,没定位到问题,不知道升级或者降级包有没有用

1.2.18也出现了 只要如删除的表数据很大 几十万 就报这个错

删除的几十万条的数据吗?我们服务器没有,删除了几条数据或者新增的几条数据,但表都是大表

那问题应该差不多,你们配置我看了感觉也没啥问题,数据库的超时和等待配置时间是多少,之前hikari没有这个问题的

1

我们部分场景有类似问题,初步看是mysql服务端针对超长实际没有使用的连接进行了主动关闭。 但是连接池为何会有连接长时间没有被取出来使用,还有待分析。 这几天正在分析,有可能跟参数配置有关。

我们服务器的场景是:每天凌晨3点33前后一分钟准时出现,没定位到问题,不知道升级或者降级包有没有用

1.2.18也出现了 只要如删除的表数据很大 几十万 就报这个错

删除的几十万条的数据吗?我们服务器没有,删除了几条数据或者新增的几条数据,但表都是大表

那问题应该差不多,你们配置我看了感觉也没啥问题,数据库的超时和等待配置时间是多少,之前hikari没有这个问题的

配置文章内容上面有,我还没跳过,看过有些文章说在数据库链接后面加上sockettime 时间,不晓得有没有用

4

我们部分场景有类似问题,初步看是mysql服务端针对超长实际没有使用的连接进行了主动关闭。 但是连接池为何会有连接长时间没有被取出来使用,还有待分析。 这几天正在分析,有可能跟参数配置有关。

我们服务器的场景是:每天凌晨3点33前后一分钟准时出现,没定位到问题,不知道升级或者降级包有没有用

1.2.18也出现了 只要如删除的表数据很大 几十万 就报这个错

删除的几十万条的数据吗?我们服务器没有,删除了几条数据或者新增的几条数据,但表都是大表

那问题应该差不多,你们配置我看了感觉也没啥问题,数据库的超时和等待配置时间是多少,之前hikari没有这个问题的

数据库超时和等待好像没配置

3

请问有找到这个问题所在吗?1.1.21 也有这个偶发的问题

9

给大家分享一下今天验证了一天的初步分析和临时规避方法:

1.现象概述: 执行业务逻辑时,偶发连接失败 Communications link failure。

2.触发异常的组件版本: druid 1.2.15,mysql jdbc 8.0.31。

3.异常现象描述:生产环境很多tdsql实例,也有很多java应用进程,通过 tdsql proxy访问数据库,目前仅连接指定db的部分实例出现连接失败的情况。 具体表现是,应用投产部署超过48小时之后,执行业务逻辑时,出现少量Communications link failure。 经与dba核实,目前服务端配置的wait_timeout=48h.

4.分析方法: 初期想通过增加filter来采集信息分析,但是druid连接池管理的代码中日志太少,还是不方便分析,于是拉源代码来加了日志写了测试代码验证。 测试代码基于druid 1.2.18,mysql jdbc 8.0.33,测试用例部分核心代码:

连接池初始话代码:

   System.setProperty("druid.mysql.usePingMethod", "false");
        dataSource.setInitialSize(10);
        dataSource.setMinIdle(10);//
        dataSource.setMaxActive(100);
        // 配置获取连接等待超时的时间
        dataSource.setMaxWait(10000);
        // 配置间隔多久才进行一次检测,检测需要关闭的空闲连接,单位是毫秒
        dataSource.setTimeBetweenEvictionRunsMillis(6000); // 每6秒检测一次看下
        // 配置一个连接在池中最小生存的时间,单位是毫秒
        dataSource.setMinEvictableIdleTimeMillis(30000);
        dataSource.setCreateScheduler(new ScheduledThreadPoolExecutor(3));
        dataSource.setDestroyScheduler(new ScheduledThreadPoolExecutor(3));
        // 空闲连接保活
        dataSource.setKeepAlive(true);
        // 检测语句强制用执行SQL(规避网关的假连接,参考启动属性:-Ddruid.mysql.usePingMethod=false)
        dataSource.setValidationQuery("SELECT 1");
        dataSource.setTestWhileIdle(true);
        dataSource.setTestOnBorrow(false);
        dataSource.setTestOnReturn(false);
        // 打开PSCache,并且指定每个连接上PSCache的大小。Oracle 才用的着, MySQL 关闭
        dataSource.setPoolPreparedStatements(false);
        // 配置监控统计filters
        List<Filter> filters = new ArrayList<>();
        filters.add(weupConnAliveCheckFilter);
        dataSource.setProxyFilters(filters);
        dataSource.init();
        return dataSource;

Filter采集信息的代码示意:

public class WeupConnAliveCheckFilter extends FilterAdapter {
    ConcurrentHashMap<String, ConnectionStatInfo> statMap = new ConcurrentHashMap<>(512);

    @Override
    public DruidPooledConnection dataSource_getConnection(FilterChain chain, DruidDataSource dataSource, long maxWaitMillis) throws SQLException {

        System.out.println("获取连接池连接dataSource_getConnection" + connection.getId());
 }

    @Override
    public void dataSource_releaseConnection(FilterChain chain, DruidPooledConnection connection) throws SQLException {
        System.out.println("归还连接池连接connection_close" + connectionTmp.getId());
   }

    @Override
    public ConnectionProxy connection_connect(FilterChain chain, Properties info) throws SQLException {
        System.out.println("获取物理连接connection_connect" + connection.getId());
@Override
    public void connection_close(FilterChain chain, ConnectionProxy connection) throws SQLException {
        System.out.println("关闭物理连接connection_close" + connection.getId());
  }

16并发触发db操作的示例代码片段:

 ThreadPoolExecutor tpe = new ThreadPoolExecutor(16, 16, 20, TimeUnit.SECONDS, new ArrayBlockingQueue<>(500));
 DruidDataSource dds = newDataSource();
        JdbcTemplate jt = new JdbcTemplate(dds);
        Thread.sleep(7000);//先等超过6秒以上的时间
        System.out.println(weupConnAliveCheckFilter.dumpStatInfo());
        int taskCount = 200;
//16并发执行200次db操作
        runBatchTask(tpe, jt, taskCount);
        Thread.sleep(1000);
        System.out.println(weupConnAliveCheckFilter.dumpStatInfo());
        runBatchTask(tpe, jt, taskCount);
.....

5.执行结果示例:

6.初步结论: 6.1 druid在初始10个连接之后,又多初始化了10个连接,实际初始化了20给连接(在6秒后DestroyTask的定时任务里会回收掉只保留minIdle的10个) 6.2 druid目前连接池借用连接的算法有不足之处,在业务并发量不大的情况下,会出现先创建的连接一直没被借出来使用的情况(定期的validate是会执行的,这些连接只会定期执行select 1) 6.3 目前猜测tdsql的服务端配置可能存在缺陷或bug,会导致这些连接被视为不活跃连接,然后在超过wait_timeout配置的时间之后,服务端主动断开了连接。

7.临时规避方法: 7.1规避方法1: 把minIdle设置成1,不要用10,这样空闲连接会及时关闭掉,只保留1个,这样这一个连接不被借出来使用的概率极低,只要并发db操作大于2,基本上每个连接都会被借来跑业务逻辑,这样连接就执行了真正的业务逻辑,就不会被数据库识别成非活跃连接而断开了 (在实际业务中,minIdle保留多个连接所能减少的性能开销基本可以忽略不计) 7.2 规避方法2: 设置数据源的phyTimeoutMillis(代码中有,但是文档中没有该参数),比如配置成最大使用4个小时,

dataSource.setPhyTimeoutMillis(3600000*4); 

这样每个物理连接在创建超过四个小时之后,也会被DestroyTask 强制回收掉,然后再创建新的物理连接。

7.3. 升级使用druid 1.2.18,和mysql jdbc 8.0.33及更高版本,这个可能会有一定的加固效果,不确定哈。

8.后续措施: 已经跟温少沟通,后续我来加上一些debug级别的日志,在连接回收和出错等关键逻辑的地方,输出详细的信息共定位分析用(前提是对应日志级别为debug) 且准备在com.alibaba.druid.pool.DruidDataSource.shrink(boolean, boolean)的这个方法里,加上对连接数组的适当简单乱序操作,确保每个连接都相对平均的被借出去使用执行业务逻辑。 (待详细测试验证)