[keycloak-user] keycloak 4.8.3 ReadOnlyException on new SAML client with ldap federation

[Iain Steers]

Hey folks,

We upgraded to keycloak 4.8.3 fairly recently. We were on version 4.2.1.

All existing SAML and OAuth clients work as expected and there are no
issues signing into them.

However, we just created a new SAML client and don't seem to be able to
successfully complete the auth process. With the vague error message:
“Unexpected error when handling authentication request to identity provider”
Digging into the logs I found a stacktrace[1]. This occurs on login
attempts with this new client.
Our User Federation backend is a read-only ldap. Some searching of the
jboss jira and web didn't find much related to this. Any help would be
appreciated.

This is reproducible for us across two separate instances of keycloak
backed by separate ldap backends.

Thanks,

Iain

[1]
May 07 20:01:05 keycloak-01 standalone.sh[947]: 20:01:05,600 DEBUG
[org.keycloak.services.managers.AuthenticationManager] (default task-733)
Expiring cookie: KEYCLOAK_REMEMBER_ME path: /auth/realms/washington/
May 07 20:01:05 keycloak-01 standalone.sh[947]: 20:01:05,600 WARN
[org.keycloak.services] (default task-733) KC-SERVICES0013: Failed
authentication: org.keycloak.storage.ReadOnlyException
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.models.utils.ReadOnlyUserModelDelegate.setSingleAttribute(ReadOnlyUserModelDelegate.java:48)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.models.utils.UserModelDelegate.setSingleAttribute(UserModelDelegate.java:69)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.models.utils.UserModelDelegate.setSingleAttribute(UserModelDelegate.java:69)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.models.utils.UserModelDelegate.setSingleAttribute(UserModelDelegate.java:69)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.models.utils.UserModelDelegate.setSingleAttribute(UserModelDelegate.java:69)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.models.utils.UserModelDelegate.setSingleAttribute(UserModelDelegate.java:69)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.models.cache.infinispan.UserAdapter.setSingleAttribute(UserAdapter.java:137)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.protocol.saml.SamlProtocol.getPersistentNameId(SamlProtocol.java:366)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.protocol.saml.SamlProtocol.getNameId(SamlProtocol.java:324)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.protocol.saml.SamlProtocol.authenticated(SamlProtocol.java:380)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.services.managers.AuthenticationManager.redirectAfterSuccessfulFlow(AuthenticationManager.java:790)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.services.managers.AuthenticationManager.redirectAfterSuccessfulFlow(AuthenticationManager.java:742)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.services.managers.AuthenticationManager.finishedRequiredActions(AuthenticationManager.java:876)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.authentication.AuthenticationProcessor.authenticationComplete(AuthenticationProcessor.java:1008)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.authentication.AuthenticationProcessor.authenticationAction(AuthenticationProcessor.java:878)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.services.resources.LoginActionsService.processFlow(LoginActionsService.java:292)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.services.resources.LoginActionsService.processAuthentication(LoginActionsService.java:263)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.services.resources.LoginActionsService.authenticate(LoginActionsService.java:259)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.services.resources.LoginActionsService.authenticateForm(LoginActionsService.java:320)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
sun.reflect.GeneratedMethodAccessor673.invoke(Unknown Source)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
java.lang.reflect.Method.invoke(Method.java:498)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:140)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:509)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:399)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:363)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:365)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:337)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:137)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:100)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:443)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:233)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:139)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:142)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:219)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:227)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
javax.servlet.http.HttpServlet.service(HttpServlet.java:791)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.keycloak.services.filters.KeycloakSessionServletFilter.doFilter(KeycloakSessionServletFilter.java:90)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:132)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
May 07 20:01:05 keycloak-01 standalone.sh[947]: at
java.lang.Thread.run(Thread.java:748)