#StackBounty: #mysql #hibernate #spring-boot #hikaricp #spring-repositories HikariCP not releasing active MySql connections

Bounty: 50

I have recently updated from JDK 8 to JDK 11 and in the process updated the app Hikari dependency to ‘com.zaxxer:HikariCP:3.3.1’ and I am using springBootVersion = ‘2.1.3.RELEASE’. The app has 2 data sources, 1 postgres and 1 MySql. Postgres is fine but MySql is not. As the Pool expires connections and adds new connections the active connections are created and never released, from the hikari perspective. When querying the DB it only shows the 5 idle connections that I expect to see. This continues until I reach the max pool size and then the app starts to sporadically fail to connect.
Has anyone seen anything like this and/or does anyone know something that could help me get to the bottom of this?

The limited logs I could get for this issue:

mysql-17 - After cleanup stats (total=12, active=7, idle=5, waiting=0)
mysql-17 - Before cleanup stats (total=12, active=7, idle=5, waiting=0)
at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:562)
... 89 more
at com.mysql.cj.jdbc.StatementImpl.executeQuery(StatementImpl.java:1186)
at batch.processor.Processor.processRequest(Processor.java:50)
at batch.processor.Processor.checkinStaleAssignedTransaction(Processor.java:76)
at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:153)
at org.springframework.dao.support.ChainedPersistenceExceptionTranslator.translateExceptionIfPossible(ChainedPersistenceExceptionTranslator.java:61)
at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.translateExceptionIfPossible(AbstractEntityManagerFactoryBean.java:527)
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:275)
SQL Error: 0, SQLState: 08S01
mysql-17 - After cleanup stats (total=11, active=6, idle=5, waiting=0)
mysql-17 - Before cleanup stats (total=11, active=6, idle=5, waiting=0)
at java.base/sun.security.ssl.Alert.createSSLException(Alert.java:117)
at java.base/sun.security.ssl.Alert.createSSLException(Alert.java:133)
javax.net.ssl.SSLException: closing inbound before receiving peer's close_notify
STACKTRACE:
MESSAGE: closing inbound before receiving peer's close_notify
javax.net.ssl.SSLException
** BEGIN NESTED EXCEPTION **
EXCEPTION STACK TRACE:
Thu Jul 25 14:52:55 UTC 2019 WARN: Caught while disconnecting...
mysql-17 - Closing connection com.mysql.cj.jdbc.ConnectionImpl@79447870: (

The MySql Config is:

# MySql Properties
mysql.datasource.type=com.zaxxer.hikari.HikariDataSource
mysql.datasource.jdbcUrl=${DB_URL}
mysql.datasource.username=${SECRET_DB_USERNAME}
mysql.datasource.password=${SECRET_DB_PASSWORD}
mysql.datasource.driver-class-name=com.mysql.jdbc.Driver

mysql.datasource.connection-timeout=7000
mysql.datasource.maximum-pool-size=30
mysql.datasource.minimum-idle=5
mysql.datasource.idle-timeout=300000
mysql.datasource.max-lifetime=600000
mysql.datasource.connection-test-query=SELECT 1
mysql.datasource.leak-detection-threshold=3000
mysql.datasource.pool-name=mysql-${node.id}

mysql.jpa.properties.hibernate.dialect=org.hibernate.dialect.MySQLDialect

The MySql Spring Java config is:

@Configuration
@EnableTransactionManagement
@EnableJpaRepositories(entityManagerFactoryRef = "mySqlEntityManagerFactory", transactionManagerRef = "mySqlTransactionManager", basePackages = {"mysql.dao", "models"})
public class MySqlConfiguration {
    @Value("${mysql.jpa.properties.hibernate.dialect}")
    private String dialect;

    @Primary
    @Bean(name = "mySqlTransactionManager")
    public PlatformTransactionManager mySqlTransactionManager() {
        return new JpaTransactionManager(mySqlEntityManagerFactory().getObject());
    }

    @Primary
    @Bean(name = {
        "entityManagerFactory", "mySqlEntityManagerFactory"
    })
    public LocalContainerEntityManagerFactoryBean mySqlEntityManagerFactory() {
        LocalContainerEntityManagerFactoryBean factoryBean = new LocalContainerEntityManagerFactoryBean();
        HibernateJpaVendorAdapter vendorAdapter = new HibernateJpaVendorAdapter();
        Properties props = new Properties();
        props.put("hibernate.dialect", dialect);

        factoryBean.setPersistenceUnitName("mysql");
        factoryBean.setJpaProperties(props);
        factoryBean.setDataSource(mysqlDataSource());
        factoryBean.setJpaVendorAdapter(vendorAdapter);
        factoryBean.setPackagesToScan("models", "mysql.entity");

        return factoryBean;
    }

    @Primary
    @Bean(name = "mysqlDataSource")
    @ConfigurationProperties(prefix = "mysql.datasource")
    public DataSource mysqlDataSource() {
        return DataSourceBuilder.create().type(HikariDataSource.class).build();
    }
}

**** EDIT ****
Some additional logging that may help:

org.springframework.jdbc.CannotGetJdbcConnectionException: Failed to obtain JDBC Connection; nested exception is com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure

The last packet successfully received from the server was 417 milliseconds ago.  The last packet sent successfully to the server was 417 milliseconds ago.
    at org.springframework.jdbc.datasource.DataSourceUtils.getConnection(DataSourceUtils.java:81)
    at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:324)
    at org.springframework.boot.actuate.jdbc.DataSourceHealthIndicator.getProduct(DataSourceHealthIndicator.java:122)
    at org.springframework.boot.actuate.jdbc.DataSourceHealthIndicator.doDataSourceHealthCheck(DataSourceHealthIndicator.java:109)
    at org.springframework.boot.actuate.jdbc.DataSourceHealthIndicator.doHealthCheck(DataSourceHealthIndicator.java:104)
    at org.springframework.boot.actuate.health.AbstractHealthIndicator.health(AbstractHealthIndicator.java:84)
    at org.springframework.boot.actuate.health.CompositeHealthIndicator.health(CompositeHealthIndicator.java:98)
    at org.springframework.boot.actuate.health.CompositeHealthIndicator.health(CompositeHealthIndicator.java:98)
    at org.springframework.boot.actuate.health.HealthEndpoint.health(HealthEndpoint.java:50)
    at org.springframework.boot.actuate.health.HealthEndpointWebExtension.health(HealthEndpointWebExtension.java:54)
    at jdk.internal.reflect.GeneratedMethodAccessor206.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:567)
    at org.springframework.util.ReflectionUtils.invokeMethod(ReflectionUtils.java:246)
    at org.springframework.boot.actuate.endpoint.invoke.reflect.ReflectiveOperationInvoker.invoke(ReflectiveOperationInvoker.java:76)
    at org.springframework.boot.actuate.endpoint.annotation.AbstractDiscoveredOperation.invoke(AbstractDiscoveredOperation.java:61)
    at org.springframework.boot.actuate.endpoint.web.servlet.AbstractWebMvcEndpointHandlerMapping$ServletWebOperationAdapter.handle(AbstractWebMvcEndpointHandlerMapping.java:294)
    at org.springframework.boot.actuate.endpoint.web.servlet.AbstractWebMvcEndpointHandlerMapping$OperationHandler.handle(AbstractWebMvcEndpointHandlerMapping.java:355)
    at jdk.internal.reflect.GeneratedMethodAccessor205.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:567)
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:189)
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138)
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:102)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:895)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:800)
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1038)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:942)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1005)
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:897)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:645)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:882)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:750)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:867)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1623)
    at org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:214)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
    at org.springframework.boot.actuate.web.trace.servlet.HttpTraceFilter.doFilterInternal(HttpTraceFilter.java:90)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:209)
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:178)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:357)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:270)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.filterAndRecordMetrics(WebMvcMetricsFilter.java:117)
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:106)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
    at tracing.shadow.io.opentracing.contrib.web.servlet.filter.TracingFilter.doFilter(TracingFilter.java:140)
    at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
    at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
    at org.eclipse.jetty.server.Server.handle(Server.java:502)
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364)
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
    at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
    at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)
    at java.base/java.lang.Thread.run(Thread.java:835)
Caused by: com.mysql.cj.jdbc.exceptions.CommunicationsException: Communications link failure

The last packet successfully received from the server was 417 milliseconds ago.  The last packet sent successfully to the server was 417 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.StatementImpl.executeQuery(StatementImpl.java:1218)
    at com.mysql.cj.jdbc.DatabaseMetaData.getUserName(DatabaseMetaData.java:4036)
    at tracing.shadow.io.opentracing.contrib.spring.cloud.jdbc.JdbcAspect.getConnection(JdbcAspect.java:44)
    at jdk.internal.reflect.GeneratedMethodAccessor201.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:567)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:644)
    at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:633)
    at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:175)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:93)
    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$$8dfc4e21.getConnection(<generated>)
    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)
    ... 83 common frames omitted
Caused by: com.mysql.cj.exceptions.CJCommunicationsException: Communications link failure

The last packet successfully received from the server was 417 milliseconds ago.  The last packet sent successfully to the server was 417 milliseconds ago.
    at jdk.internal.reflect.GeneratedConstructorAccessor201.newInstance(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
    at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:500)
    at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:481)
    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:562)
    at com.mysql.cj.protocol.a.NativeProtocol.checkErrorMessage(NativeProtocol.java:732)
    at com.mysql.cj.protocol.a.NativeProtocol.sendCommand(NativeProtocol.java:671)
    at com.mysql.cj.protocol.a.NativeProtocol.sendQueryPacket(NativeProtocol.java:986)
    at com.mysql.cj.protocol.a.NativeProtocol.sendQueryString(NativeProtocol.java:921)
    at com.mysql.cj.NativeSession.execSQL(NativeSession.java:1154)
    at com.mysql.cj.jdbc.StatementImpl.executeQuery(StatementImpl.java:1186)
    ... 99 common frames omitted
Caused by: java.io.EOFException: Can not read response from server. Expected to read 4 bytes, read 0 bytes before connection was unexpectedly lost.
    at com.mysql.cj.protocol.FullReadInputStream.readFully(FullReadInputStream.java:67)
    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:556)
    ... 105 common frames omitted


Get this bounty!!!

Leave a Reply

This site uses Akismet to reduce spam. Learn how your comment data is processed.