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

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@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@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(a)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(a)lists.jboss.org https://lists.jboss.org/mailman/listinfo/keycloak-user