1. 程式人生 > 其它 >記一次 DatebookHikariCP - Connection is not available 異常排查

記一次 DatebookHikariCP - Connection is not available 異常排查

前提

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;
	}