Hi team,
I'm very new to Keycloak. My Keycloak server (24.0.0) is running on the following infrastructure. I experience the same behaviour with version 25 as well.
Keycloak: Running on AWS ECS Fargate instance
Keycloak Database: RDS Aurora Serverless Postgres
I have federated LDAP with Keycloak, and it works fine most of the time. However, randomly, I encounter the following error when a user tries to log in or refresh the page once logged in. But, if refresh it again, it works fine. It's a very strange problem. Please see the logs below and screenshots (I have included the screenshot of the Flow as well).
What could be the root cause?
05 July 2024 at 10:56 (UTC+1:00) 2024-07-05 09:56:35,577 ERROR [org.keycloak.services.error.KeycloakErrorHandler] (executor-thread-432) Uncaught server error: org.keycloak.models.ModelException: LDAP Query failed
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.query.internal.LDAPQuery.getResultList(LDAPQuery.java:178)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.query.internal.LDAPQuery.getFirstResult(LDAPQuery.java:185)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.LDAPStorageProvider.loadLDAPUserByUsername(LDAPStorageProvider.java:1005)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.LDAPStorageProvider.getUserByUsername(LDAPStorageProvider.java:639)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.LDAPStorageProvider.getUserById(LDAPStorageProvider.java:366)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.UserStorageManager.getUserById(UserStorageManager.java:375)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.models.cache.infinispan.UserCacheSession.getUserById(UserCacheSession.java:218)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.models.sessions.infinispan.InfinispanUserSessionProvider.wrap(InfinispanUserSessionProvider.java:779)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.models.sessions.infinispan.InfinispanUserSessionProvider.getUserSession(InfinispanUserSessionProvider.java:277)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.models.sessions.infinispan.InfinispanUserSessionProvider.getUserSession(InfinispanUserSessionProvider.java:270)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.managers.AuthenticationManager.verifyIdentityToken(AuthenticationManager.java:1411)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.managers.AuthenticationManager.authenticateIdentityCookie(AuthenticationManager.java:859)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.managers.AuthenticationManager.authenticateIdentityCookie(AuthenticationManager.java:849)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.managers.AppAuthManager.authenticateIdentityCookie(AppAuthManager.java:43)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountConsole.init(AccountConsole.java:79)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountConsole.<init>(AccountConsole.java:75)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountConsoleFactory.create(AccountConsoleFactory.java:28)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountConsoleFactory.create(AccountConsoleFactory.java:16)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.DefaultKeycloakSession.getProvider(DefaultKeycloakSession.java:177)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.models.KeycloakBeanProducer_ProducerMethod_getKeycloakSession_XoSEUTXOsE3bpqXlGMAykCiECUM_ClientProxy.getProvider(Unknown Source)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountLoader.getAccountResourceProvider(AccountLoader.java:171)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountLoader.getAccountService(AccountLoader.java:85)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountLoader$quarkusrestinvoker$getAccountService_265aa1aaf86cc2a5ca4d1c819f2a826c7dc11dc0.invoke(Unknown Source)
05 July 2024 at 10:56 (UTC+1:00) at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
05 July 2024 at 10:56 (UTC+1:00) at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
05 July 2024 at 10:56 (UTC+1:00) at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
05 July 2024 at 10:56 (UTC+1:00) at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582)
05 July 2024 at 10:56 (UTC+1:00) at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
05 July 2024 at 10:56 (UTC+1:00) at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1512)
05 July 2024 at 10:56 (UTC+1:00) at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
05 July 2024 at 10:56 (UTC+1:00) at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
05 July 2024 at 10:56 (UTC+1:00) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
05 July 2024 at 10:56 (UTC+1:00) at java.base/java.lang.Thread.run(Thread.java:840)
05 July 2024 at 10:56 (UTC+1:00) Caused by: org.keycloak.models.ModelException: Querying of LDAP failed org.keycloak.storage.ldap.idm.query.internal.LDAPQuery@1492af9b
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPIdentityStore.fetchQueryResults(LDAPIdentityStore.java:295)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.query.internal.LDAPQuery.getResultList(LDAPQuery.java:174)
05 July 2024 at 10:56 (UTC+1:00) Caused by: javax.naming.NamingException: LDAP connection has been closed; remaining name 'ou=accounts,dc=example,dc=org'
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.LdapRequest.getReplyBer(LdapRequest.java:133)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.Connection.readReply(Connection.java:442)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.LdapClient.getSearchReply(LdapClient.java:639)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.LdapClient.search(LdapClient.java:562)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.LdapCtx.doSearch(LdapCtx.java:2014)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.LdapCtx.searchAux(LdapCtx.java:1873)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1798)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.toolkit.ctx.ComponentDirContext.p_search(ComponentDirContext.java:392)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:358)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/javax.naming.directory.InitialDirContext.search(InitialDirContext.java:305)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager$3.execute(LDAPOperationManager.java:258)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager$3.execute(LDAPOperationManager.java:255)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager.execute(LDAPOperationManager.java:721)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager.execute(LDAPOperationManager.java:701)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager.execute(LDAPOperationManager.java:696)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager.search(LDAPOperationManager.java:255)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPIdentityStore.fetchQueryResults(LDAPIdentityStore.java:279)
05 July 2024 at 10:56 (UTC+1:00) 2024-07-05 09:56:35,571 ERROR [org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager] (executor-thread-432) Could not query server using DN [ou=accounts,dc=example,dc=org] and filter [(&(cn=firstname...@example.org)(objectclass=inetOrgPerson)(objectclass=organizationalPerson))]: javax.naming.NamingException: LDAP connection has been closed; remaining name 'ou=accounts,dc=example,dc=org'
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.LdapRequest.getReplyBer(LdapRequest.java:133)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.Connection.readReply(Connection.java:442)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.LdapClient.getSearchReply(LdapClient.java:639)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.LdapClient.search(LdapClient.java:562)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.LdapCtx.doSearch(LdapCtx.java:2014)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.LdapCtx.searchAux(LdapCtx.java:1873)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1798)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.toolkit.ctx.ComponentDirContext.p_search(ComponentDirContext.java:392)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:358)
05 July 2024 at 10:56 (UTC+1:00) at java.naming/javax.naming.directory.InitialDirContext.search(InitialDirContext.java:305)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager$3.execute(LDAPOperationManager.java:258)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager$3.execute(LDAPOperationManager.java:255)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager.execute(LDAPOperationManager.java:721)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager.execute(LDAPOperationManager.java:701)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager.execute(LDAPOperationManager.java:696)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager.search(LDAPOperationManager.java:255)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.store.ldap.LDAPIdentityStore.fetchQueryResults(LDAPIdentityStore.java:279)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.query.internal.LDAPQuery.getResultList(LDAPQuery.java:174)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.idm.query.internal.LDAPQuery.getFirstResult(LDAPQuery.java:185)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.LDAPStorageProvider.loadLDAPUserByUsername(LDAPStorageProvider.java:1005)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.LDAPStorageProvider.getUserByUsername(LDAPStorageProvider.java:639)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.ldap.LDAPStorageProvider.getUserById(LDAPStorageProvider.java:366)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.storage.UserStorageManager.getUserById(UserStorageManager.java:375)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.models.cache.infinispan.UserCacheSession.getUserById(UserCacheSession.java:218)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.models.sessions.infinispan.InfinispanUserSessionProvider.wrap(InfinispanUserSessionProvider.java:779)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.models.sessions.infinispan.InfinispanUserSessionProvider.getUserSession(InfinispanUserSessionProvider.java:277)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.models.sessions.infinispan.InfinispanUserSessionProvider.getUserSession(InfinispanUserSessionProvider.java:270)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.managers.AuthenticationManager.verifyIdentityToken(AuthenticationManager.java:1411)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.managers.AuthenticationManager.authenticateIdentityCookie(AuthenticationManager.java:859)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.managers.AuthenticationManager.authenticateIdentityCookie(AuthenticationManager.java:849)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.managers.AppAuthManager.authenticateIdentityCookie(AppAuthManager.java:43)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountConsole.init(AccountConsole.java:79)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountConsole.<init>(AccountConsole.java:75)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountConsoleFactory.create(AccountConsoleFactory.java:28)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountConsoleFactory.create(AccountConsoleFactory.java:16)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.DefaultKeycloakSession.getProvider(DefaultKeycloakSession.java:177)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.models.KeycloakBeanProducer_ProducerMethod_getKeycloakSession_XoSEUTXOsE3bpqXlGMAykCiECUM_ClientProxy.getProvider(Unknown Source)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountLoader.getAccountResourceProvider(AccountLoader.java:171)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountLoader.getAccountService(AccountLoader.java:85)
05 July 2024 at 10:56 (UTC+1:00) at org.keycloak.services.resources.account.AccountLoader$quarkusrestinvoker$getAccountService_265aa1aaf86cc2a5ca4d1c819f2a826c7dc11dc0.invoke(Unknown Source)
05 July 2024 at 10:56 (UTC+1:00) at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
05 July 2024 at 10:56 (UTC+1:00) at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
05 July 2024 at 10:56 (UTC+1:00) at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
05 July 2024 at 10:56 (UTC+1:00) at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582)
05 July 2024 at 10:56 (UTC+1:00) at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
05 July 2024 at 10:56 (UTC+1:00) at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1512)
05 July 2024 at 10:56 (UTC+1:00) at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
05 July 2024 at 10:56 (UTC+1:00) at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
05 July 2024 at 10:56 (UTC+1:00) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
05 July 2024 at 10:56 (UTC+1:00) at java.base/java.lang.Thread.run(Thread.java:840)
Kind regards,
Prasanth Nair