Hi,
Recently i have faced an issue in keycloak, the DB connection is lost and not able to perform any operation.
Keycloak version: 18.0.2
DB: MySQL server
Last server restarted: 75days ago
Below is my server logs:
2024-05-27 10:08:11,502 WARN [com.arjuna.ats.jta] (executor-thread-393366) ARJUNA016138: Failed to enlist XA resource io.agroal.narayana.BaseXAResource@1dafe4a9: javax.transaction.xa.XAException: Error trying to start xa transaction: The last packet successfully received from the server was 198,568 milliseconds ago. The last packet sent successfully to the server was 198,569 milliseconds ago. is longer than the server configured value of ‘wait_timeout’. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property ‘autoReconnect=true’ to avoid this problem.
at io.agroal.narayana.BaseXAResource.start(BaseXAResource.java:156)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:661)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.enlistResource(TransactionImple.java:422)
at io.agroal.narayana.NarayanaTransactionIntegration.associate(NarayanaTransactionIntegration.java:93)
at io.agroal.pool.ConnectionPool.getConnection(ConnectionPool.java:245)
at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
at io.quarkus.hibernate.orm.runtime.customized.QuarkusConnectionProvider.getConnection(QuarkusConnectionProvider.java:23)
at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:38)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:108)
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:138)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:50)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$1.doPrepare(StatementPreparerImpl.java:90)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:176)
at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareStatement(StatementPreparerImpl.java:81)
at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.buildBatchStatement(AbstractBatchImpl.java:137)
at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.getBatchStatement(AbstractBatchImpl.java:126)
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3356)
at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3908)
at org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:107)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
at org.hibernate.engine.spi.ActionQueue.lambda$executeActions$1(ActionQueue.java:478)
at java.base/java.util.LinkedHashMap.forEach(LinkedHashMap.java:684)
at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:475)
at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:344)
at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:40)
at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:107)
at org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1402)
at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:493)
at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3285)
at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2420)
at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:449)
at org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoordinatorImpl.java:356)
at org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:47)
at org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:37)
at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:360)
at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91)
at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1295)
at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:128)
at io.quarkus.narayana.jta.runtime.CDIDelegatingTransactionManager.commit(CDIDelegatingTransactionManager.java:105)
at org.keycloak.transaction.JtaTransactionWrapper.commit(JtaTransactionWrapper.java:90)
at org.keycloak.services.DefaultKeycloakTransactionManager.commit(DefaultKeycloakTransactionManager.java:136)
at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.close(QuarkusRequestFilter.java:129)
at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$configureEndHandler$2(QuarkusRequestFilter.java:95)
at io.vertx.ext.web.impl.RoutingContextImpl.lambda$null$0(RoutingContextImpl.java:545)
at io.vertx.ext.web.impl.SparseArray.forEachInReverseOrder(SparseArray.java:40)
at io.vertx.ext.web.impl.RoutingContextImpl.lambda$getHeadersEndHandlers$1(RoutingContextImpl.java:545)
at io.vertx.core.http.impl.Http1xServerResponse.prepareHeaders(Http1xServerResponse.java:707)
at io.vertx.core.http.impl.Http1xServerResponse.end(Http1xServerResponse.java:411)
at io.vertx.core.http.impl.Http1xServerResponse.end(Http1xServerResponse.java:391)
at io.vertx.core.http.impl.Http1xServerResponse.end(Http1xServerResponse.java:460)
at io.quarkus.resteasy.runtime.standalone.VertxBlockingOutput.write(VertxBlockingOutput.java:71)
at io.quarkus.resteasy.runtime.standalone.VertxHttpResponse.writeBlocking(VertxHttpResponse.java:172)
at io.quarkus.resteasy.runtime.standalone.VertxOutputStream.close(VertxOutputStream.java:126)
at io.quarkus.resteasy.runtime.standalone.VertxHttpResponse.finish(VertxHttpResponse.java:145)
at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:170)
at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:82)
at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:42)
at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
at io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:201)
at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:67)
at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:55)
at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
at io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:201)
at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:380)
at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:358)
at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
at io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:201)
at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$1(QuarkusRequestFilter.java:71)
at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
at io.quarkus.vertx.core.runtime.VertxCoreRecorder$13.runWith(VertxCoreRecorder.java:543)
at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2449)
at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1452)
at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: com.mysql.cj.jdbc.exceptions.CommunicationsException: The last packet successfully received from the server was 198,568 milliseconds ago. The last packet sent successfully to the server was 198,569 milliseconds ago. is longer than the server configured value of ‘wait_timeout’. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property ‘autoReconnect=true’ to avoid this problem.
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:2053)
at com.mysql.cj.jdbc.ConnectionWrapper.setAutoCommit(ConnectionWrapper.java:121)
at io.agroal.pool.ConnectionHandler.transactionStart(ConnectionHandler.java:324)
at io.agroal.narayana.BaseXAResource.start(BaseXAResource.java:149)
… 82 more
Caused by: com.mysql.cj.exceptions.CJCommunicationsException: The last packet successfully received from the server was 198,568 milliseconds ago. The last packet sent successfully to the server was 198,569 milliseconds ago. is longer than the server configured value of ‘wait_timeout’. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property ‘autoReconnect=true’ to avoid this problem.
at jdk.internal.reflect.GeneratedConstructorAccessor8195.newInstance(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
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.send(NativeProtocol.java:567)
at com.mysql.cj.protocol.a.NativeProtocol.sendCommand(NativeProtocol.java:622)
at com.mysql.cj.protocol.a.NativeProtocol.sendQueryPacket(NativeProtocol.java:987)
at com.mysql.cj.protocol.a.NativeProtocol.sendQueryString(NativeProtocol.java:933)
at com.mysql.cj.NativeSession.execSQL(NativeSession.java:664)
at com.mysql.cj.jdbc.ConnectionImpl.setAutoCommit(ConnectionImpl.java:2036)
… 85 more
Caused by: java.net.SocketException: Connection reset by peer (Write failed)
at java.base/java.net.SocketOutputStream.socketWrite0(Native Method)
at java.base/java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:110)
at java.base/java.net.SocketOutputStream.write(SocketOutputStream.java:150)
at java.base/sun.security.ssl.SSLSocketOutputRecord.deliver(SSLSocketOutputRecord.java:345)
at java.base/sun.security.ssl.SSLSocketImpl$AppOutputStream.write(SSLSocketImpl.java:1304)
at java.base/java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:81)
at java.base/java.io.BufferedOutputStream.flush(BufferedOutputStream.java:142)
at com.mysql.cj.protocol.a.SimplePacketSender.send(SimplePacketSender.java:55)
at com.mysql.cj.protocol.a.TimeTrackingPacketSender.send(TimeTrackingPacketSender.java:50)
at com.mysql.cj.protocol.a.NativeProtocol.send(NativeProtocol.java:558)
… 90 more
2024-05-27 10:08:11,503 WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (executor-thread-393366) SQL Error: 0, SQLState: null
2024-05-27 10:08:11,503 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (executor-thread-393366) Deferred enlistment not supported