Uploaded image for project: 'Red Hat build of Keycloak'
  1. Red Hat build of Keycloak
  2. RHBK-3417

ModelDuplicateException since Keycloak v26 when logging into Keycloak [GHI#39759]

XMLWordPrintable

    • False
    • Hide

      None

      Show
      None
    • False

      Before reporting an issue

      [x] I have read and understood the above terms for submitting issues, and I understand that my issue may be closed without action if I do not follow them.

      Area

      core

      Describe the bug

      Starting from Keycloak v26 we keeps getting the following exception in the logs. It doesn't seem to cause user-facing issues, but adds a lot of noise with our monitoring.

      {
      

      "timestamp": "2025-05-16T14:26:03.726727038+12:00",
      "sequence": 134613,
      "loggerClassName": "org.jboss.logging.Logger",
      "loggerName": "org.keycloak.services.error.KeycloakErrorHandler",
      "level": "ERROR",
      "message": "Uncaught server error",
      "threadName": "executor-thread-505",
      "threadId": 1744421,
      "mdc": {},
      "ndc": "",
      "hostName": "ip-10-162-104-185.ap-southeast-2.compute.internal",
      "processName": "/usr/lib/jvm/java-21-openjdk-21.0.7.0.6-1.el9.x86_64/bin/java",
      "processId": 1,
      "exception": {
      "refId": 1,
      "exceptionType": "java.lang.RuntimeException",
      "message": "unable to complete the session updates",
      "frames": [

      { "class": "org.keycloak.models.sessions.infinispan.changes.JpaChangesPerformer", "method": "applyChanges", "line": 112 }

      ,

      { "class": "java.lang.Iterable", "method": "forEach", "line": 75 }

      ,

      { "class": "org.keycloak.models.sessions.infinispan.changes.PersistentSessionsChangelogBasedTransaction", "method": "commitImpl", "line": 222 }

      ,

      { "class": "org.keycloak.models.AbstractKeycloakTransaction", "method": "commit", "line": 46 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakTransactionManager", "method": "lambda$commitWithTracing$0", "line": 169 }

      ,

      { "class": "org.keycloak.tracing.NoopTracingProvider", "method": "trace", "line": 59 }

      ,

      { "class": "org.keycloak.tracing.NoopTracingProvider", "method": "trace", "line": 69 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakTransactionManager", "method": "commitWithTracing", "line": 168 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakTransactionManager", "method": "commit", "line": 146 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakSession", "method": "closeTransactionManager", "line": 396 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakSession", "method": "close", "line": 361 }

      ,

      { "class": "org.keycloak.models.KeycloakBeanProducer_ProducerMethod_getKeycloakSession_XoSEUTXOsE3bpqXlGMAykCiECUM_ClientProxy", "method": "close" }

      ,

      { "class": "org.keycloak.quarkus.runtime.transaction.TransactionalSessionHandler", "method": "close", "line": 60 }

      ,

      { "class": "org.keycloak.quarkus.runtime.integration.jaxrs.CloseSessionFilter", "method": "closeSession", "line": 67 }

      ,

      { "class": "org.keycloak.quarkus.runtime.integration.jaxrs.CloseSessionFilter", "method": "filter", "line": 63 }

      ,

      { "class": "org.jboss.resteasy.reactive.server.handlers.ResourceResponseFilterHandler", "method": "handle", "line": 25 }

      ,

      { "class": "io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext", "method": "invokeHandler", "line": 150 }

      ,

      { "class": "org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext", "method": "run", "line": 147 }

      ,

      { "class": "io.quarkus.vertx.core.runtime.VertxCoreRecorder$15", "method": "runWith", "line": 638 }

      ,

      { "class": "org.jboss.threads.EnhancedQueueExecutor$Task", "method": "doRunWith", "line": 2675 }

      ,

      { "class": "org.jboss.threads.EnhancedQueueExecutor$Task", "method": "run", "line": 2654 }

      ,

      { "class": "org.jboss.threads.EnhancedQueueExecutor", "method": "runThreadBody", "line": 1627 }

      ,

      { "class": "org.jboss.threads.EnhancedQueueExecutor$ThreadBody", "method": "run", "line": 1594 }

      ,

      { "class": "org.jboss.threads.DelegatingRunnable", "method": "run", "line": 11 }

      ,

      { "class": "org.jboss.threads.ThreadLocalResettingRunnable", "method": "run", "line": 11 }

      ,

      { "class": "io.netty.util.concurrent.FastThreadLocalRunnable", "method": "run", "line": 30 }

      ,

      { "class": "java.lang.Thread", "method": "run", "line": 1583 }

      ],
      "suppressed": [
      {
      "refId": 2,
      "exceptionType": "org.keycloak.models.ModelDuplicateException",
      "message": "Duplicate resource error",
      "frames": [

      { "class": "org.keycloak.connections.jpa.PersistenceExceptionConverter", "method": "convert", "line": 100 }

      ,

      { "class": "org.keycloak.connections.jpa.JpaExceptionConverter", "method": "convert", "line": 31 }

      ,

      { "class": "org.keycloak.transaction.JtaTransactionWrapper", "method": "lambda$handleException$0", "line": 77 }

      ,

      { "class": "java.util.stream.ReferencePipeline$3$1", "method": "accept", "line": 197 }

      ,

      { "class": "java.util.HashMap$ValueSpliterator", "method": "forEachRemaining", "line": 1787 }

      ,

      { "class": "java.util.stream.AbstractPipeline", "method": "copyInto", "line": 509 }

      ,

      { "class": "java.util.stream.AbstractPipeline", "method": "wrapAndCopyInto", "line": 499 }

      ,

      { "class": "java.util.stream.ForEachOps$ForEachOp", "method": "evaluateSequential", "line": 151 }

      ,

      { "class": "java.util.stream.ForEachOps$ForEachOp$OfRef", "method": "evaluateSequential", "line": 174 }

      ,

      { "class": "java.util.stream.AbstractPipeline", "method": "evaluate", "line": 234 }

      ,

      { "class": "java.util.stream.ReferencePipeline", "method": "forEach", "line": 596 }

      ,

      { "class": "org.keycloak.transaction.JtaTransactionWrapper", "method": "handleException", "line": 79 }

      ,

      { "class": "org.keycloak.transaction.JtaTransactionWrapper", "method": "commit", "line": 104 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakTransactionManager", "method": "lambda$commitWithTracing$0", "line": 169 }

      ,

      { "class": "org.keycloak.tracing.NoopTracingProvider", "method": "trace", "line": 59 }

      ,

      { "class": "org.keycloak.tracing.NoopTracingProvider", "method": "trace", "line": 69 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakTransactionManager", "method": "commitWithTracing", "line": 168 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakTransactionManager", "method": "commit", "line": 136 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakSession", "method": "closeTransactionManager", "line": 396 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakSession", "method": "close", "line": 361 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "runJobInTransactionWithResult", "line": 467 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "runJobInTransaction", "line": 340 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "runJobInTransaction", "line": 330 }

      ,

      { "class": "org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker", "method": "lambda$process$4", "line": 125 }

      ,

      { "class": "java.util.ArrayList", "method": "forEach", "line": 1596 }

      ,

      { "class": "org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker", "method": "lambda$process$5", "line": 123 }

      ,

      { "class": "org.keycloak.common.util.Retry", "method": "executeWithBackoff", "line": 102 }

      ,

      { "class": "org.keycloak.common.util.Retry", "method": "executeWithBackoff", "line": 93 }

      ,

      { "class": "org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker", "method": "lambda$process$7", "line": 113 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "lambda$runJobInTransaction$1", "line": 341 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "runJobInTransactionWithResult", "line": 460 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "runJobInTransaction", "line": 340 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "runJobInTransaction", "line": 330 }

      ,

      { "class": "org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker", "method": "process", "line": 97 }

      ,

      { "class": "org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker", "method": "run", "line": 76 }

      ],
      "causedBy": {
      "exception": {
      "refId": 3,
      "exceptionType": "org.postgresql.util.PSQLException",
      "message": "ERROR: duplicate key value violates unique constraint \"constraint_offl_us_ses_pk2\"\n Detail: Key (user_session_id, offline_flag)=(73d321c7-827f-41de-a4b5-75d8c13afdb9, 0) already exists.",
      "frames": [

      { "class": "org.postgresql.core.v3.QueryExecutorImpl", "method": "receiveErrorResponse", "line": 2733 }

      ,

      { "class": "org.postgresql.core.v3.QueryExecutorImpl", "method": "processResults", "line": 2420 }

      ,

      { "class": "org.postgresql.core.v3.QueryExecutorImpl", "method": "execute", "line": 580 }

      ,

      { "class": "org.postgresql.jdbc.PgStatement", "method": "internalExecuteBatch", "line": 889 }

      ,

      { "class": "org.postgresql.jdbc.PgStatement", "method": "executeBatch", "line": 913 }

      ,

      { "class": "org.postgresql.jdbc.PgPreparedStatement", "method": "executeBatch", "line": 1739 }

      ,

      { "class": "software.amazon.jdbc.wrapper.PreparedStatementWrapper", "method": "lambda$executeBatch$13", "line": 208 }

      ,

      { "class": "software.amazon.jdbc.plugin.DefaultConnectionPlugin", "method": "execute", "line": 128 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$execute$5", "line": 348 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$null$0", "line": 270 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "executeWithTelemetry", "line": 246 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$makePluginChainFunc$1", "line": 270 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$null$2", "line": 280 }

      ,

      { "class": "software.amazon.jdbc.plugin.efm2.HostMonitoringConnectionPlugin", "method": "execute", "line": 177 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$execute$5", "line": 348 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$null$3", "line": 278 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "executeWithTelemetry", "line": 246 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$makePluginChainFunc$4", "line": 277 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$null$2", "line": 280 }

      ,

      { "class": "software.amazon.jdbc.plugin.failover.FailoverConnectionPlugin", "method": "execute", "line": 264 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$execute$5", "line": 348 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$null$3", "line": 278 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "executeWithTelemetry", "line": 246 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$makePluginChainFunc$4", "line": 277 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$null$2", "line": 280 }

      ,

      { "class": "software.amazon.jdbc.plugin.AuroraConnectionTrackerPlugin", "method": "execute", "line": 138 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$execute$5", "line": 348 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$null$3", "line": 278 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "executeWithTelemetry", "line": 246 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "lambda$makePluginChainFunc$4", "line": 277 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "executeWithSubscribedPlugins", "line": 236 }

      ,

      { "class": "software.amazon.jdbc.ConnectionPluginManager", "method": "execute", "line": 345 }

      ,

      { "class": "software.amazon.jdbc.util.WrapperUtils", "method": "executeWithPlugins", "line": 244 }

      ,

      { "class": "software.amazon.jdbc.wrapper.PreparedStatementWrapper", "method": "executeBatch", "line": 202 }

      ,

      { "class": "io.agroal.pool.wrapper.StatementWrapper", "method": "executeBatch", "line": 340 }

      ,

      { "class": "org.hibernate.engine.jdbc.batch.internal.BatchImpl", "method": "lambda$performExecution$2", "line": 279 }

      ,

      { "class": "org.hibernate.engine.jdbc.mutation.internal.PreparedStatementGroupSingleTable", "method": "forEachStatement", "line": 67 }

      ,

      { "class": "org.hibernate.engine.jdbc.batch.internal.BatchImpl", "method": "performExecution", "line": 264 }

      ,

      { "class": "org.hibernate.engine.jdbc.batch.internal.BatchImpl", "method": "execute", "line": 242 }

      ,

      { "class": "org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl", "method": "executeBatch", "line": 188 }

      ,

      { "class": "org.hibernate.engine.spi.ActionQueue", "method": "executeActions", "line": 674 }

      ,

      { "class": "org.hibernate.engine.spi.ActionQueue", "method": "executeActions", "line": 511 }

      ,

      { "class": "org.hibernate.event.internal.AbstractFlushingEventListener", "method": "performExecutions", "line": 414 }

      ,

      { "class": "org.hibernate.event.internal.DefaultFlushEventListener", "method": "onFlush", "line": 41 }

      ,

      { "class": "org.hibernate.event.service.internal.EventListenerGroupImpl", "method": "fireEventOnEachListener", "line": 127 }

      ,

      { "class": "org.hibernate.internal.SessionImpl", "method": "doFlush", "line": 1429 }

      ,

      { "class": "org.hibernate.internal.SessionImpl", "method": "managedFlush", "line": 491 }

      ,

      { "class": "org.hibernate.internal.SessionImpl", "method": "flushBeforeTransactionCompletion", "line": 2354 }

      ,

      { "class": "org.hibernate.internal.SessionImpl", "method": "beforeTransactionCompletion", "line": 1978 }

      ,

      { "class": "org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl", "method": "beforeTransactionCompletion", "line": 439 }

      ,

      { "class": "org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl", "method": "beforeCompletion", "line": 336 }

      ,

      { "class": "org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorNonTrackingImpl", "method": "beforeCompletion", "line": 47 }

      ,

      { "class": "org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization", "method": "beforeCompletion", "line": 37 }

      ,

      { "class": "com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple", "method": "beforeCompletion", "line": 52 }

      ,

      { "class": "com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator", "method": "beforeCompletion", "line": 348 }

      ,

      { "class": "com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator", "method": "end", "line": 66 }

      ,

      { "class": "com.arjuna.ats.arjuna.AtomicAction", "method": "commit", "line": 135 }

      ,

      { "class": "com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple", "method": "commitAndDisassociate", "line": 1307 }

      ,

      { "class": "com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction", "method": "commit", "line": 104 }

      ,

      { "class": "io.quarkus.narayana.jta.runtime.NotifyingTransactionManager", "method": "commit", "line": 70 }

      ,

      { "class": "org.keycloak.transaction.JtaTransactionWrapper", "method": "commit", "line": 102 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakTransactionManager", "method": "lambda$commitWithTracing$0", "line": 169 }

      ,

      { "class": "org.keycloak.tracing.NoopTracingProvider", "method": "trace", "line": 59 }

      ,

      { "class": "org.keycloak.tracing.NoopTracingProvider", "method": "trace", "line": 69 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakTransactionManager", "method": "commitWithTracing", "line": 168 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakTransactionManager", "method": "commit", "line": 136 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakSession", "method": "closeTransactionManager", "line": 396 }

      ,

      { "class": "org.keycloak.services.DefaultKeycloakSession", "method": "close", "line": 361 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "runJobInTransactionWithResult", "line": 467 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "runJobInTransaction", "line": 340 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "runJobInTransaction", "line": 330 }

      ,

      { "class": "org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker", "method": "lambda$process$4", "line": 125 }

      ,

      { "class": "java.util.ArrayList", "method": "forEach", "line": 1596 }

      ,

      { "class": "org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker", "method": "lambda$process$5", "line": 123 }

      ,

      { "class": "org.keycloak.common.util.Retry", "method": "executeWithBackoff", "line": 102 }

      ,

      { "class": "org.keycloak.common.util.Retry", "method": "executeWithBackoff", "line": 93 }

      ,

      { "class": "org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker", "method": "lambda$process$7", "line": 113 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "lambda$runJobInTransaction$1", "line": 341 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "runJobInTransactionWithResult", "line": 460 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "runJobInTransaction", "line": 340 }

      ,

      { "class": "org.keycloak.models.utils.KeycloakModelUtils", "method": "runJobInTransaction", "line": 330 }

      ,

      { "class": "org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker", "method": "process", "line": 97 }

      ,

      { "class": "org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker", "method": "run", "line": 76 }

      ]
      }
      }
      }
      ]
      }

      }
      

      Version

      26.2.4

      Regression

      [ ] The issue is a regression

      Expected behavior

      I would not expect the exception to occur such frequently and it should allow tracing the session update causing the issue better

      Actual behavior

      We get about 3-10 of this exception every day for the past 5 month (since v26 upgrade)

      How to Reproduce?

      I guess running a large enough instance with concurrent requests would trigger it?

      Anything else?

      No response

              Unassigned Unassigned
              pvlha Pavel Vlha
              Keycloak Core (shared)
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Created:
                Updated:
                Resolved: