Open gaopeng1234567 opened 4 years ago
brettwooldridge
commented
4 years ago @gaopeng1234567 Two things. 1) Enable debug logging. 2) Enable the leakDetectionThreshold. This looks like there is a connection leak somewhere in your code, or threads are holding onto connections for long enough to starve other threads needing a connection.
dmitrymurashenkov
commented
4 years ago We occasionally see these exceptions too. In our project we do not use Spring - just JPA Hibernate with manually created Hikary 3.1.0 datasource.
In our case we set leakDetectionThreshold to 10 minutes, but once service got stuck - no messages with leak word in logs in 10 hours. No debug logs available for now, the problem happens very rarely - once in 2-3 months.
However - we have a heapdump from this situation! We set minIdle to 0, maxPoolSize to 20. And in heap dump we see only 9 PoolEntry instances, only 4 of them have non-null connection and only 1 connection have non-null entry in openStatements. The heap dump size is small, so it's not an OOM case like in #1186.
Can this info indicate that there might be a problem in Hikari code?
dmitrymurashenkov
commented
4 years ago After further investigation of the heap dump we found that connection adder is actually waiting to get connection:
"HikariPool-1 connection adder" #30609 daemon prio=5 os_prio=0 tid=0x00007f20e800c000 nid=0x1f31 runnable [0x00007f215ced2000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.FileDispatcherImpl.read0(Native Method)
at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223)
at sun.nio.ch.IOUtil.read(IOUtil.java:197)
at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:380)
- locked <0x00000000e0e8dbb0> (a java.lang.Object)
at oracle.net.nt.TimeoutSocketChannel.read(TimeoutSocketChannel.java:140)
at oracle.net.ns.NIOHeader.readHeaderBuffer(NIOHeader.java:78)
at oracle.net.ns.NIOPacket.readNIOPacket(NIOPacket.java:248)
at oracle.net.ns.NSProtocolNIO.negotiateConnection(NSProtocolNIO.java:114)
at oracle.net.ns.NSProtocol.connect(NSProtocol.java:313)
at oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:1434)
at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:514)
at oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:684)
at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:35)
at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:687)
at oracle.jdbc.pool.OracleDataSource.getPhysicalConnection(OracleDataSource.java:380)
at oracle.jdbc.pool.OracleDataSource.getConnection(OracleDataSource.java:269)
at oracle.jdbc.pool.OracleDataSource.getConnection(OracleDataSource.java:194)
at oracle.jdbc.pool.OracleDataSource.getConnection(OracleDataSource.java:172)
at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:367)
at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:196)
at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:467)
at com.zaxxer.hikari.pool.HikariPool.access$100(HikariPool.java:71)
at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:706)
at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:692)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)Our connection timeout is 10 seconds, but at the moment we can't verify if this call got stuck and remained stuck or there were many calls and none of them managed to create new connection because of some DB problems.
geniqtech
commented
4 years ago We are facing this issue too but it does not happen all the time. It seems to happen randomly and most of the time, the application can work pretty well for weeks before encountering this issue. Once this error occurred, the only way is to restart the application.
Have attached the debug logs. hikari.log
In my production environment, there is a huge bug. How can I fix it springboot:2.1.6.RELEASE spring-boot-starter-jdbc:2.1.6.RELEASE HikariCP:3.2.0 springcloud:Greenwich.SR1 jdk:1.8 mysql-connector-java:5.1.44
Complete error log: org.mybatis.spring.MyBatisSystemException: nested exception is org.apache.ibatis.exceptions.PersistenceException:
Error querying database. Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30043ms.
The error may exist in URL [jar:file:/home/bird3/etc/i2work-employee.jar!/BOOT-INF/classes!/mybatis/mapper/EmployeeInfoMapper.xml]
The error may involve com.i2f.i2work.employee.mapper.EmployeeInfoMapper.selectByPrimaryKey
The error occurred while executing a query
Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30043ms.
Caused by: org.apache.ibatis.exceptions.PersistenceException:
Error querying database. Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30043ms.
The error may exist in URL [jar:file:/home/bird3/etc/i2work-employee.jar!/BOOT-INF/classes!/mybatis/mapper/EmployeeInfoMapper.xml]
The error may involve com.i2f.i2work.employee.mapper.EmployeeInfoMapper.selectByPrimaryKey
The error occurred while executing a query
Cause: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30043ms.
Caused by: org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30043ms. at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:81) at org.mybatis.spring.transaction.SpringManagedTransaction.openConnection(SpringManagedTransaction.java:82) at org.mybatis.spring.transaction.SpringManagedTransaction.getConnection(SpringManagedTransaction.java:68) at org.apache.ibatis.executor.BaseExecutor.getConnection(BaseExecutor.java:336) at org.apache.ibatis.executor.SimpleExecutor.prepareStatement(SimpleExecutor.java:85) 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 com.github.pagehelper.PageInterceptor.intercept(PageInterceptor.java:143) at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61) at com.sun.proxy.$Proxy194.query(Unknown Source) at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:147) ... 118 common frames omitted Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30043ms. at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:676) at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:190) at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:155) at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128) at com.zaxxer.hikari.HikariDataSource$$FastClassBySpringCGLIB$$eeb1ae86.invoke()
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:749)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:136)
at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:124)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688)
at com.zaxxer.hikari.HikariDataSource$$EnhancerBySpringCGLIB$$6c0271a1.getConnection()
at org.springframework.jdbc.datasource.DataSourceUtils.fetchConnection(DataSourceUtils.java:157)
at org.springframework.jdbc.datasource.DataSourceUtils.doGetConnection(DataSourceUtils.java:115)
at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:78)
... 130 common frames omitted
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.
at sun.reflect.GeneratedConstructorAccessor332.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
at com.mysql.jdbc.Util.getInstance(Util.java:408)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:918)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:897)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:886)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:860)
at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1187)
at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1182)
at com.mysql.jdbc.ConnectionImpl.setNetworkTimeout(ConnectionImpl.java:5506)
at com.zaxxer.hikari.pool.PoolBase.setNetworkTimeout(PoolBase.java:550)
at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:165)
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:179)
... 144 common frames omitted
Urgent! We look forward to your reply