HikariCP
HikariCP copied to clipboard
Published
20 hours ago •
brettwooldridge
brettwooldridge
Connection com.mysql.cj.jdbc.ConnectionImpl marked as broken because of SQLSTATE(08S01), ErrorCode(0) => Communications link failure
Hi,
Help me to understand and solve this error. I've been trying to figure out different options for days/weeks now. I probably read everything that is on the Internet and tried all kinds of options and combinations. HikariCP refuses to work as expected.
So, I have HikariCP-5.0.1 and MySQL 8.1
Pods are located in Kubernetes in various namespaces. There are no proxies, firewalls or service meshes between them. I run a task that runs 20-30 minutes. That is, at startup there is a connection to the database, then the logic works, and then I need to save the results in the database. It's simple case.
In the debug output I can see that Hikari pings the database every 30 seconds and says that everything is ok.
06:35:52.890 [HikariPool-1 housekeeper] DEBUG [ com.zaxxer.hikari.pool.HikariPool:414.logPoolState()] - HikariPool-1 - Pool stats (total=10, active=1, idle=9, waiting=0)
06:35:52.890 [HikariPool-1 housekeeper] DEBUG [ com.zaxxer.hikari.pool.HikariPool:521.fillPool()] - HikariPool-1 - Fill pool skipped, pool has sufficient level or currently being filled (queueDepth=0).
Here are the HIkariCP settings in Spring Autoconfiguration:
spring.datasource.hikari.jdbc-url=jdbc:mysql://mysql.mysql:3306/dev
spring.datasource.type=com.zaxxer.hikari.HikariDataSource
spring.datasource.hikari.username=${DB_USER}
spring.datasource.hikari.password=${DB_PASSWORD}
spring.datasource.hikari.driver-class-name=com.mysql.cj.jdbc.Driver
spring.datasource.hikari.data-source-properties.maxAllowedPacket=534773760
spring.datasource.hikari.data-source-properties.allowPublicKeyRetrieval=YES
spring.datasource.hikari.data-source-properties.useSSL=NO
spring.datasource.hikari.connection-test-query=SELECT 1
#This is my experiments, which i set in different combinations and values. Но данный пример я описываю со значениями, которые активны. Здесь только закомментированный пример.
#To hold connection
#spring.datasource.hikari.max-lifetime=120000
#spring.datasource.hikari.validation-timeout=864000000
#spring.datasource.hikari.data-source-properties.autoReconnect=true
#Keep connection for 10 days
#spring.datasource.hikari.keepalive-time=864000000
#spring.datasource.hikari.idle-timeout=864000000
#spring.datasource.hikari.validation-timeout=864000000
Here are the HikariCP settings in debug mode:
06:33:21.946 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:968.attemptFromContextLoader()] - Driver class org.hsqldb.jdbc.JDBCDriver found in Thread context class loader org.springframework.boot.loader.LaunchedURLClassLoader@7291c18f
06:33:21.961 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:968.attemptFromContextLoader()] - Driver class com.mysql.cj.jdbc.Driver found in Thread context class loader org.springframework.boot.loader.LaunchedURLClassLoader@7291c18f
06:33:22.070 [main] INFO [rg.hibernate.jpa.internal.util.LogHelper:31.logPersistenceUnitInformation()] - HHH000204: Processing PersistenceUnitInfo [name: default]
Waiting for starting Guardius Owasp Worker Agent...
06:33:22.132 [main] INFO [ org.hibernate.Version:44.logVersion()] - HHH000412: Hibernate ORM core version 6.1.5.Final
06:33:22.491 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1100.logConfiguration()] - HikariPool-1 - configuration:
06:33:22.493 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - allowPoolSuspension.............false
06:33:22.493 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - autoCommit......................true
06:33:22.493 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - catalog.........................none
06:33:22.493 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - connectionInitSql...............none
06:33:22.494 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - connectionTestQuery............."SELECT 1"
06:33:22.494 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - connectionTimeout...............30000
06:33:22.494 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - dataSource......................none
06:33:22.494 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - dataSourceClassName.............none
06:33:22.495 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - dataSourceJNDI..................none
06:33:22.495 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - dataSourceProperties............{maxAllowedPacket=534773760, password=<masked>, allowPublicKeyRetrieval=YES, useSSL=NO}
06:33:22.495 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - driverClassName................."com.mysql.cj.jdbc.Driver"
06:33:22.495 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - exceptionOverrideClassName......none
06:33:22.496 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - healthCheckProperties...........{}
06:33:22.496 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - healthCheckRegistry.............none
06:33:22.496 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - idleTimeout.....................600000
06:33:22.496 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - initializationFailTimeout.......1
06:33:22.497 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - isolateInternalQueries..........false
06:33:22.497 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - jdbcUrl.........................jdbc:mysql://mysql.mysql:3306/dev
06:33:22.497 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - keepaliveTime...................0
06:33:22.497 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - leakDetectionThreshold..........0
06:33:22.497 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - maxLifetime.....................1800000
06:33:22.498 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - maximumPoolSize.................10
06:33:22.498 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - metricRegistry..................none
06:33:22.498 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - metricsTrackerFactory...........none
06:33:22.498 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - minimumIdle.....................10
06:33:22.498 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - password........................<masked>
06:33:22.498 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - poolName........................"HikariPool-1"
06:33:22.498 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - readOnly........................false
06:33:22.499 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - registerMbeans..................false
06:33:22.499 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - scheduledExecutor...............none
06:33:22.499 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - schema..........................none
06:33:22.499 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - threadFactory...................internal
06:33:22.499 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - transactionIsolation............default
06:33:22.500 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - username........................"dev"
06:33:22.500 [main] DEBUG [ com.zaxxer.hikari.HikariConfig:1132.logConfiguration()] - validationTimeout...............5000
06:33:22.500 [main] INFO [ com.zaxxer.hikari.HikariDataSource:110.getConnection()] - HikariPool-1 - Starting...
06:33:22.720 [main] INFO [ com.zaxxer.hikari.pool.HikariPool:565.checkFailFast()] - HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@61e7bf2f
06:33:22.722 [main] INFO [ com.zaxxer.hikari.HikariDataSource:123.getConnection()] - HikariPool-1 - Start completed.
06:33:22.744 [main] INFO [ SQL dialect:66.logSelectedDialect()] - HHH000400: Using dialect: org.hibernate.dialect.MySQLDialect
06:33:22.822 [HikariPool-1 housekeeper] DEBUG [ com.zaxxer.hikari.pool.HikariPool:414.logPoolState()] - HikariPool-1 - Pool stats (total=1, active=0, idle=1, waiting=0)
06:33:22.826 [HikariPool-1 connection adder] DEBUG [ com.zaxxer.hikari.pool.HikariPool:738.call()] - HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@bd80a7
06:33:22.839 [HikariPool-1 connection adder] DEBUG [ com.zaxxer.hikari.pool.HikariPool:738.call()] - HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@41808a9c
06:33:22.852 [HikariPool-1 connection adder] DEBUG [ com.zaxxer.hikari.pool.HikariPool:738.call()] - HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@708b2c9f
06:33:22.865 [HikariPool-1 connection adder] DEBUG [ com.zaxxer.hikari.pool.HikariPool:738.call()] - HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@21af75d3
06:33:22.878 [HikariPool-1 connection adder] DEBUG [ com.zaxxer.hikari.pool.HikariPool:738.call()] - HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@6dab02dc
06:33:22.890 [HikariPool-1 connection adder] DEBUG [ com.zaxxer.hikari.pool.HikariPool:738.call()] - HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@25e1a8d5
06:33:22.903 [HikariPool-1 connection adder] DEBUG [ com.zaxxer.hikari.pool.HikariPool:738.call()] - HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@3da1f629
06:33:22.916 [HikariPool-1 connection adder] DEBUG [ com.zaxxer.hikari.pool.HikariPool:738.call()] - HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@38e18d72
06:33:22.928 [HikariPool-1 connection adder] DEBUG [ com.zaxxer.hikari.pool.HikariPool:738.call()] - HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@4fef7aea
06:33:22.939 [HikariPool-1 connection adder] DEBUG [ com.zaxxer.hikari.pool.HikariPool:414.logPoolState()] - HikariPool-1 - After adding stats (total=10, active=0, idle=10, waiting=0)
Here is my my.cnf:
[mysqld]
default_authentication_plugin=mysql_native_password
skip-name-resolve
explicit_defaults_for_timestamp
basedir=/opt/bitnami/mysql
plugin_dir=/opt/bitnami/mysql/lib/plugin
port=3306
socket=/opt/bitnami/mysql/tmp/mysql.sock
datadir=/bitnami/mysql/data
tmpdir=/opt/bitnami/mysql/tmp
max_allowed_packet=512M
bind-address=*
pid-file=/opt/bitnami/mysql/tmp/mysqld.pid
log-error=/opt/bitnami/mysql/logs/mysqld.log
character-set-server=UTF8
collation-server=utf8_general_ci
slow_query_log=0
slow_query_log_file=/opt/bitnami/mysql/logs/mysqld.log
long_query_time=10.0
default-time-zone = '+02:00'
wait_timeout=2592000
interactive_timeout=2592000
[client]
port=3306
socket=/opt/bitnami/mysql/tmp/mysql.sock
default-character-set=UTF8
plugin_dir=/opt/bitnami/mysql/lib/plugin
[manager]
port=3306
socket=/opt/bitnami/mysql/tmp/mysql.sock
pid-file=/opt/bitnami/mysql/tmp/mysqld.pid
Here are the results of the database queries:
show global variables LIKE "%timeout%";
show global variables LIKE "%wait%";
show global variables LIKE "%conn%";
Here is the complete Stacktrace::
06:53:46.114 [http-nio-0.0.0.0-9999-exec-2] WARN [ com.zaxxer.hikari.pool.ProxyConnection:177.checkException()] - HikariPool-1 - Connection com.mysql.cj.jdbc.ConnectionImpl@61e7bf2f marked as broken because of SQLSTATE(08S01), ErrorCode(0)
com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure
The last packet successfully received from the server was 1,214,276 milliseconds ago. The last packet sent successfully to the server was 1,214,276 milliseconds ago.
at com.mysql.cj.jdbc.exceptions.SQLError.createCommunicationsException(SQLError.java:174)
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:64)
at com.mysql.cj.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:2050)
at com.zaxxer.hikari.pool.ProxyConnection.setAutoCommit(ProxyConnection.java:401)
at com.zaxxer.hikari.pool.HikariProxyConnection.setAutoCommit(HikariProxyConnection.java)
at org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor.begin(AbstractLogicalConnectionImplementor.java:72)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:276)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:246)
at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:83)
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:164)
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:421)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.startTransaction(AbstractPlatformTransactionManager.java:400)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:595)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:382)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:752)
at org.springframework.retry.interceptor.RetryOperationsInterceptor$1.doWithRetry(RetryOperationsInterceptor.java:102)
at org.springframework.retry.support.RetryTemplate.doExecute(RetryTemplate.java:329)
at org.springframework.retry.support.RetryTemplate.execute(RetryTemplate.java:209)
at org.springframework.retry.interceptor.RetryOperationsInterceptor.invoke(RetryOperationsInterceptor.java:135)
at org.springframework.retry.annotation.AnnotationAwareRetryOperationsInterceptor.invoke(AnnotationAwareRetryOperationsInterceptor.java:160)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:752)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:703)
at io.my.services.StorageService$$SpringCGLIB$$0.saveReport(<generated>)
at io.my.services.ReportService.persistsReports(ReportService.java:110)
at io.my.services.MyActiveScanService.activeScan(MyActiveScanService.java:219)
at io.my.controllers.MyController.activeAttack(MyController.java:35)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
at java.base/java.lang.reflect.Method.invoke(Method.java:578)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:207)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:152)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:117)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:884)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1080)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:973)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1003)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:895)
at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:705)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:880)
at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:814)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:223)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
at org.springframework.web.filter.ServerHttpObservationFilter.doFilterInternal(ServerHttpObservationFilter.java:109)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:119)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:741)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:400)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1739)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.base/java.lang.Thread.run(Thread.java:1589)
Caused by: com.mysql.cj.exceptions.CJCommunicationsException: Communications link failure
The last packet successfully received from the server was 1,214,276 milliseconds ago. The last packet sent successfully to the server was 1,214,276 milliseconds ago.
at java.base/jdk.internal.reflect.DirectConstructorHandleAccessor.newInstance(DirectConstructorHandleAccessor.java:67)
at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:500)
at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:484)
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:61)
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:105)
at com.mysql.cj.exceptions.ExceptionFactory.createException(ExceptionFactory.java:151)
at com.mysql.cj.exceptions.ExceptionFactory.createCommunicationsException(ExceptionFactory.java:167)
at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:581)
at com.mysql.cj.protocol.a.NativeProtocol.checkErrorMessage(NativeProtocol.java:761)
at com.mysql.cj.protocol.a.NativeProtocol.sendCommand(NativeProtocol.java:700)
at com.mysql.cj.protocol.a.NativeProtocol.sendQueryPacket(NativeProtocol.java:1051)
at com.mysql.cj.protocol.a.NativeProtocol.sendQueryString(NativeProtocol.java:997)
at com.mysql.cj.NativeSession.execSQL(NativeSession.java:663)
at com.mysql.cj.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:2033)
... 80 common frames omitted
Caused by: java.net.SocketException: Connection reset
at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:313)
at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:340)
at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:789)
at java.base/java.net.Socket$SocketInputStream.read(Socket.java:1025)
at com.mysql.cj.protocol.ReadAheadInputStream.fill(ReadAheadInputStream.java:107)
at com.mysql.cj.protocol.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:150)
at com.mysql.cj.protocol.ReadAheadInputStream.read(ReadAheadInputStream.java:180)
at java.base/java.io.FilterInputStream.read(FilterInputStream.java:119)
at com.mysql.cj.protocol.FullReadInputStream.readFully(FullReadInputStream.java:64)
at com.mysql.cj.protocol.a.SimplePacketReader.readHeaderLocal(SimplePacketReader.java:81)
at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:63)
at com.mysql.cj.protocol.a.SimplePacketReader.readHeader(SimplePacketReader.java:45)
at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:52)
at com.mysql.cj.protocol.a.TimeTrackingPacketReader.readHeader(TimeTrackingPacketReader.java:41)
at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:54)
at com.mysql.cj.protocol.a.MultiPacketReader.readHeader(MultiPacketReader.java:44)
at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:575)
... 86 common frames omitted
06:53:46.116 [HikariPool-1 connection closer] DEBUG [ com.zaxxer.hikari.pool.PoolBase:132.quietlyCloseConnection()] - HikariPool-1 - Closing connection com.mysql.cj.jdbc.ConnectionImpl@61e7bf2f: (connection is broken)
06:53:46.167 [HikariPool-1 connection adder] DEBUG [ com.zaxxer.hikari.pool.HikariPool:738.call()] - HikariPool-1 - Added connection com.mysql.cj.jdbc.ConnectionImpl@28017506
06:53:50.118 [http-nio-0.0.0.0-9999-exec-2] ERROR [my.services.MyActiveScanService:226.activeScan()] - =#= Execution Error. RunId=53. Error=Could not open JPA EntityManager for transaction
org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:467)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.startTransaction(AbstractPlatformTransactionManager.java:400)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373)
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:595)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:382)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:752)
at org.springframework.retry.interceptor.RetryOperationsInterceptor$1.doWithRetry(RetryOperationsInterceptor.java:102)
at org.springframework.retry.support.RetryTemplate.doExecute(RetryTemplate.java:329)
at org.springframework.retry.support.RetryTemplate.execute(RetryTemplate.java:209)
at org.springframework.retry.interceptor.RetryOperationsInterceptor.invoke(RetryOperationsInterceptor.java:135)
at org.springframework.retry.annotation.AnnotationAwareRetryOperationsInterceptor.invoke(AnnotationAwareRetryOperationsInterceptor.java:160)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184)
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:752)
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:703)
at io.my.services.StorageService$$SpringCGLIB$$0.saveReport(<generated>)
at io.my.services.ReportService.persistsReports(ReportService.java:110)
at io.my.services.MyActiveScanService.activeScan(MyActiveScanService.java:219)
at io.my.controllers.MyController.activeAttack(MyController.java:35)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
at java.base/java.lang.reflect.Method.invoke(Method.java:578)
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:207)
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:152)
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:117)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:884)
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797)
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1080)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:973)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1003)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:895)
at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:705)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:880)
at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:814)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:223)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
at org.springframework.web.filter.ServerHttpObservationFilter.doFilterInternal(ServerHttpObservationFilter.java:109)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:185)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:158)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:119)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:741)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:400)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1739)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.base/java.lang.Thread.run(Thread.java:1589)
Caused by: org.hibernate.TransactionException: JDBC begin transaction failed:
at org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor.begin(AbstractLogicalConnectionImplementor.java:78)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:276)
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:246)
at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:83)
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:164)
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:421)
... 72 common frames omitted
Caused by: java.sql.SQLException: Connection is closed
at com.zaxxer.hikari.pool.ProxyConnection$ClosedConnection.lambda$getClosedConnection$0(ProxyConnection.java:502)
at jdk.proxy3/jdk.proxy3.$Proxy127.setAutoCommit(Unknown Source)
at com.zaxxer.hikari.pool.ProxyConnection.setAutoCommit(ProxyConnection.java:401)
at com.zaxxer.hikari.pool.HikariProxyConnection.setAutoCommit(HikariProxyConnection.java)
at org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor.begin(AbstractLogicalConnectionImplementor.java:72)
... 77 common frames omitted
Here is the application start and its end time.
startedAt: '2023-10-02T04:33:05Z'
finishedAt: '2023-10-02T04:53:52Z'
Almost 21 minutes in total.
As you can see from the stacktrace message, the last successful connection to the database was 1,214,276 milliseconds ago, which is equivalent to 20.2379 minutes.
And I think that this is some kind of incomprehensible bug, because I have a running application for clients and it works great, there are no glitches. With the same settings and versions.
I would be grateful for your help. I have already seen many similar topics on the Internet and here, but not a single proposed solution helped.
Thanks!
I encountered the same error, which requires the following conditions to be met at the same time:
- Using azure-cloud-mysql (version: 5.7.32-log/5.6.50-log), manually installed mysql-5.7.28 on Azure virtual machine shows no issues.
-
Optimization parameters for MySQL have been configured in Hikari:
useServerPrepStmts=true. - The version of mysql-connector-j must be: 8.0.32.
Breaking any of the above conditions will not cause the problem, for example:
- Using a self-installed MySQL instance, even if it is installed on an Azure virtual machine.
- Removing the parameter configuration of
useServerPrepStmts=true. Other parameters may also cause this problem. - Use new version of mysql-connector later than 8.0.32, for example, 8.0.33
Problem recurrence
build.gradle
plugins {
id('java')
}
sourceCompatibility = JavaVersion.VERSION_17
dependencies {
implementation 'com.zaxxer:HikariCP:5.0.1'
// conditon2: mysql-connector-j version should be 8.0.32
// It is recommended to use "com.mysql:mysql-connector-java" instead of "mysql:mysql-connector-java".
runtimeOnly 'com.mysql:mysql-connector-j:8.0.32'
}
test table: t1
CREATE TABLE `t1` (
`id` int(11) NOT NULL AUTO_INCREMENT,
`fld1` varchar(50) DEFAULT NULL,
PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=1 DEFAULT CHARSET=utf8mb4;
test code: A1.java
import com.zaxxer.hikari.HikariConfig;
import com.zaxxer.hikari.HikariDataSource;
import java.sql.SQLException;
import java.time.Duration;
import java.util.Properties;
public class A1 {
public static void main(String[] args) throws SQLException {
final var config = new HikariConfig();
// condition 1: use an azure-cloud-mysql instance
config.setJdbcUrl("jdbc:mysql://yourHost:3306/yourDatabase");
config.setUsername("yourUser");
config.setPassword("yourPass");
// Make sure that maxLifetime/connectionTimeout is less than the relevant configuration in MySQL.
config.setMaxLifetime(Duration.ofSeconds(30).toMillis());
config.setConnectionTimeout(Duration.ofSeconds(3).toMillis());
Properties properties = new Properties();
// condition 3: useServerPrepStmts=true
properties.setProperty("useServerPrepStmts", "true");
config.setDataSourceProperties(properties);
try (var pool = new HikariDataSource(config)) {
try (var conn = pool.getConnection();
var pst = conn.prepareStatement("INSERT INTO t1(fld1) values(?) ")) {
pst.setString(1, System.currentTimeMillis() + "");
final var insert = pst.executeUpdate();
System.out.println("insert = " + insert);
}
}
}
}
btw The correspondence between Springboot version and the default included mysql-connector-j version may be unordered, and the correspondence can be viewed in the official website instructions. The tested correspondence is as follows:
| springboot | mysql-connector-j | match condition-2? |
|---|---|---|
| 2.7.16 | 8.0.33 | NO |
| 3.0.2 | 8.0.32 | YES |
| 3.1.4 | 8.0.33 | NO |
As described above, under the premise of meeting conditions 1 and 3, when using Springboot 3.0.2 and not explicitly declaring the version of mysql-connector-j, mysql-connector-j-8.0.32 was introduced, thus meeting condition 2 and triggering the Communications link failure error. However, When downgraded to Springboot 2.7.16 or using Springboot 3.1.4, mysql-connector-j-8.0.33 will be introduced, which does not meet condition 2, and the program can run normally. When using Springboot 3.0.2, if you wish to circumvent condition 2, you need to explicitly specify the version of mysql-connector-j to 8.0.33.
runtimeOnly 'com.mysql:mysql-connector-j:8.0.33'
However, I don't know if this is a bug in HikariCp or a problem with mysql-connector-j?
It's not a problem of HikariCP. The problem occurs when using jdk to directly connect to the database.
public class A2 {
public static void main(String[] args) throws ClassNotFoundException, SQLException {
// condition2: Set useServerPrepStmts=true in the url
final var url = "jdbc:mysql://yourHost:3306/yourDatabase?useServerPrepStmts=true";
final var user = "yourUser";
final var pass = "yourPass";
final var sql = "INSERT INTO t1(fld1) values(?) ";
// Class.forName("com.mysql.cj.jdbc.Driver");
try (var conn = DriverManager.getConnection(url, user, pass);
var pst = conn.prepareStatement(sql)) {
pst.setString(1, System.currentTimeMillis() + "");
final var insert = pst.executeUpdate();
System.out.println("insert = " + insert);
}
}
}
Hi. It was the Spring. Not Hikari.
In my application properties was spring.jpa.open-in-view=true, after changing to the false, everything works as expected.