Keycloak giving Lock wait timeout exceeded error in case Save Events enable

I am using keycloak as an Identity broker in my project.

Environment setup: Keycloak version 16.1.1 deployed in k8s cluster with replica 2.

Cluster configuration:

  - name: JGROUPS_DISCOVERY_PROTOCOL
    value: kubernetes.KUBE_PING
  - name: KUBERNETES_NAMESPACE
    valueFrom:
      fieldRef:
        apiVersion: v1
        fieldPath: metadata.namespace
  - name: CACHE_OWNERS_COUNT
    value: "2"
  - name: CACHE_OWNERS_AUTH_SESSIONS_COUNT
    value: "2"

In keycloak setup we want to log Login and Logout events so I enabled the Save Events and added Save Types as below

Event config:

Now when users login/logout from the application, I am getting below error in logs and the event is not getting saved, I am not getting this error all the time.

Error:

10:21:01,074 ERROR [io.undertow.request] (default task-17) UT005023: Exception handling request to /auth/realms/realm123/protocol/openid-connect/logout: org.keycloak.models.ModelException: org.hibernate.PessimisticLockException: could not execute statement
    at org.keycloak.keycloak-model-jpa@16.1.1//org.keycloak.connections.jpa.PersistenceExceptionConverter.convert(PersistenceExceptionConverter.java:84)
    at org.keycloak.keycloak-model-jpa@16.1.1//org.keycloak.connections.jpa.JpaExceptionConverter.convert(JpaExceptionConverter.java:31)
    at org.keycloak.keycloak-services@16.1.1//org.keycloak.transaction.JtaTransactionWrapper.lambda$handleException$0(JtaTransactionWrapper.java:65)
    at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
    at java.base/java.util.HashMap$ValueSpliterator.forEachRemaining(HashMap.java:1693)
    at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
    at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
    at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
    at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
    at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
    at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497)
    at org.keycloak.keycloak-services@16.1.1//org.keycloak.transaction.JtaTransactionWrapper.handleException(JtaTransactionWrapper.java:67)
    at org.keycloak.keycloak-services@16.1.1//org.keycloak.transaction.JtaTransactionWrapper.commit(JtaTransactionWrapper.java:92)
    at org.keycloak.keycloak-services@16.1.1//org.keycloak.services.DefaultKeycloakTransactionManager.commit(DefaultKeycloakTransactionManager.java:136)
    at org.keycloak.keycloak-services@16.1.1//org.keycloak.services.filters.AbstractRequestFilter.close(AbstractRequestFilter.java:64)
    at org.keycloak.keycloak-services@16.1.1//org.keycloak.services.filters.AbstractRequestFilter.filter(AbstractRequestFilter.java:49)
    at org.keycloak.keycloak-wildfly-extensions@16.1.1//org.keycloak.provider.wildfly.WildFlyRequestFilter.doFilter(WildFlyRequestFilter.java:39)
    at [e-mail]//io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at [e-mail]//io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at [e-mail]//io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
    at [e-mail]//io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
    at [e-mail]//io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
    at [e-mail]//io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
    at [e-mail]//org.wildfly.elytron.web.undertow.server.ElytronRunAsHandler.lambda$handleRequest$1(ElytronRunAsHandler.java:68)
    at [e-mail]//org.wildfly.security.auth.server.FlexibleIdentityAssociation.runAsFunctionEx(FlexibleIdentityAssociation.java:103)
    at [e-mail]//org.wildfly.security.auth.server.Scoped.runAsFunctionEx(Scoped.java:161)
    at [e-mail]//org.wildfly.security.auth.server.Scoped.runAs(Scoped.java:73)
    at [e-mail]//org.wildfly.elytron.web.undertow.server.ElytronRunAsHandler.handleRequest(ElytronRunAsHandler.java:67)
    at [e-mail]//io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68)
    at [e-mail]//io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:117)
    at [e-mail]//io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
    at [e-mail]//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at [e-mail]//io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
    at [e-mail]//io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
    at [e-mail]//io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
    at [e-mail]//org.wildfly.elytron.web.undertow.server.servlet.CleanUpHandler.handleRequest(CleanUpHandler.java:38)
    at [e-mail]//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at [e-mail]//org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
    at [e-mail]//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at [e-mail]//org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
    at [e-mail]//io.undertow.servlet.handlers.SendErrorPageHandler.handleRequest(SendErrorPageHandler.java:52)
    at [e-mail]//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at [e-mail]//io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:275)
    at [e-mail]//io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:79)
    at [e-mail]//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:134)
    at [e-mail]//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:131)
    at [e-mail]//io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
    at [e-mail]//io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
    at [e-mail]//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1544)
    at [e-mail]//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1544)
    at [e-mail]//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1544)
    at [e-mail]//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1544)
    at [e-mail]//io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:255)
    at [e-mail]//io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:79)
    at [e-mail]//io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:100)
    at [e-mail]//io.undertow.server.Connectors.executeRootHandler(Connectors.java:387)
    at [e-mail]//io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:852)
    at [e-mail]//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
    at [e-mail]//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
    at [e-mail]//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
    at [e-mail]//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
    at [e-mail]//org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1280)
    at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: org.hibernate.PessimisticLockException: could not execute statement
    at [e-mail]//org.hibernate.dialect.MySQLDialect$3.convert(MySQLDialect.java:532)
    at [e-mail]//org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
    at [e-mail]//org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
    at [e-mail]//org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
    at [e-mail]//org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:178)
    at [e-mail]//org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3193)
    at [e-mail]//org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3707)
    at [e-mail]//org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:90)
    at [e-mail]//org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
    at [e-mail]//org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:478)
    at [e-mail]//org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:356)
    at [e-mail]//org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
    at [e-mail]//org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1472)
    at [e-mail]//org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:512)
    at [e-mail]//org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3310)
    at [e-mail]//org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2506)
    at [e-mail]//org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:447)
    at [e-mail]//org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoordinatorImpl.java:352)
    at [e-mail]//org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:47)
    at [e-mail]//org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:37)
    at [e-mail]//org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:236)
    at [e-mail]//org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:247)
    at [e-mail]//org.wildfly.transaction.client.AbstractTransaction$AssociatingSynchronization.beforeCompletion(AbstractTransaction.java:292)
    at org.jboss.jts//com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
    at org.jboss.jts//com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:360)
    at org.jboss.jts//com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91)
    at org.jboss.jts//com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
    at org.jboss.jts//com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1295)
    at org.jboss.jts//com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:128)
    at org.jboss.jts.integration//com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:94)
    at [e-mail]//org.wildfly.transaction.client.LocalTransaction.commitAndDissociate(LocalTransaction.java:78)
    at [e-mail]//org.wildfly.transaction.client.ContextTransactionManager.commit(ContextTransactionManager.java:71)
    at org.keycloak.keycloak-services@16.1.1//org.keycloak.transaction.JtaTransactionWrapper.commit(JtaTransactionWrapper.java:90)
    ... 50 more
Caused by: java.sql.SQLException: (conn=64759) Lock wait timeout exceeded; try restarting transaction
    at org.mariadb.jdbc//org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:262)
    at org.mariadb.jdbc//org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:164)
    at org.mariadb.jdbc//org.mariadb.jdbc.MariaDbStatement.executeExceptionEpilogue(MariaDbStatement.java:258)
    at org.mariadb.jdbc//org.mariadb.jdbc.ClientSidePreparedStatement.executeInternal(ClientSidePreparedStatement.java:225)
    at org.mariadb.jdbc//org.mariadb.jdbc.ClientSidePreparedStatement.execute(ClientSidePreparedStatement.java:145)
    at org.mariadb.jdbc//org.mariadb.jdbc.ClientSidePreparedStatement.executeUpdate(ClientSidePreparedStatement.java:176)
    at [e-mail]//org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:537)
    at [e-mail]//org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:175)
    ... 78 more
Caused by: java.sql.SQLException: Lock wait timeout exceeded; try restarting transaction
    at org.mariadb.jdbc//org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.readErrorPacket(AbstractQueryProtocol.java:1598)
    at org.mariadb.jdbc//org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.readPacket(AbstractQueryProtocol.java:1460)
    at org.mariadb.jdbc//org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.getResult(AbstractQueryProtocol.java:1423)
    at org.mariadb.jdbc//org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol.executeQuery(AbstractQueryProtocol.java:240)
    at org.mariadb.jdbc//org.mariadb.jdbc.ClientSidePreparedStatement.executeInternal(ClientSidePreparedStatement.java:216)
    ... 82 more

I am not getting this error if I disable Save Events

Answer

The issue was with database which is MariaDB Opensource.

I checked in database with show processlist, I found that to many delete and insert query running on the table EVENT_ENTITY and table size was around 14GB.

I truncated the table EVENT_ENTITY as I don’t required older events. After truncating records all is working as expected.