Hikari:Apparent connection leak detected连接泄露分析 原创
16-05-2019 13:25:46.494 [HikariPool-1 housekeeper] WARNcom.zaxxer.hikari.pool.ProxyLeakTask.run - Connection leak detection triggered for com.mysql.jdbc.JDBC4Connection@7c3beffb, stack trace followsja
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 耗尽了连接池的连接,导致新线程获取连接超时,又导致了获取连接超时的报错。
开放原子开发者工作坊旨在鼓励更多人参与开源活动,与志同道合的开发者们相互交流开发经验、分享开发心得、获取前沿技术趋势。工作坊有多种形式的开发者活动,如meetup、训练营等,主打技术交流,干货满满,真诚地邀请各位开发者共同参与!
更多推荐
所有评论(0)