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 耗盡了鏈接池的鏈接，致使新線程獲取鏈接超時，又致使了獲取鏈接超時的報錯。