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 耗尽了连接池的连接,导致新线程获取连接超时,又导致了获取连接超时的报错。

Logo

开放原子开发者工作坊旨在鼓励更多人参与开源活动,与志同道合的开发者们相互交流开发经验、分享开发心得、获取前沿技术趋势。工作坊有多种形式的开发者活动,如meetup、训练营等,主打技术交流,干货满满,真诚地邀请各位开发者共同参与!

更多推荐