Login error with Ondemand 1.8 and Keycloak 10

danielfr · May 21, 2021, 3:33pm

Hello,

I am testing the upgrade from 1.7 to 1.8.
For configuring the node I am using https://github.com/OSC/puppet-module-openondemand/blob/v1.5.0/ (latest version compatible with 1.8.X).

And this is my yaml configuration related to OIDC:

openondemand::oidc_client_id: 'openondemand-dev'
openondemand::oidc_client_secret: 'secret'
openondemand::ondemand_package_ensure: '1.8.20-1.el7'
openondemand::mod_auth_openidc_ensure: "2.4.4.1-1.el7"
openondemand::repo_release: '1.8'
openondemand::oidc_remote_user_claim: 'preferred_username'
openondemand::oidc_uri: '/oidc'
openondemand::user_map_match: '.*'
openondemand::oidc_provider_metadata_url: 'https://keycloak.server/auth/realms/BBP/.well-known/openid-configuration'
openondemand::oidc_settings:
  OIDCPassIDTokenAs: 'serialized'
  OIDCPassRefreshToken: 'On'
  OIDCPassClaimsAs: environment
  OIDCStripCookies: 'mod_auth_openidc_session mod_auth_openidc_session_chunks mod_auth_openidc_session_0 mod_auth_openidc_session_1'

Puppet ran with no issues and ondemand1.8 is running perfectly BUT if I don’t have a valid token when accesing the site, keycloak crashes with the following trace:

May 21 16:51:07 keycloak.server standalone.sh[26316]: 16:51:07,468 WARN  [org.keycloak.services] (default task-214) KC-SERVICES0013: Failed authentication: org.keycloak.storage.ReadOnlyException
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.models.utils.ReadOnlyUserModelDelegate.addRequiredAction(ReadOnlyUserModelDelegate.java:62)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.models.utils.UserModelDelegate.addRequiredAction(UserModelDelegate.java:104)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.models.utils.UserModelDelegate.addRequiredAction(UserModelDelegate.java:104)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.models.utils.UserModelDelegate.addRequiredAction(UserModelDelegate.java:104)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.models.cache.infinispan.UserAdapter.addRequiredAction(UserAdapter.java:196)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.authentication.authenticators.browser.OTPFormAuthenticator.setRequiredActions(OTPFormAuthenticator.java:133)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.authentication.DefaultAuthenticationFlow.processSingleFlowExecutionModel(DefaultAuthenticationFlow.java:430)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.authentication.DefaultAuthenticationFlow.processFlow(DefaultAuthenticationFlow.java:247)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.authentication.DefaultAuthenticationFlow.processSingleFlowExecutionModel(DefaultAuthenticationFlow.java:381)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.authentication.DefaultAuthenticationFlow.processFlow(DefaultAuthenticationFlow.java:247)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.authentication.DefaultAuthenticationFlow.processSingleFlowExecutionModel(DefaultAuthenticationFlow.java:381)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.authentication.DefaultAuthenticationFlow.continueAuthenticationAfterSuccessfulAction(DefaultAuthenticationFlow.java:180)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.authentication.DefaultAuthenticationFlow.processAction(DefaultAuthenticationFlow.java:158)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.authentication.AuthenticationProcessor.authenticationAction(AuthenticationProcessor.java:936)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.services.resources.LoginActionsService.processFlow(LoginActionsService.java:311)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.services.resources.LoginActionsService.processAuthentication(LoginActionsService.java:282)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.services.resources.LoginActionsService.authenticate(LoginActionsService.java:266)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.services.resources.LoginActionsService.authenticateForm(LoginActionsService.java:339)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at sun.reflect.GeneratedMethodAccessor575.invoke(Unknown Source)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at java.lang.reflect.Method.invoke(Method.java:498)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:138)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:535)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:424)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:385)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:356)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:387)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:356)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:150)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:104)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:440)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:229)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:135)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:356)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:138)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:215)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:227)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at javax.servlet.http.HttpServlet.service(HttpServlet.java:590)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.keycloak.services.filters.KeycloakSessionServletFilter.doFilter(KeycloakSessionServletFilter.java:91)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:132)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:269)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:78)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:133)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:130)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1541)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1541)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1541)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1541)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:249)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:78)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:99)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.server.Connectors.executeRootHandler(Connectors.java:370)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1982)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
May 21 16:51:07 keycloak.server standalone.sh[26316]: at java.lang.Thread.run(Thread.java:748)

And error=invalid_user_credentials:

May 21 16:51:07 keycloak.server standalone.sh[26316]: 16:51:07,478 WARN  [org.keycloak.events] (default task-214) type=LOGIN_ERROR, realmId=BBP, clientId=openondemand-dev, userId=null, ipAddress=XXX.YYY.255.29, error=invalid_user_credentials, auth_method=openid-connect, auth_type=code, redirect_uri=https://ondemand.server/oidc, code_id=73d3673f-e67f-4029-8b4c-50a2054707f2, username=danielfr, authSessionParentId=73d3673f-e67f-4029-8b4c-50a2054707f2, authSessionTabId=bRgTTXiblwU

On the other hand, If I have a valid OIDC session already, I can access ondemand 1.8 and use it with no issues. The problem is at login.

I am using keycloak 10.0.2, might this be a problem realted to this old version of Keycloak??

Same OIDC client/keycloak configuration was working fine with Ondemand 1.7.

Thank you very much,
Daniel.

jeff.ohrstrom · May 21, 2021, 7:42pm

Yea I’m not entirely sure what’s going on here. We shipped the same version of mod_auth_openidc in 1.7 and 1.8 (I just checked the yum repos)

I don’t know enough about keycloak, but I’d hone in on the error type org.keycloak.storage.ReadOnly. Did you happen to change the client id or secret? Or maybe you need to bounce it?

@tdockendorf do you have any insight into what’s going on here?

tdockendorf · May 21, 2021, 8:34pm

If I had to guess, something with your user mapping and user lookups in Keycloak is broken. I would log into Keycloak and assuming your user provider is LDAP, try the LDAP test section in the LDAP config to see if you can authenticate as yourself against the LDAP server configured.

I think the big clue is the log entry having “error=invalid_user_credentials”, it looks like Keycloak is unable to authenticate the user against your user database. For OSC we use LDAP in readonly mode so when someone logs in the authenticating password they provide is used to authenticate and bind to LDAP and that’s how someone is authenticated.

If this was some misconfiguration between OnDemand and Keycloak I would see other issues like invalid ClientID or ClientSecret which would produce different messages, or if the token had expired you’d see a message like this I believe:

2021-05-21 16:24:47,782 WARN [org.keycloak.events] (default task-16342) type=LOGIN_ERROR, realmId=osc, clientId=null, userId=null, ipAddress=OMIT, error=expired_code, restart_after_timeout=true, authSessionParentId=08da0f43-316c-4b56-bdea-a765f216aa23, authSessionTabId=GqLTK22GxZc

danielfr · May 25, 2021, 1:53pm

Hi,

my bad. I had a broken “Authentication Flow Overrides” configured for the ondemand dev client.
Sorry for wasting your time. There is no issue with ondemand 1.8 and keycloak 10 at all.

Thanks a lot,
Daniel.

Topic		Replies	Views
Ondemand + keycloak + RHEL8 issues Get Help question	4	286	January 30, 2023
Ondemand with dedicated keycloak server Get Help	3	737	May 26, 2022
OIDC redirect failing Get Help question	14	3936	May 26, 2022
OnDemand-Keycloak-IDM authentication Get Help	4	1119	May 26, 2022
For Ondemand 1.8 should I switch from Keycloak as my IDP to OnDemand-Dex? Get Help	3	763	May 19, 2022

Login error with Ondemand 1.8 and Keycloak 10

Related Topics