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

PersistentSessionsWorker: Cannot access delegate without a transaction [GHI#36332]

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

      ldap

      Describe the bug

      Hello,

      Since enabling persistent user sessions, our app sometimes gets a 500 at the token step of an OIDC login.
      We detect this most often in our test system during the first login of a federated user: I don't think we ever managed to reproduce it afterwards.

      This only happens if the PERSISTENT_USER_SESSIONS feature is enabled, so we started getting this error with KC 26.0.x. I do not know if this happens with KC 25, so unsure if this is a regression.

      The Keycloak log is as follows at the time of error:
      ```
      2025-01-06 08:38:04,808 WARN [io.agroal.pool] (org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker) Datasource '<default>': JDBC resources leaked: 1 ResultSet(s) and 1 Statement(s)
      2025-01-06 08:38:04,808 WARN [io.agroal.pool] (org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker) Datasource '<default>': JDBC resources leaked: 1 ResultSet(s) and 1 Statement(s)
      2025-01-06 08:38:14,802 WARN [org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker] (org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker) Running single changes in iteration 2 for 1 entries

          • Last 2 lines repeated with incrementing counter
            2025-01-06 08:38:04,814 WARN [io.agroal.pool] (org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker) Datasource '<default>': JDBC resources leaked: 1 ResultSet(s) and 1 Statement(s)
            2025-01-06 08:38:14,802 WARN [org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker] (org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker) Running single changes in iteration 13597 for 1 entries
            2025-01-06 08:38:14,802 WARN [io.agroal.pool] (org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker) Datasource '<default>': JDBC resources leaked: 1 ResultSet(s) and 1 Statement(s)
            2025-01-06 08:38:14,803 WARN [org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker] (org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker) Unable to write 1 deferred session updates: java.lang.RuntimeException: unable to complete some changes
                at org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker.lambda$process$3(PersistentSessionsWorker.java:108)
                at org.keycloak.common.util.Retry.executeWithBackoff(Retry.java:102)
                at org.keycloak.common.util.Retry.executeWithBackoff(Retry.java:93)
                at org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker.process(PersistentSessionsWorker.java:86)
                at org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker.run(PersistentSessionsWorker.java:69)
                Suppressed: java.lang.IllegalStateException: Cannot access delegate without a transaction
                        at org.keycloak.models.cache.infinispan.RealmCacheSession.getClientDelegate(RealmCacheSession.java:199)
                        at org.keycloak.models.cache.infinispan.RealmCacheSession.getClientById(RealmCacheSession.java:1214)
                        at org.keycloak.models.cache.infinispan.RealmAdapter.getClientById(RealmAdapter.java:853)
                        at org.keycloak.models.jpa.session.JpaUserSessionPersisterProvider.toAdapter(JpaUserSessionPersisterProvider.java:669)
                        at org.keycloak.models.jpa.session.JpaUserSessionPersisterProvider.lambda$loadClientSession$6(JpaUserSessionPersisterProvider.java:469)
                        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
                        at java.base/java.util.Spliterators$IteratorSpliterator.tryAdvance(Spliterators.java:1856)
                        at java.base/java.util.stream.ReferencePipeline.forEachWithCancel(ReferencePipeline.java:129)
                        at java.base/java.util.stream.AbstractPipeline.copyIntoWithCancel(AbstractPipeline.java:527)
                        at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:513)
                        at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
                        at java.base/java.util.stream.FindOps$FindOp.evaluateSequential(FindOps.java:150)
                        at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
                        at java.base/java.util.stream.ReferencePipeline.findFirst(ReferencePipeline.java:647)
                        at org.keycloak.utils.ClosingStream.findFirst(ClosingStream.java:231)
                        at org.keycloak.models.jpa.session.JpaUserSessionPersisterProvider.loadClientSession(JpaUserSessionPersisterProvider.java:470)
                        at org.keycloak.models.sessions.infinispan.changes.JpaChangesPerformer.processClientSessionUpdate(JpaChangesPerformer.java:263)
                        at org.keycloak.models.sessions.infinispan.changes.JpaChangesPerformer.processClientSessionUpdate(JpaChangesPerformer.java:263)
                        at org.keycloak.models.sessions.infinispan.changes.JpaChangesPerformer.lambda$registerChange$0(JpaChangesPerformer.java:72)
                        at org.keycloak.models.sessions.infinispan.changes.PersistentUpdate.perform(PersistentUpdate.java:40)
                        at org.keycloak.models.utils.KeycloakModelUtils.lambda$runJobInTransaction$1(KeycloakModelUtils.java:313)
                        at org.keycloak.models.utils.KeycloakModelUtils.runJobInTransactionWithResult(KeycloakModelUtils.java:432)
                        at org.keycloak.models.utils.KeycloakModelUtils.runJobInTransaction(KeycloakModelUtils.java:312)
                        at org.keycloak.models.utils.KeycloakModelUtils.runJobInTransaction(KeycloakModelUtils.java:302)
                        at org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker.lambda$process$2(PersistentSessionsWorker.java:98)
                        at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
                        at org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker.lambda$process$3(PersistentSessionsWorker.java:96)
                        ... 4 more
            

            2025-01-06 08:38:14,848 ERROR [org.keycloak.services.error.KeycloakErrorHandler] (executor-thread-64) Uncaught server error: java.lang.RuntimeException: unable to complete the session updates

                at org.keycloak.models.sessions.infinispan.changes.JpaChangesPerformer.applyChanges(JpaChangesPerformer.java:112)
                at java.base/java.lang.Iterable.forEach(Iterable.java:75)
                at org.keycloak.models.sessions.infinispan.changes.PersistentSessionsChangelogBasedTransaction.commitImpl(PersistentSessionsChangelogBasedTransaction.java:219)
                at org.keycloak.models.AbstractKeycloakTransaction.commit(AbstractKeycloakTransaction.java:46)
                at org.keycloak.services.DefaultKeycloakTransactionManager.commit(DefaultKeycloakTransactionManager.java:146)
                at org.keycloak.services.DefaultKeycloakSession.closeTransactionManager(DefaultKeycloakSession.java:396)
                at org.keycloak.services.DefaultKeycloakSession.close(DefaultKeycloakSession.java:361)
                at org.keycloak.models.KeycloakBeanProducer_ProducerMethod_getKeycloakSession_XoSEUTXOsE3bpqXlGMAykCiECUM_ClientProxy.close(Unknown Source)
                at org.keycloak.quarkus.runtime.transaction.TransactionalSessionHandler.close(TransactionalSessionHandler.java:60)
                at org.keycloak.quarkus.runtime.integration.jaxrs.CloseSessionFilter.closeSession(CloseSessionFilter.java:67)
                at org.keycloak.quarkus.runtime.integration.jaxrs.CloseSessionFilter.filter(CloseSessionFilter.java:63)
                at org.jboss.resteasy.reactive.server.handlers.ResourceResponseFilterHandler.handle(ResourceResponseFilterHandler.java:25)
                at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:150)
                at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
                at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:635)
                at org.jboss.threads.EnhancedQueueExecutor$Task.doRunWith(EnhancedQueueExecutor.java:2516)
                at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2495)
                at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1521)
                at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:11)
                at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:11)
                at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
                at java.base/java.lang.Thread.run(Thread.java:840)
                Suppressed: java.lang.RuntimeException: unable to complete some changes
                        at org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker.lambda$process$3(PersistentSessionsWorker.java:108)
                        at org.keycloak.common.util.Retry.executeWithBackoff(Retry.java:102)
                        at org.keycloak.common.util.Retry.executeWithBackoff(Retry.java:93)
                        at org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker.process(PersistentSessionsWorker.java:86)
                        at org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker.run(PersistentSessionsWorker.java:69)
                        Suppressed: java.lang.IllegalStateException: Cannot access delegate without a transaction
                                at org.keycloak.models.cache.infinispan.RealmCacheSession.getClientDelegate(RealmCacheSession.java:199)
                                at org.keycloak.models.cache.infinispan.RealmCacheSession.getClientById(RealmCacheSession.java:1214)
                                at org.keycloak.models.cache.infinispan.RealmAdapter.getClientById(RealmAdapter.java:853)
                                at org.keycloak.models.jpa.session.JpaUserSessionPersisterProvider.toAdapter(JpaUserSessionPersisterProvider.java:669)
                                at org.keycloak.models.jpa.session.JpaUserSessionPersisterProvider.lambda$loadClientSession$6(JpaUserSessionPersisterProvider.java:469)
                                at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
                                at java.base/java.util.Spliterators$IteratorSpliterator.tryAdvance(Spliterators.java:1856)
                                at java.base/java.util.stream.ReferencePipeline.forEachWithCancel(ReferencePipeline.java:129)
                                at java.base/java.util.stream.AbstractPipeline.copyIntoWithCancel(AbstractPipeline.java:527)
                                at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:513)
                                at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
                                at java.base/java.util.stream.FindOps$FindOp.evaluateSequential(FindOps.java:150)
                                at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
                                at java.base/java.util.stream.ReferencePipeline.findFirst(ReferencePipeline.java:647)
                                at org.keycloak.utils.ClosingStream.findFirst(ClosingStream.java:231)
                                at org.keycloak.models.jpa.session.JpaUserSessionPersisterProvider.loadClientSession(JpaUserSessionPersisterProvider.java:470)
                                at org.keycloak.models.sessions.infinispan.changes.JpaChangesPerformer.processClientSessionUpdate(JpaChangesPerformer.java:263)
                                at org.keycloak.models.sessions.infinispan.changes.JpaChangesPerformer.lambda$registerChange$0(JpaChangesPerformer.java:72)
                                at org.keycloak.models.sessions.infinispan.changes.PersistentUpdate.perform(PersistentUpdate.java:40)
                                at org.keycloak.models.utils.KeycloakModelUtils.lambda$runJobInTransaction$1(KeycloakModelUtils.java:313)
                                at org.keycloak.models.utils.KeycloakModelUtils.runJobInTransactionWithResult(KeycloakModelUtils.java:432)
                                at org.keycloak.models.utils.KeycloakModelUtils.runJobInTransaction(KeycloakModelUtils.java:312)
                                at org.keycloak.models.utils.KeycloakModelUtils.runJobInTransaction(KeycloakModelUtils.java:302)
                                at org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker.lambda$process$2(PersistentSessionsWorker.java:98)
                                at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
                                at org.keycloak.models.sessions.infinispan.changes.PersistentSessionsWorker$BatchWorker.lambda$process$3(PersistentSessionsWorker.java:96)
                                ... 4 more
            

            ```

      I realise this report is a bit scarce, but maybe the stacktrace would help understand what the cause of this error problem is?

      Version

      26.0.7

      Regression

      [ ] The issue is a regression

      Expected behavior

      Successful LDAP user login

      Actual behavior

      Login fails, because the protocol/openid-connect/token endpoint returns 500.
      The user can login by simply running the OIDC flow again: they will immediately be logged in without the need to input their user name and password.

      How to Reproduce?

      Ensure the PERSISTENT_USER_SESSIONS feature is enabled.
      Most successful to reproduce for the first login of a federated user.
      Might be easier to reproduce when the hardware specs are a bit low (i.e. 1 KC instance on a small machine), but we've seen it once on a bigger system too (with multiple KC instances and good hardware specs).

      Anything else?

      No response

              Unassigned Unassigned
              pvlha Pavel Vlha
              Keycloak SRE
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Created:
                Updated:
                Resolved: