Hikari:Apparent connection leak detected链接泄露分析

欢迎访问个人博客，同步更新: 枫山别院 部分报错日志以下:

16-05-2019 13:25:46.494 [HikariPool-1 housekeeper] WARN  com.zaxxer.hikari.pool.ProxyLeakTask.run - Connection leak detection triggered for com.mysql.jdbc.JDBC4Connection@7c3beffb, stack trace follows
java.lang.Exception: Apparent connection leak detected
    at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:111)
    at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:77)
    at org.mybatis.spring.transaction.SpringManagedTransaction.openConnection(SpringManagedTransaction.java:84)
    at org.mybatis.spring.transaction.SpringManagedTransaction.getConnection(SpringManagedTransaction.java:70)
    at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:336)
    at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:84)
    at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:62)
    at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:324)
    at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:156)
    at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:109)
    at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:83)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:148)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:141)
    at org.apache.ibatis.session.defaults.DefaultSqlSession.selectOne(DefaultSqlSession.java:77)
    at sun.reflect.GeneratedMethodAccessor148.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:434)
    at com.sun.proxy.$Proxy107.selectOne(Unknown Source)
    at org.mybatis.spring.SqlSessionTemplate.selectOne(SqlSessionTemplate.java:167)

日志显示，检测到了链接泄露
Hikari配置以下：

hikari:
      maximum-pool-size: 100
      minimum-idle: 0
      leak-detection-threshold: 180000
      connection-timeout: 180000
      validation-timeout: 180000
      idle-timeout: 180000

leak-detection-threshold:用来设置链接被占用的超时时间，单位为毫秒，默认为0，表示禁用链接泄露检测。
connection-timeout:从链接池获取链接的超时时间。

分析源代码发现，该错误的缘由是从链接池获取链接超时，触发了链接泄露检测。
此处spring调用了doGetConnection从hikari中获取链接
在org.springframework.jdbc.datasource.DataSourceUtils#doGetConnection中，

image.png

咱们看看hikari中的实现，进入该方法继续看，
com.zaxxer.hikari.HikariDataSource#getConnection()

image.png

getConnection()又调用了另外一个方法，在com.zaxxer.hikari.pool.HikariPool#getConnection(long)中，

image.png

com.zaxxer.hikari.pool.ProxyLeakTask#ProxyLeakTask(com.zaxxer.hikari.pool.ProxyLeakTask, com.zaxxer.hikari.pool.PoolEntry)中

image.png

这个地方是真正的获取链接的实现了，
分析上面的代码会发现，在获取Connection的时候，建立了一个ProxyLeakTask，这个task是一个定时任务，在leakDetectionThreshold毫秒后调用run()方法抛出Apparent connection leak detected异常。

Xnip2019-09-28_13-26-40.jpg

也就是说，获取到链接以后使用以前的时间+使用链接的时间+使用以后还回链接以前的时间，超出了leakDetectionThreshold毫秒，就抛出检测到链接泄露的异常。结合咱们的业务发现，此处确实是使用链接的时间超出了leakDetectionThreshold毫秒，是由于执行了慢 sql，同时慢 sql 耗尽了链接池的链接，致使新线程获取链接超时，又致使了获取链接超时的报错。