[keycloak-user] trouble importing user from ldap when using broker feature

Marek Posolda mposolda at redhat.com
Fri Apr 26 04:08:54 EDT 2019 

In that case, I think you may need to switch realm option for Duplicate 
emails allowed, which is disabled by default. In that case, duplicate 
emails are not checked and also it is not pssible to login with email 
(as KC won;t know which user it should use in case there are multiple 
users with same email).

Marek


On 25/04/2019 20:32, Mizuki Karasawa wrote:
> Hi,
> I configured LDAP for user federation with Kerberos integrated, then I added external identify Providers via the broker feature.If a user was previously imported to local Keycloak db, the account linking process will work successfully while users login via external providers.However if the user was not imported to local keycloak db yet, following 'First Broker Login' auth flow, once users logged in via external provider and updated their profile, during 'Create User if Unique' stage (importing users), if the email address with the user associated with multiple accounts in LDAP, the importing will fail.
> As the symptom, the browser throws error ' We’re sorry...Unexpected error when handling authentication request to identity provider. '
> I'm attaching the debugging log as a reference at the bottom of this email as well.But in reality it's pretty common to have multiple accounts associated with the same email address (at least in our case), for example, some accounts there are for running programs/services but associated with particular person's email for convenience. I wonder if there is a work-around or some ways to configure and avoid this issue.  Does someone have the same experience and have advices on that?
>
> Ex, debugging log is attached (with the error portion high lighted)
>
> 2019-04-24 15:45:04,220 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new JtaTransactionWrapper
>
> 2019-04-24 15:45:04,220 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing? false
>
> 2019-04-24 15:45:04,220 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper  commit
>
> 2019-04-24 15:45:04,220 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper end
>
> 2019-04-24 15:45:04,220 DEBUG [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-2) Executed scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$776/1511347521
>
> 2019-04-24 15:45:09,220 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) new JtaTransactionWrapper
>
> 2019-04-24 15:45:09,221 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) was existing? false
>
> 2019-04-24 15:45:09,221 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper  commit
>
> 2019-04-24 15:45:09,221 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (Timer-2) JtaTransactionWrapper end
>
> 2019-04-24 15:45:09,221 DEBUG [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-2) Executed scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$776/1511347521
>
> 2019-04-24 15:45:12,488 DEBUG [io.undertow.request] (default I/O-7) Matched prefix path /auth for path /auth/realms/SDCC2/login-actions/first-broker-login
>
> 2019-04-24 15:45:12,488 DEBUG [io.undertow.request.security] (default task-260) Attempting to authenticate /auth/realms/SDCC2/login-actions/first-broker-login, authentication required: false
>
> 2019-04-24 15:45:12,488 DEBUG [io.undertow.request.security] (default task-260) Authentication outcome was NOT_ATTEMPTED with method io.undertow.security.impl.CachedAuthenticatedSessionMechanism at 6854b209 for /auth/realms/SDCC2/login-actions/first-broker-login
>
> 2019-04-24 15:45:12,488 DEBUG [io.undertow.request.security] (default task-260) Authentication result was ATTEMPTED for /auth/realms/SDCC2/login-actions/first-broker-login
>
> 2019-04-24 15:45:12,488 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-260) new JtaTransactionWrapper
>
> 2019-04-24 15:45:12,488 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (default task-260) was existing? false
>
> 2019-04-24 15:45:12,489 DEBUG [org.jboss.resteasy.resteasy_jaxrs.i18n] (default task-260) RESTEASY002315: PathInfo: /realms/SDCC2/login-actions/first-broker-login
>
> 2019-04-24 15:45:12,489 DEBUG [org.keycloak.services.resources.SessionCodeChecks] (default task-260) Will use client 'test2-oidc' in back-to-application link
>
> 2019-04-24 15:45:12,489 DEBUG [org.keycloak.services.util.CookieHelper] (default task-260) {1} cookie found in the requests header
>
> 2019-04-24 15:45:12,489 DEBUG [org.keycloak.services.util.CookieHelper] (default task-260) {1} cookie found in the cookies field
>
> 2019-04-24 15:45:12,489 DEBUG [org.keycloak.services.managers.AuthenticationSessionManager] (default task-260) Found AUTH_SESSION_ID cookie with value a1069878-5c31-41d6-9d29-9cfa61e6b806.mktst1
>
> 2019-04-24 15:45:12,490 DEBUG [org.keycloak.authentication.AuthenticationProcessor] (default task-260) authenticationAction
>
> 2019-04-24 15:45:12,491 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (default task-260) processAction: e3d20da0-9a2a-49ba-aeaf-c7503a648d67
>
> 2019-04-24 15:45:12,491 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (default task-260) check: idp-review-profile requirement: REQUIRED
>
> 2019-04-24 15:45:12,491 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (default task-260) action: idp-review-profile
>
> 2019-04-24 15:45:12,491 DEBUG [org.keycloak.authentication.authenticators.broker.IdpReviewProfileAuthenticator] (default task-260) Profile updated successfully after first authentication with identity provider 'CILogon' for broker user 'http://cilogon.org/serverA/users/2706181'.
>
> 2019-04-24 15:45:12,491 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (default task-260) authenticator SUCCESS: idp-review-profile
>
> 2019-04-24 15:45:12,491 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (default task-260) processFlow
>
> 2019-04-24 15:45:12,491 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (default task-260) check execution: idp-create-user-if-unique requirement: ALTERNATIVE
>
> 2019-04-24 15:45:12,491 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (default task-260) authenticator: idp-create-user-if-unique
>
> 2019-04-24 15:45:12,491 DEBUG [org.keycloak.authentication.DefaultAuthenticationFlow] (default task-260) invoke authenticator.authenticate: idp-create-user-if-unique
>
> 2019-04-24 15:45:12,492 DEBUG [org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl] (default task-260) Hibernate RegisteredSynchronization successfully registered with JTA platform
>
> 2019-04-24 15:45:12,492 DEBUG [org.hibernate.SQL] (default task-260)
>
>      select
>
>          userentity0_.ID as ID1_75_,
>
>          userentity0_.CREATED_TIMESTAMP as CREATED_2_75_,
>
>          userentity0_.EMAIL as EMAIL3_75_,
>
>          userentity0_.EMAIL_CONSTRAINT as EMAIL_CO4_75_,
>
>          userentity0_.EMAIL_VERIFIED as EMAIL_VE5_75_,
>
>          userentity0_.ENABLED as ENABLED6_75_,
>
>          userentity0_.FEDERATION_LINK as FEDERATI7_75_,
>
>          userentity0_.FIRST_NAME as FIRST_NA8_75_,
>
>          userentity0_.LAST_NAME as LAST_NAM9_75_,
>
>          userentity0_.NOT_BEFORE as NOT_BEF10_75_,
>
>          userentity0_.REALM_ID as REALM_I11_75_,
>
>          userentity0_.SERVICE_ACCOUNT_CLIENT_LINK as SERVICE12_75_,
>
>          userentity0_.USERNAME as USERNAM13_75_
>
>      from
>
>          USER_ENTITY userentity0_
>
>      where
>
>          userentity0_.EMAIL=?
>
>          and userentity0_.REALM_ID=?
>
> 2019-04-24 15:45:12,492 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default task-260) KeycloakDS: getConnection(null, WrappedConnectionRequestInfo at 1f75e0ca[userName=sa]) [0/20]
>
> 2019-04-24 15:45:12,492 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (default task-260) Initiating JDBC connection release from afterStatement
>
> 2019-04-24 15:45:12,503 WARN  [org.keycloak.services] (default task-260) KC-SERVICES0013: Failed authentication: org.keycloak.models.ModelDuplicateException: Error - multiple LDAP objects found but expected just one
>
>   at org.keycloak.storage.ldap.idm.query.internal.LDAPQuery.getFirstResult(LDAPQuery.java:189)
>
>   at org.keycloak.storage.ldap.LDAPStorageProvider.queryByEmail(LDAPStorageProvider.java:540)
>
>   at org.keycloak.storage.ldap.LDAPStorageProvider.getUserByEmail(LDAPStorageProvider.java:546)
>
>   at org.keycloak.storage.UserStorageManager.getUserByEmail(UserStorageManager.java:408)
>
>   at org.keycloak.models.cache.infinispan.UserCacheSession.getUserByEmail(UserCacheSession.java:380)
>
>   at org.keycloak.authentication.authenticators.broker.IdpCreateUserIfUniqueAuthenticator.checkExistingUser(IdpCreateUserIfUniqueAuthenticator.java:123)
>
>   at org.keycloak.authentication.authenticators.broker.IdpCreateUserIfUniqueAuthenticator.authenticateImpl(IdpCreateUserIfUniqueAuthenticator.java:69)
>
>   at org.keycloak.authentication.authenticators.broker.AbstractIdpAuthenticator.authenticate(AbstractIdpAuthenticator.java:74)
>
>   at org.keycloak.authentication.DefaultAuthenticationFlow.processFlow(DefaultAuthenticationFlow.java:221)
>
>   at org.keycloak.authentication.DefaultAuthenticationFlow.processAction(DefaultAuthenticationFlow.java:117)
>
>   at org.keycloak.authentication.AuthenticationProcessor.authenticationAction(AuthenticationProcessor.java:873)
>
>   at org.keycloak.services.resources.LoginActionsService.processFlow(LoginActionsService.java:292)
>
>   at org.keycloak.services.resources.LoginActionsService.brokerLoginFlow(LoginActionsService.java:779)
>
>   at org.keycloak.services.resources.LoginActionsService.firstBrokerLoginPost(LoginActionsService.java:702)
>
>   at sun.reflect.GeneratedMethodAccessor1032.invoke(Unknown Source)
>
>   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>
>   at java.lang.reflect.Method.invoke(Method.java:498)
>
>   at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:139)
>
>   at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:509)
>
>   at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:399)
>
>   at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:363)
>
>   at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:355)
>
>   at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:365)
>
>   at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:337)
>
>   at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:137)
>
>   at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:100)
>
>   at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:439)
>
>   at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:229)
>
>   at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:135)
>
>   at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:355)
>
>   at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:138)
>
>   at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:215)
>
>   at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:227)
>
>   at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
>
>   at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51)
>
>   at javax.servlet.http.HttpServlet.service(HttpServlet.java:791)
>
>   at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
>
>   at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
>
>   at org.keycloak.services.filters.KeycloakSessionServletFilter.doFilter(KeycloakSessionServletFilter.java:90)
>
>   at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
>
>   at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
>
>   at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
>
>   at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
>
>   at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
>
>   at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
>
>   at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
>
>   at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
>
>   at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:132)
>
>   at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
>
>   at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
>
>   at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
>
>   at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
>
>   at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
>
>   at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
>
>   at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
>
>   at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
>
>   at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
>
>   at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
>
>   at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
>
>   at org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
>
>   at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
>
>   at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)
>
>   at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
>
>   at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
>
>   at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
>
>   at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
>
>   at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
>
>   at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
>
>   at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
>
>   at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
>
>   at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
>
>   at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
>
>   at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
>
>   at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
>
>   at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
>
>   at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
>
>   at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
>
>   at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
>
>   at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
>
>   at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
>
>   at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
>
>   at java.lang.Thread.run(Thread.java:748)
>
>
>
>
> 2019-04-24 15:45:12,504 WARN  [org.keycloak.events] (default task-260) type=UPDATE_PROFILE_ERROR, realmId=SDCC2, clientId=test2-oidc, userId=null, ipAddress=443, error=invalid_user_credentials, identity_provider=CILogon, auth_method=openid-connect, updated_email=mizuki at yahoo.com, redirect_uri=https://test2.racf.bnl.gov/*, identity_provider_identity=http://cilogon.org/serverA/users/2706181, code_id=be-xYIYKAlCQjhk3D28GVOorE8krIRO-XhMM79zYQOI
>
> 2019-04-24 15:45:12,505 DEBUG [freemarker.cache] (default task-260) Couldn't find template in cache for "error.ftl"("en_US", UTF-8, parsed); will try to load it.
>
>
>
> Thanks!
> Mizuki Karasawa
> _______________________________________________
> keycloak-user mailing list
> keycloak-user at lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/keycloak-user

More information about the keycloak-user mailing list