记一次 DatebookHikariCP – Connection is not available 异常排查

  • Post author:
  • Post category:其他

前提

HikariCP配置如下 , 经过多方面排查,这部分配置并无异常

## 最小空闲连接数量
spring.datasource.hikari.minimum-idle=10
## 连接池最大连接数,默认是10
spring.datasource.hikari.maximum-pool-size=50
## 此属性控制池中连接的最长生命周期,值0表示无限生命周期,默认1800000即30分钟  30分钟
spring.datasource.hikari.max-lifetime=1800000
## 数据库连接超时时间,默认30秒,即30000  35秒
spring.datasource.hikari.connection-timeout=35000
## 空闲连接存活最大时间,默认600000(10分钟) 3分钟
spring.datasource.hikari.idle-timeout=180000
spring.datasource.hikari.connection-test-query=SELECT 1
#这个属性是配置“验证与数据库连接的有效时间”,就是说每隔这么多时间就要去验证一次与数据库的时间是否有效
spring.datasource.hikari.validation-timeout=3000

 

mysql情况

#当前连接数
SHOW FULL PROCESSLIST;
#最大连接数
SHOW VARIABLES LIKE '%max_connections%';

得知:mysql最大可用链接151,目前使用链接106,其中有50个链接是被本应用占用了(达到maximum-pool-size 上限),数据库链接还有45个,可以排除数据库连接池不够用问题。

 

线程分析 
 

jstack     13430 > source.log

"http-nio-8004-exec-10" #46 daemon prio=5 os_prio=0 tid=0x00007efc84b94800 nid=0x2b9d waiting on condition [0x00007efc302ad000]
   java.lang.Thread.State: TIMED_WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00000000e857e820> (a java.util.concurrent.SynchronousQueue$TransferQueue)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	at java.util.concurrent.SynchronousQueue$TransferQueue.awaitFulfill(SynchronousQueue.java:764)
	at java.util.concurrent.SynchronousQueue$TransferQueue.transfer(SynchronousQueue.java:695)
	at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	at com.zaxxer.hikari.util.ConcurrentBag.borrow(ConcurrentBag.java:157)
	at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
	at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:161)
	at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128)
	at org.springframework.jdbc.datasource.DataSourceUtils.fetchConnection(DataSourceUtils.java:158)
	at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:116)
	at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:79)
	at org.mybatis.spring.transaction.SpringManagedTransaction.openConnection(SpringManagedTransaction.java:80)
	at org.mybatis.spring.transaction.SpringManagedTransaction.getConnection(SpringManagedTransaction.java:67)
	at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:336)
	at com.baomidou.mybatisplus.core.executor.MybatisSimpleExecutor.prepareStatement(MybatisSimpleExecutor.java:91)
	at com.baomidou.mybatisplus.core.executor.MybatisSimpleExecutor.doQuery(MybatisSimpleExecutor.java:66)
	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.BaseExecutor.query(BaseExecutor.java:136)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:147)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:140)
	at sun.reflect.GeneratedMethodAccessor185.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)

除了这个相对可疑的数据,其它都正常,并没有发生死锁导致线程被占用,基本可以肯定跟线程无关

 

内存分析

jmap -histo:live 13430 > free.info
 516:            41            984  org.apache.ibatis.type.JdbcType
 517:            41            984  springfox.documentation.spring.web.WebMvcRequestHandler
 518:            12            960  [Ljava.util.concurrent.RunnableScheduledFuture;
 519:            30            960  com.mysql.cj.conf.EnumProperty
 520:            20            960  com.mysql.cj.protocol.a.result.TextBufferRow
 521:            30            960  java.security.Provider$EngineDescription
 522:            12            960  java.util.concurrent.ScheduledThreadPoolExecutor
 523:            15            960  sun.security.provider.SHA5$SHA384
 524:            17            952  sun.misc.URLClassPath$JarLoader
 525:            28            936  [Ljava.io.ObjectStreamField;
 526:            39            936  java.util.regex.Pattern$7
 527:            58            928  com.sun.proxy.$Proxy2
 528:            50            920  com.mysql.cj.jdbc.ConnectionImpl

  528:            50            920  com.mysql.cj.jdbc.ConnectionImpl

   项目中的dataSource引用
   <dependency>
            <groupId>mysql</groupId>
            <artifactId>mysql-connector-java</artifactId>
            <version>8.0.21</version>
   </dependency>

 

发现 java.sql.Connection  -> 实现类 com.mysql.cj.jdbc.ConnectionImpl,被占用了50个实例,有实例却拿不到,说明被占用了。

仔细检查源代码

 

public xxx xxx(String instanceId,int power,int type){
		Connection connection = null;
        try {
            connection = dataSource.getConnection();	
            // xxx 省略
        }catch(Exception e){
        	e.printStackTrace();
        }finally {
            
        }
        return data;
	}

 

项目中有直接使用DataSource对象,connection = dataSource.getConnection() 获取链接之后,没有在finally关闭掉。

接着尝试,在finally加上connection.close(),发现Connection is not available 不再触发

 

总结

并不是说项目中配置了HikariCP数据源Datasource对象就能全部扔给其管理,只要项目中有直接使用DataSource对象的,那么这部分数据源的管理就得自己处理,即: 

public xxx xxx(String instanceId,int power,int type){
		Connection connection = null;
        try {
            connection = dataSource.getConnection();	
            // xxx 省略
        }catch(Exception e){
        	e.printStackTrace();
        }finally {
            if (connection != null) {
                    connection.close();
                }
        }
        return data;
	}

 


版权声明:本文为czk740960212原创文章,遵循 CC 4.0 BY-SA 版权协议,转载请附上原文出处链接和本声明。