Registering user fails using LDAP Federation

[puggimer]

Before reporting an issue

• I have read and understood the above terms for submitting issues, and I understand that my issue may be closed without action if I do not follow them.

Area

ldap

Describe the bug

I have a 20.0.4 version of keycloak working with Open LDAP.
Instead of upgrading, I made a new installation using 24.0.4. Everything works fine, until I turn on User Federation with Open LDAP (using the same configuration that is working in 20.0.4).

Users can register with no issue if User Federation is disabled. If User Federation is turned on, the user receives an internal error occured.

Version

24.0.4

Regression

• The issue is a regression

Expected behavior

User should be able to register using LDAP federation (this is working in our 20.0.4 version).

Actual behavior

I have TRACE turned on, and see where the an LDAP entry is created, but it is using the USERNAME field in the CN. It then renames the entry changing the CN to the FullName. Then after calling removeUserLoginFailure on the original CN (i.e. username), it tries to get the user information using the old CN - which now no longer exists. This causes an exception to be thrown:

2024-06-26 16:12:59,501 ERROR [org.keycloak.services.error.KeycloakErrorHandler] (executor-thread-13) Uncaught server error: java.lang.NullPointerException: Cannot invoke "org.keycloak.models.UserModel.getFirstAttribute(String)" because the return value of "org.keycloak.authentication.RequiredActionContext.getUser()" is null

and the user gets a screen showing that an internal error has occurred.

The user IS added to the LDAP server however, and appears to be correct (though they still have to acknowledge the Terms and Conditions).

How to Reproduce?

Enable user federation. User requests access and is granted, and they receive an email with an accept-invite link
https://ardisdev-sso.usaftechconnect.com/invitations/accept-invite/bczjrvrjdhfotvmolmshev1qqrfsoa417uw2qb7aqvzpcngddxuz0vqs3nxy6hfv
This takes them to keycloak to register. Once they hit the Register button, they see a screen with "An internal server error has occurred"

Anything else?

Attached is the TRACE of the full registration session.
kc.log
At line 7410 the CN is changed

LdapOperation: renameEntry
 oldDn: cn=mike.at.home,ou=users,dc=usaftechconnect,dc=com
 newDn: cn=Mike Home Carter,ou=users,dc=usaftechconnect,dc=com
took: 32 ms

At line 752 is a modify operation with the new cn, but then at line 769 is a lookupById, which uses the OLD cn (this is for a removeUserLoginFailure)

LdapOperation: lookupById
 baseDN: ou=users,dc=usaftechconnect,dc=com
 filter: (entryDN=cn=mike.at.home,ou=users,dc=usaftechconnect,dc=com)
 searchScope: 2
 returningAttrs: [uid, mail, givenName, sn, createTimestamp, modifyTimestamp]
took: 1 ms

This seems to be ok, but then at line 803 it attempts to look up the old CN again, this time failing and giving the user the error.

2024-06-26 16:43:50,257 TRACE [org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager.perf] (executor-thread-61) 
LdapOperation: lookupById
 baseDN: ou=users,dc=usaftechconnect,dc=com
 filter: (entryDN=cn=mike.at.home,ou=users,dc=usaftechconnect,dc=com)
 searchScope: 2
 returningAttrs: [uid, mail, givenName, sn, createTimestamp, modifyTimestamp]
took: 0 ms

2024-06-26 16:43:50,258 TRACE [org.keycloak.models.cache.infinispan.RealmCacheSession] (executor-thread-61) by id cache hit: wagtail
2024-06-26 16:43:50,258 TRACE [org.keycloak.quarkus.runtime.storage.legacy.database.QuarkusJpaConnectionProviderFactory] (executor-thread-61) Create QuarkusJpaConnectionProvider
2024-06-26 16:43:50,262 TRACE [org.keycloak.connections.jpa.DefaultJpaConnectionProvider] (executor-thread-61) DefaultJpaConnectionProvider close()
2024-06-26 16:43:50,262 ERROR [org.keycloak.services.error.KeycloakErrorHandler] (executor-thread-61) Uncaught server error: java.lang.NullPointerException: Cannot invoke "org.keycloak.models.UserModel.getFirstAttribute(String)" because the return value of "org.keycloak.authentication.RequiredActionContext.getUser()" is null
	at org.keycloak.authentication.requiredactions.UpdateUserLocaleAction.evaluateTriggers(UpdateUserLocaleAction.java:27)
	at org.keycloak.services.managers.AuthenticationManager.evaluateRequiredAction(AuthenticationManager.java:1353)
	at org.keycloak.services.managers.AuthenticationManager.lambda$evaluateRequiredActionTriggers$19(AuthenticationManager.java:1324)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
	at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
	at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
	at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150)
	at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.base/java.util.stream.ReferencePipeline.forEachOrdered(ReferencePipeline.java:601)
	at org.keycloak.services.managers.AuthenticationManager.evaluateRequiredActionTriggers(AuthenticationManager.java:1324)
	at org.keycloak.services.managers.AuthenticationManager.actionRequired(AuthenticationManager.java:1105)
	at org.keycloak.services.managers.AuthenticationManager.nextActionAfterAuthentication(AuthenticationManager.java:959)
	at org.keycloak.services.resources.LoginActionsService.processRequireAction(LoginActionsService.java:1080)
	at org.keycloak.services.resources.LoginActionsService.requiredActionGET(LoginActionsService.java:1062)
	at org.keycloak.services.resources.LoginActionsService$quarkusrestinvoker$requiredActionGET_900f1400af417d7ade6b5fdd106784903c8de34e.invoke(Unknown Source)
	at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
	at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
	at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
	at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582)
	at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
	at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
	at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:840)

The ldap entry has been added and is still there however.

[puggimer]

Changed version to 25.0.1 (quay.io/keycloak/keycloak:25.0.1), exact same issue occurs at the exact same place. Attached is the full log from startup. There are a lot of getClientById() errors - but that is a known issue and does not seem to be an issue.
Line 1063 is where the CN is changed
Line 1128 is where it attempts to find the user by using the OLD CN
NLP is thrown on line 1138
I have also attached the user screenshot showing that the user has been created (mikey.cac).

I then disabled the User Federation, and ran it again. This time it worked as expected (homeboymike).

kc-25-0-1.log

[jonkoops]

Thanks for confirming this is still an issue in the latest version. We'll try to get this triaged.

[pedroigor]

@puggimer I'm trying to understand the problem and it seems it was working on 20 but not in 24. Can you please confirm how it works in 22 or 23?

Can you also send the logs for the same problem but when using 20? We could try to compare both 20 and 24 and see where they are behaving differently.

One thing that is weird is that the user mike.at.home is removed because it can't be found when looking up the entry in LDAP by ID:

LdapOperation: lookupById
 baseDN: ou=users,dc=usaftechconnect,dc=com
 filter: (entryDN=cn=mike.at.home,ou=users,dc=usaftechconnect,dc=com)
 searchScope: 2
 returningAttrs: [uid, mail, givenName, sn, createTimestamp, modifyTimestamp]
took: 0 ms

And this is because the CN changed but for some reason, as you pointed out, the DN used there is not reflecting the previous modification.

[pedroigor]

Can you please provide the value of the LDAP_ID attribute on that user?

[pedroigor]

I'm also wondering why you are using the cn as a UUID LDAP attribute?

[puggimer]

@pedroigor Sorry, took a long weekend (with the holiday Thursday in the USA).
I have not run 22 or 23 to give possible logs (I went straight from 20 to 25, just importing/rebuilding the realm, since this is not yet in production.

Yes, it does seem strange to me that it is attempting to remove the old user after changing the CN - my thought was it is a cleanup step in the case that the update left something behind.

You are correct that it does not use the new DN and that seems odd - I am wondering if the old DN is cached and it is not recalculating it when the CN changes?

I don't have the LDAP_ID of that user as it has been deleted (and recreated) many times with different usernames (but the same emails, as I only have a few accounts to play with, especially when using my CAC (i.e. X509).

As for using the CN as the UUID - it is unique so it works. However this configuration is also something I inherited, so I had not looked at changing this at all. I'll look at this, but it requires me to standup a separate OPEN LDAP server to play with.

I'm working on getting the version 20 logs - however that is deployed in AWS ECS Fargate, so it is not as simple as a straight docker deployment.

[puggimer]

I'm not able to get logs from the 20.0.4 version due to some unrelated errors (in the software that calls it).

[pedroigor]

@puggimer I can not reproduce the error. I'm using exactly the same mappers. I'm not sure what else to investigate.

My best guess is that you are using the RDN LDAP attribute as cn while at the same time you have full-name-ldap-mapper set to also use the cn attribute. When updating the first and last names you end up changing the RDN that the server wil use to match a user DN. For instance, I see most people using sAMAccountName or mail, or something else to uniquely identify a user entry.

The fact you are mapping the full name as a cn is not making it unique. And that might be the cause of the failures you are seeing.

[keycloak-github-bot]

Thanks for reporting this issue, but there is insufficient information or lack of steps to reproduce.

Please provide additional details, otherwise this issue will be automatically closed within 14 days.

[keycloak-github-bot]

Due to lack of updates in the last 14 days this issue will be automatically closed.