Administrator
发布于 2018-12-24 / 1470 阅读
21

数据库连接池参数怎么配?Druid 连接泄漏排查

发布后第二天上午,接口全卡在 3 秒

12 月 18 号那次上线加了个订单导出功能,第二天上午十点,运维在群里 @ 我:订单查询接口 P99 从 40ms 涨到了 3000ms,超时率 12%。

第一反应是慢 SQL。打开 Druid 监控页(我们一直开着 /druid),看到的画面不太对:

ActiveCount     : 20 / 20
PoolingCount    : 0
WaitThreadCount : 137
MaxWait         : 3000 ms

连接池被打满,137 个线程在排队。慢 SQL 的表现应该是活跃连接忽高忽低,我这个是死死贴着上限不动

再看应用日志,满屏都是同一条:

Caused by: com.alibaba.druid.pool.GetConnectionTimeoutException:
wait millis 3000, active 20, maxActive 20, creating 0, runningSqlCount 20

注意 creating 0:说明池子不是"正在扩容中",而是彻底拿不出来了。

先分清是连接不够用,还是连接没还

这两种情况表现很像,处理方式完全不同。我的区分办法是重启后盯 ActiveCount 曲线:并发不够的话,高峰上去、高峰过后会回落;泄漏则是只涨不落。

重启一次,每 15 分钟记一个数:

时间QPSActiveCount
10:05(重启)1803
10:2031011
10:4042020(满)
11:1024020(满)
11:4015020(满)

QPS 都掉回 150 了,活跃连接还挂在上限,基本可以断定是泄漏。

用 removeAbandoned 把"借条"打出来

Druid 有个 removeAbandoned 机制:连接被借出超过指定秒数还没归还,就强制回收,并在日志里打印这个连接被借出时的堆栈。这玩意儿是排查利器,但它是兜底回收,不是修复手段。

spring:
  datasource:
    druid:
      remove-abandoned: true
      remove-abandoned-timeout: 180
      log-abandoned: true

打开后等了三分钟,日志里出来了:

2018-12-19 10:52:31 ERROR [Druid-ConnectionPool-Destroy-1987402336] -
abandon connection, owner thread: http-nio-8080-exec-7, connected at :
    java.lang.Thread.getStackTrace(Thread.java:1552)
    com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:1231)
    com.alibaba.druid.filter.FilterChainImpl.connection_connect(FilterChainImpl.java:156)
    com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:1140)
    com.xxx.service.ExportService.queryDetail(ExportService.java:68)
    com.xxx.controller.ExportController.export(ExportController.java:31)

直接指到了 ExportService.java 第 68 行,就是我前一天写的代码。

问题代码:循环里的 return 把 close 跳过了

导出模块没走 MyBatis,是自己写的 JDBC 大批量查询,代码长这样:

public List<ExportRow> queryDetail(Long orderId) throws SQLException {
    Connection conn = dataSource.getConnection();
    PreparedStatement ps = conn.prepareStatement(DETAIL_SQL);
    ps.setLong(1, orderId);
    ResultSet rs = ps.executeQuery();

    List<ExportRow> rows = new ArrayList<>();
    while (rs.next()) {
        if (rows.size() >= MAX_ROW) {
            return rows;          // 提前返回,下面三行 close 全被跳过
        }
        rows.add(buildRow(rs));
    }
    rs.close();
    ps.close();
    conn.close();                 // 第 68 行拿的连接,永远走不到这里
    return rows;
}

导出行数超过 5 万就会命中那个 return,三个 close 一个都不会执行。连接被业务线程一直捏着不撒手,Druid 池子里的 PoolingCount 慢慢归零。

隐蔽的地方在于:测试环境订单最多几千行,永远走不到这一行。上线后只有大客户的导出请求会触发,而且一次泄漏一个连接,攒够 20 个才炸,所以隔了一整晚才出事。

顺带说一句,while 循环里如果抛异常,同样会跳过 close,只是我们这次没踩到。

改法:try-with-resources

JDK 7 就有的语法,编译器会帮你生成 finally 里的 close,不管从哪个出口离开都会执行:

public List<ExportRow> queryDetail(Long orderId) throws SQLException {
    List<ExportRow> rows = new ArrayList<>();
    try (Connection conn = dataSource.getConnection();
         PreparedStatement ps = conn.prepareStatement(DETAIL_SQL)) {

        ps.setLong(1, orderId);
        ps.setFetchSize(1000);

        try (ResultSet rs = ps.executeQuery()) {
            while (rs.next()) {
                if (rows.size() >= MAX_ROW) {
                    break;                    // 改成 break,从循环出去而不是从方法出去
                }
                rows.add(buildRow(rs));
            }
        }
    }
    return rows;
}

这里有个我一开始搞混的点:try-with-resources 调用的 conn.close(),实际执行的是 DruidPooledConnection.close(),它不会真的断开 TCP 连接,只是把物理连接归还给池子并且把 abandoned 标记清掉。我专门翻了源码确认过,不然还真不敢这么改。

顺带把池子参数重算了一遍

之前的 maxActive: 200 是照着网上抄的,被 DBA 骂过一次。这次认真算了一下。

思路是:一条连接在理想状态下每秒能执行 1 / 平均耗时 条 SQL。从 Druid 监控的 SQL 执行时间分布看,我们订单库单次查询平均 18ms,那单连接理论上限约 55 QPS。单机目标峰值 400 QPS,纯计算 400 / 55 ≈ 7.3 条。再考虑三个因素:

  • 一个请求里往往串行执行 3 到 5 条 SQL
  • 慢查询会长时间占着连接不放
  • 留 30% 余量应对毛刺

最后定在 20。DBA 给的硬上限是单库 100 个连接,我们 4 个应用实例,20 × 4 = 80,还有余量。

spring:
  datasource:
    druid:
      initial-size: 5
      min-idle: 5
      max-active: 20
      max-wait: 3000
      time-between-eviction-runs-millis: 60000
      min-evictable-idle-time-millis: 300000
      validation-query: SELECT 1
      test-while-idle: true
      test-on-borrow: false        # 千万别开,下面说原因
      test-on-return: false

几个参数的实测体会:

  • maxWait 3000:拿不到连接最多等 3 秒就快速失败。拖着不报错会把 Tomcat 的 200 个工作线程全堵死,那才是真灾难。
  • testOnBorrow:每次借连接都跑一次 SELECT 1,我们压测时 TPS 从 4200 掉到 3600,掉了 14%。用 testWhileIdle 让后台线程 60 秒扫一次空闲连接就够。
  • minIdleinitialSize 设成一样,避免高峰期临时创建连接造成抖动。
  • removeAbandoned 我只在排查期开着,定位完就关了。它每 180 秒要全池扫描一次,而且会掩盖真实问题:连接被强制回收了,业务却不知道自己写错了。

修复前后在同一台机器上跑了压测(400 并发,持续 5 分钟):

指标修复前修复后
TPS601350
错误率12.3%0%
P99 响应时间3000ms47ms

小结

这次踩坑记下三条。

第一,判断"不够用"还是"没归还",看的是活跃连接曲线会不会回落,不是看峰值有多高。这个判断决定了后续是调参数还是改代码,方向搞反了会浪费大量时间。

第二,JDBC 手动关闭资源一律用 try-with-resources,别信自己写的 finally。项目里还有几处老代码是手写 close 的,我用这个命令扫了一遍:

grep -rn "getConnection()" --include=*.java src/ | grep -v "try ("

一共 6 处,都改成 try-with-resources 了。

第三,连接池不是越大越好。连接数超过数据库 CPU 能扛的并行度之后,加连接只会让上下文切换变多、每条 SQL 都变慢,最后集体超时。20 这个数字是算出来的,不是抄来的。

参考