如果启用保存事件,Keycloak 会给出 Lock wait timeout exceeded 错误

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

我在我的项目中使用 keycloak 作为身份代理。

环境设置: Keycloak 版本 16.1.1 部署在具有副本 2 的 k8s 集群中。

集群配置:

  - 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"

在 keycloak 设置中,我们想要记录登录和注销事件,所以我启用了 Save Events 并添加了如下保存类型

事件配置:

现在,当用户 login/logout 来自应用程序时,我在日志中收到以下错误并且事件未保存,我不会一直收到此错误。

错误:

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[=11=](JtaTransactionWrapper.java:65)
    at java.base/java.util.stream.ReferencePipeline.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 io.undertow.servlet@2.2.14.Final//io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.ServletChain.handleRequest(ServletChain.java:68)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
    at org.wildfly.security.elytron-web.undertow-server@1.10.1.Final//org.wildfly.elytron.web.undertow.server.ElytronRunAsHandler.lambda$handleRequest(ElytronRunAsHandler.java:68)
    at org.wildfly.security.elytron-base@1.18.3.Final//org.wildfly.security.auth.server.FlexibleIdentityAssociation.runAsFunctionEx(FlexibleIdentityAssociation.java:103)
    at org.wildfly.security.elytron-base@1.18.3.Final//org.wildfly.security.auth.server.Scoped.runAsFunctionEx(Scoped.java:161)
    at org.wildfly.security.elytron-base@1.18.3.Final//org.wildfly.security.auth.server.Scoped.runAs(Scoped.java:73)
    at org.wildfly.security.elytron-web.undertow-server@1.10.1.Final//org.wildfly.elytron.web.undertow.server.ElytronRunAsHandler.handleRequest(ElytronRunAsHandler.java:67)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:117)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
    at io.undertow.core@2.2.14.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.core@2.2.14.Final//io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
    at io.undertow.core@2.2.14.Final//io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
    at org.wildfly.security.elytron-web.undertow-server-servlet@1.10.1.Final//org.wildfly.elytron.web.undertow.server.servlet.CleanUpHandler.handleRequest(CleanUpHandler.java:38)
    at io.undertow.core@2.2.14.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at org.wildfly.extension.undertow@26.0.1.Final//org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
    at io.undertow.core@2.2.14.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at org.wildfly.extension.undertow@26.0.1.Final//org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.SendErrorPageHandler.handleRequest(SendErrorPageHandler.java:52)
    at io.undertow.core@2.2.14.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:275)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.ServletInitialHandler.access0(ServletInitialHandler.java:79)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.ServletInitialHandler.call(ServletInitialHandler.java:134)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.ServletInitialHandler.call(ServletInitialHandler.java:131)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.core.ServletRequestContextThreadSetupAction.call(ServletRequestContextThreadSetupAction.java:48)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.core.ContextClassLoaderSetupAction.call(ContextClassLoaderSetupAction.java:43)
    at org.wildfly.extension.undertow@26.0.1.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create[=11=](UndertowDeploymentInfoService.java:1544)
    at org.wildfly.extension.undertow@26.0.1.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create[=11=](UndertowDeploymentInfoService.java:1544)
    at org.wildfly.extension.undertow@26.0.1.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create[=11=](UndertowDeploymentInfoService.java:1544)
    at org.wildfly.extension.undertow@26.0.1.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create[=11=](UndertowDeploymentInfoService.java:1544)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:255)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.ServletInitialHandler.access[=11=]0(ServletInitialHandler.java:79)
    at io.undertow.servlet@2.2.14.Final//io.undertow.servlet.handlers.ServletInitialHandler.handleRequest(ServletInitialHandler.java:100)
    at io.undertow.core@2.2.14.Final//io.undertow.server.Connectors.executeRootHandler(Connectors.java:387)
    at io.undertow.core@2.2.14.Final//io.undertow.server.HttpServerExchange.run(HttpServerExchange.java:852)
    at org.jboss.threads@2.4.0.Final//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
    at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
    at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
    at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
    at org.jboss.xnio@3.8.5.Final//org.xnio.XnioWorker$WorkerThreadFactory.run(XnioWorker.java:1280)
    at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: org.hibernate.PessimisticLockException: could not execute statement
    at org.hibernate@5.3.24.Final//org.hibernate.dialect.MySQLDialect.convert(MySQLDialect.java:532)
    at org.hibernate@5.3.24.Final//org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42)
    at org.hibernate@5.3.24.Final//org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
    at org.hibernate@5.3.24.Final//org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
    at org.hibernate@5.3.24.Final//org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:178)
    at org.hibernate@5.3.24.Final//org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3193)
    at org.hibernate@5.3.24.Final//org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:3707)
    at org.hibernate@5.3.24.Final//org.hibernate.action.internal.EntityInsertAction.execute(EntityInsertAction.java:90)
    at org.hibernate@5.3.24.Final//org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:604)
    at org.hibernate@5.3.24.Final//org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:478)
    at org.hibernate@5.3.24.Final//org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:356)
    at org.hibernate@5.3.24.Final//org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39)
    at org.hibernate@5.3.24.Final//org.hibernate.internal.SessionImpl.doFlush(SessionImpl.java:1472)
    at org.hibernate@5.3.24.Final//org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:512)
    at org.hibernate@5.3.24.Final//org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3310)
    at org.hibernate@5.3.24.Final//org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2506)
    at org.hibernate@5.3.24.Final//org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:447)
    at org.hibernate@5.3.24.Final//org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoordinatorImpl.java:352)
    at org.hibernate@5.3.24.Final//org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:47)
    at org.hibernate@5.3.24.Final//org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:37)
    at org.wildfly.transaction.client@2.0.0.Final//org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:236)
    at org.wildfly.transaction.client@2.0.0.Final//org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:247)
    at org.wildfly.transaction.client@2.0.0.Final//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 org.wildfly.transaction.client@2.0.0.Final//org.wildfly.transaction.client.LocalTransaction.commitAndDissociate(LocalTransaction.java:78)
    at org.wildfly.transaction.client@2.0.0.Final//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 org.jboss.ironjacamar.jdbcadapters@1.5.3.Final//org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:537)
    at org.hibernate@5.3.24.Final//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

如果我禁用 Save Events

,我不会收到此错误

问题出在 MariaDB Opensource 数据库上。

我用 show processlist 检查了数据库,我发现 table EVENT_ENTITY 和 table 大小上的许多删除和插入查询 运行 是大约 14GB。

我截断了 table EVENT_ENTITY,因为我不需要较旧的事件。 截断记录后一切正常。