search

daniel-frak / keycloak-user-migration

A Keycloak plugin for migrating users from legacy systems
MIT License
285 stars 130 forks source link

Username with uppercase letters causing errors #138

Open kidager opened 5 months ago

kidager commented 5 months ago

Summary

TL;DR: Error migrating users to keycloak when the username is not all lowercase.

In our API, given a user with username Alice@example.com (we're using the email as username). When they're first migrated to keycloak using the provider, we got the following error in the logs

2024-03-18 10:43:10,361 WARN [org.keycloak.services] (executor-thread-1148) KC-SERVICES0013: Failed authentication: java.lang.IllegalStateException: Local and remote users differ: [alice@example.com != Alice@example.com]
2024-03-18 10:43:10,359 INFO [com.danielfrak.code.keycloak.providers.rest.remote.UserModelFactory] (executor-thread-1148) Creating user model for: Alice@example.com

The user is created in keycloak, but the only info they have is the username, everything else is blank.

Steps to reproduce

What you expected would happen

The user with username Alice@example.com is created on keycloak with all the information provided on the json from the API (even a username alice@example.com would be accepted in this case)

What actually happens

A user is created on keycloak with the username alice@example.com with the status disabled, no other information is migrated (email, firstname, lastname, attributes, credentials, ...) The user is not able to login.

Notes

We've tracked it to this part of code

As a hack, we're now forcing the username to be all lowercase in the GET api, and it's working fine.

daniel-frak commented 5 months ago

Hello,

That's a bit concerning!

From what I understand, the username still has the correct case by the time we reach UserModelFactory::create. Therefore, it seems that the line userModel = session.users().addUser(realm, legacyUser.getUsername()); is actually the culprit which changes the username's case.

Ergo, signs point to your instance of Keycloak changing the case - are you sure you haven't configured Keycloak to force lowercase? I haven't used it in a while, so I'm not entirely sure how or where that could be done.

Are you able to reproduce this behavior via a Cypress test, using the provided dockerized Keycloak?

kidager commented 5 months ago

I'm not aware of any config we did in the team to force the case.

I'll try to reproduce using cypress.

kidager commented 5 months ago

I can confirm that the e2e tests are failing using the provided docker compose 😬

And I got the same logs as well.

I've updated the legacysystemexample to return a username with an uppercase letter in it, here is the result.

Test before change

image

Code changes

image

Tests after change

image image

Log trace

legacy-system-example-1  | 2024-03-19T17:55:06.670Z  INFO 1 --- [nio-8080-exec-3] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy
keycloak-1               | 2024-03-19 17:55:06,683 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy
legacy-system-example-1  | 2024-03-19T17:55:06.691Z  INFO 1 --- [nio-8080-exec-5] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy
keycloak-1               | 2024-03-19 17:55:06,694 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy
legacy-system-example-1  | 2024-03-19T17:55:06.704Z  INFO 1 --- [nio-8080-exec-7] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy
keycloak-1               | 2024-03-19 17:55:06,707 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy
legacy-system-example-1  | 2024-03-19T17:55:06.713Z  INFO 1 --- [nio-8080-exec-8] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy
keycloak-1               | 2024-03-19 17:55:06,715 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy
legacy-system-example-1  | 2024-03-19T17:55:06.721Z  INFO 1 --- [nio-8080-exec-1] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy
keycloak-1               | 2024-03-19 17:55:06,724 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy
legacy-system-example-1  | 2024-03-19T17:55:06.733Z  INFO 1 --- [nio-8080-exec-2] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy
keycloak-1               | 2024-03-19 17:55:06,735 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy
keycloak-1               | 2024-03-19 17:55:06,760 WARN  [org.keycloak.events] (executor-thread-14) type=LOGIN_ERROR, realmId=42684046-75b5-40df-a4f0-14c8126051b7, clientId=account-console, userId=null, ipAddress=192.168.65.1, error=user_not_found, auth_method=openid-connect, auth_type=code, redirect_uri=http://localhost:8024/realms/master/account/#/, code_id=4cb73fcc-d451-40c5-8d33-cf108ef9b66c, username=lucy
legacy-system-example-1  | 2024-03-19T17:55:07.969Z  INFO 1 --- [nio-8080-exec-4] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:08,014 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy@example.com
legacy-system-example-1  | 2024-03-19T17:55:08.019Z  INFO 1 --- [nio-8080-exec-6] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:08,024 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy@example.com
legacy-system-example-1  | 2024-03-19T17:55:08.028Z  INFO 1 --- [nio-8080-exec-9] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:08,031 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy@example.com
legacy-system-example-1  | 2024-03-19T17:55:08.038Z  INFO 1 --- [io-8080-exec-10] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:08,043 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy@example.com
legacy-system-example-1  | 2024-03-19T17:55:08.046Z  INFO 1 --- [nio-8080-exec-2] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:08,049 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy@example.com
legacy-system-example-1  | 2024-03-19T17:55:08.052Z  INFO 1 --- [nio-8080-exec-4] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:08,055 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy@example.com
legacy-system-example-1  | 2024-03-19T17:55:08.060Z  INFO 1 --- [nio-8080-exec-6] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:08,062 INFO  [com.danielfrak.code.keycloak.providers.rest.remote.UserModelFactory] (executor-thread-14) Creating user model for: Lucy
keycloak-1               | 2024-03-19 17:55:08,071 WARN  [org.keycloak.services] (executor-thread-14) KC-SERVICES0013: Failed authentication: java.lang.IllegalStateException: Local and remote users differ: [lucy != Lucy]
keycloak-1               |      at com.danielfrak.code.keycloak.providers.rest.remote.UserModelFactory.validateUsernamesEqual(UserModelFactory.java:109)
keycloak-1               |      at com.danielfrak.code.keycloak.providers.rest.remote.UserModelFactory.create(UserModelFactory.java:71)
keycloak-1               |      at com.danielfrak.code.keycloak.providers.rest.LegacyProvider.lambda$getUserModel$1(LegacyProvider.java:60)
keycloak-1               |      at java.base/java.util.Optional.map(Optional.java:260)
keycloak-1               |      at com.danielfrak.code.keycloak.providers.rest.LegacyProvider.getUserModel(LegacyProvider.java:60)
keycloak-1               |      at com.danielfrak.code.keycloak.providers.rest.LegacyProvider.getUserByEmail(LegacyProvider.java:168)
keycloak-1               |      at org.keycloak.storage.UserStorageManager.lambda$getUserByEmail$20(UserStorageManager.java:398)
keycloak-1               |      at org.keycloak.utils.ServicesUtils.lambda$timeBoundOne$1(ServicesUtils.java:83)
keycloak-1               |      at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
keycloak-1               |      at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
keycloak-1               |      at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
keycloak-1               |      at java.base/java.util.stream.SortedOps$RefSortingSink.end(SortedOps.java:400)
keycloak-1               |      at java.base/java.util.stream.Sink$ChainedReference.end(Sink.java:258)
keycloak-1               |      at java.base/java.util.stream.Sink$ChainedReference.end(Sink.java:258)
keycloak-1               |      at java.base/java.util.stream.AbstractPipeline.copyIntoWithCancel(AbstractPipeline.java:528)
keycloak-1               |      at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:513)
keycloak-1               |      at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
keycloak-1               |      at java.base/java.util.stream.FindOps$FindOp.evaluateSequential(FindOps.java:150)
keycloak-1               |      at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
keycloak-1               |      at java.base/java.util.stream.ReferencePipeline.findFirst(ReferencePipeline.java:647)
keycloak-1               |      at org.keycloak.storage.UserStorageManager.getUserByEmail(UserStorageManager.java:398)
keycloak-1               |      at org.keycloak.models.cache.infinispan.UserCacheSession.getUserByEmail(UserCacheSession.java:399)
keycloak-1               |      at org.keycloak.authentication.authenticators.resetcred.ResetCredentialChooseUser.action(ResetCredentialChooseUser.java:101)
keycloak-1               |      at org.keycloak.authentication.DefaultAuthenticationFlow.processAction(DefaultAuthenticationFlow.java:154)
keycloak-1               |      at org.keycloak.authentication.AuthenticationProcessor.authenticationAction(AuthenticationProcessor.java:986)
keycloak-1               |      at org.keycloak.services.resources.LoginActionsService.processFlow(LoginActionsService.java:378)
keycloak-1               |      at org.keycloak.services.resources.LoginActionsService.processResetCredentials(LoginActionsService.java:717)
keycloak-1               |      at org.keycloak.services.resources.LoginActionsService.resetCredentials(LoginActionsService.java:507)
keycloak-1               |      at org.keycloak.services.resources.LoginActionsService.resetCredentialsPOST(LoginActionsService.java:423)
keycloak-1               |      at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
keycloak-1               |      at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
keycloak-1               |      at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
keycloak-1               |      at java.base/java.lang.reflect.Method.invoke(Method.java:568)
keycloak-1               |      at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:154)
keycloak-1               |      at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:118)
keycloak-1               |      at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:560)
keycloak-1               |      at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:452)
keycloak-1               |      at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:413)
keycloak-1               |      at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:321)
keycloak-1               |      at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:415)
keycloak-1               |      at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:378)
keycloak-1               |      at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:174)
keycloak-1               |      at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:131)
keycloak-1               |      at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:33)
keycloak-1               |      at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:429)
keycloak-1               |      at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:240)
keycloak-1               |      at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:154)
keycloak-1               |      at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:321)
keycloak-1               |      at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:157)
keycloak-1               |      at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:229)
keycloak-1               |      at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:82)
keycloak-1               |      at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:147)
keycloak-1               |      at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:84)
keycloak-1               |      at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:44)
keycloak-1               |      at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
keycloak-1               |      at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
keycloak-1               |      at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
keycloak-1               |      at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$1.handle(HttpServerCommonHandlers.java:58)
keycloak-1               |      at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$1.handle(HttpServerCommonHandlers.java:36)
keycloak-1               |      at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
keycloak-1               |      at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
keycloak-1               |      at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
keycloak-1               |      at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$0(QuarkusRequestFilter.java:82)
keycloak-1               |      at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
keycloak-1               |      at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
keycloak-1               |      at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
keycloak-1               |      at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
keycloak-1               |      at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
keycloak-1               |      at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
keycloak-1               |      at java.base/java.lang.Thread.run(Thread.java:840)
keycloak-1               |
keycloak-1               | 2024-03-19 17:55:08,076 WARN  [org.keycloak.events] (executor-thread-14) type=RESET_PASSWORD_ERROR, realmId=42684046-75b5-40df-a4f0-14c8126051b7, clientId=account-console, userId=null, ipAddress=192.168.65.1, error=invalid_user_credentials, auth_method=openid-connect, auth_type=code, redirect_uri=http://localhost:8024/realms/master/account/#/, code_id=4cb73fcc-d451-40c5-8d33-cf108ef9b66c
mailhog-1                | [APIv1] KEEPALIVE /api/v1/events
mailhog-1                | [APIv1] POST /api/v1/messages
mailhog-1                | [APIv2] GET /api/v2/messages
legacy-system-example-1  | 2024-03-19T17:55:36.415Z  INFO 1 --- [nio-8080-exec-9] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:36,437 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy@example.com
legacy-system-example-1  | 2024-03-19T17:55:36.445Z  INFO 1 --- [io-8080-exec-10] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:36,449 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy@example.com
legacy-system-example-1  | 2024-03-19T17:55:36.453Z  INFO 1 --- [nio-8080-exec-2] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:36,460 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy@example.com
legacy-system-example-1  | 2024-03-19T17:55:36.468Z  INFO 1 --- [nio-8080-exec-4] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:36,472 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy@example.com
legacy-system-example-1  | 2024-03-19T17:55:36.476Z  INFO 1 --- [nio-8080-exec-6] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:36,480 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy@example.com
legacy-system-example-1  | 2024-03-19T17:55:36.482Z  INFO 1 --- [nio-8080-exec-9] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:36,491 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-14) User not found in external repository: lucy@example.com
legacy-system-example-1  | 2024-03-19T17:55:36.497Z  INFO 1 --- [io-8080-exec-10] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy@example.com
keycloak-1               | 2024-03-19 17:55:36,499 INFO  [com.danielfrak.code.keycloak.providers.rest.remote.UserModelFactory] (executor-thread-14) Creating user model for: Lucy
keycloak-1               | 2024-03-19 17:55:36,504 WARN  [org.keycloak.services] (executor-thread-14) KC-SERVICES0013: Failed authentication: java.lang.IllegalStateException: Local and remote users differ: [lucy != Lucy]
keycloak-1               |      at com.danielfrak.code.keycloak.providers.rest.remote.UserModelFactory.validateUsernamesEqual(UserModelFactory.java:109)
keycloak-1               |      at com.danielfrak.code.keycloak.providers.rest.remote.UserModelFactory.create(UserModelFactory.java:71)
keycloak-1               |      at com.danielfrak.code.keycloak.providers.rest.LegacyProvider.lambda$getUserModel$1(LegacyProvider.java:60)
keycloak-1               |      at java.base/java.util.Optional.map(Optional.java:260)
keycloak-1               |      at com.danielfrak.code.keycloak.providers.rest.LegacyProvider.getUserModel(LegacyProvider.java:60)
keycloak-1               |      at com.danielfrak.code.keycloak.providers.rest.LegacyProvider.getUserByEmail(LegacyProvider.java:168)
keycloak-1               |      at org.keycloak.storage.UserStorageManager.lambda$getUserByEmail$20(UserStorageManager.java:398)
keycloak-1               |      at org.keycloak.utils.ServicesUtils.lambda$timeBoundOne$1(ServicesUtils.java:83)
keycloak-1               |      at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
keycloak-1               |      at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
keycloak-1               |      at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
keycloak-1               |      at java.base/java.util.stream.SortedOps$RefSortingSink.end(SortedOps.java:400)
keycloak-1               |      at java.base/java.util.stream.Sink$ChainedReference.end(Sink.java:258)
keycloak-1               |      at java.base/java.util.stream.Sink$ChainedReference.end(Sink.java:258)
keycloak-1               |      at java.base/java.util.stream.AbstractPipeline.copyIntoWithCancel(AbstractPipeline.java:528)
keycloak-1               |      at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:513)
keycloak-1               |      at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
keycloak-1               |      at java.base/java.util.stream.FindOps$FindOp.evaluateSequential(FindOps.java:150)
keycloak-1               |      at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
keycloak-1               |      at java.base/java.util.stream.ReferencePipeline.findFirst(ReferencePipeline.java:647)
keycloak-1               |      at org.keycloak.storage.UserStorageManager.getUserByEmail(UserStorageManager.java:398)
keycloak-1               |      at org.keycloak.models.cache.infinispan.UserCacheSession.getUserByEmail(UserCacheSession.java:399)
keycloak-1               |      at org.keycloak.authentication.authenticators.resetcred.ResetCredentialChooseUser.action(ResetCredentialChooseUser.java:101)
keycloak-1               |      at org.keycloak.authentication.DefaultAuthenticationFlow.processAction(DefaultAuthenticationFlow.java:154)
keycloak-1               |      at org.keycloak.authentication.AuthenticationProcessor.authenticationAction(AuthenticationProcessor.java:986)
keycloak-1               |      at org.keycloak.services.resources.LoginActionsService.processFlow(LoginActionsService.java:378)
keycloak-1               |      at org.keycloak.services.resources.LoginActionsService.processResetCredentials(LoginActionsService.java:717)
keycloak-1               |      at org.keycloak.services.resources.LoginActionsService.resetCredentials(LoginActionsService.java:507)
keycloak-1               |      at org.keycloak.services.resources.LoginActionsService.resetCredentialsPOST(LoginActionsService.java:423)
keycloak-1               |      at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
keycloak-1               |      at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
keycloak-1               |      at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
keycloak-1               |      at java.base/java.lang.reflect.Method.invoke(Method.java:568)
keycloak-1               |      at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:154)
keycloak-1               |      at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:118)
keycloak-1               |      at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:560)
keycloak-1               |      at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:452)
keycloak-1               |      at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:413)
keycloak-1               |      at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:321)
keycloak-1               |      at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:415)
keycloak-1               |      at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:378)
keycloak-1               |      at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:174)
keycloak-1               |      at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:131)
keycloak-1               |      at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:33)
keycloak-1               |      at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:429)
keycloak-1               |      at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:240)
keycloak-1               |      at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:154)
keycloak-1               |      at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:321)
keycloak-1               |      at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:157)
keycloak-1               |      at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:229)
keycloak-1               |      at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:82)
keycloak-1               |      at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:147)
keycloak-1               |      at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:84)
keycloak-1               |      at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:44)
keycloak-1               |      at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
keycloak-1               |      at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
keycloak-1               |      at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
keycloak-1               |      at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$1.handle(HttpServerCommonHandlers.java:58)
keycloak-1               |      at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$1.handle(HttpServerCommonHandlers.java:36)
keycloak-1               |      at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
keycloak-1               |      at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
keycloak-1               |      at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
keycloak-1               |      at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$0(QuarkusRequestFilter.java:82)
keycloak-1               |      at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
keycloak-1               |      at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
keycloak-1               |      at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
keycloak-1               |      at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
keycloak-1               |      at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
keycloak-1               |      at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
keycloak-1               |      at java.base/java.lang.Thread.run(Thread.java:840)
keycloak-1               |
keycloak-1               | 2024-03-19 17:55:36,506 WARN  [org.keycloak.events] (executor-thread-14) type=RESET_PASSWORD_ERROR, realmId=42684046-75b5-40df-a4f0-14c8126051b7, clientId=security-admin-console, userId=null, ipAddress=192.168.65.1, error=invalid_user_credentials, auth_method=openid-connect, auth_type=code, redirect_uri=http://localhost:8024/admin/master/console/#/master/authentication/policies, code_id=7ddd7aec-3198-4941-9a23-17352f6fedb5
mailhog-1                | [APIv1] POST /api/v1/messages
mailhog-1                | [APIv2] GET /api/v2/messages
legacy-system-example-1  | 2024-03-19T17:56:10.223Z  INFO 1 --- [nio-8080-exec-2] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy
keycloak-1               | 2024-03-19 17:56:10,243 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-16) User not found in external repository: lucy
legacy-system-example-1  | 2024-03-19T17:56:10.255Z  INFO 1 --- [nio-8080-exec-4] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy
keycloak-1               | 2024-03-19 17:56:10,257 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-16) User not found in external repository: lucy
legacy-system-example-1  | 2024-03-19T17:56:10.260Z  INFO 1 --- [nio-8080-exec-6] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy
keycloak-1               | 2024-03-19 17:56:10,262 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-16) User not found in external repository: lucy
legacy-system-example-1  | 2024-03-19T17:56:10.280Z  INFO 1 --- [nio-8080-exec-9] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy
keycloak-1               | 2024-03-19 17:56:10,285 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-16) User not found in external repository: lucy
legacy-system-example-1  | 2024-03-19T17:56:10.289Z  INFO 1 --- [io-8080-exec-10] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy
keycloak-1               | 2024-03-19 17:56:10,291 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-16) User not found in external repository: lucy
legacy-system-example-1  | 2024-03-19T17:56:10.295Z  INFO 1 --- [nio-8080-exec-2] d.c.l.a.i.services.UserMigrationService  : Getting migration data for: lucy
keycloak-1               | 2024-03-19 17:56:10,296 WARN  [com.danielfrak.code.keycloak.providers.rest.LegacyProvider] (executor-thread-16) User not found in external repository: lucy
keycloak-1               | 2024-03-19 17:56:10,318 WARN  [org.keycloak.events] (executor-thread-16) type=LOGIN_ERROR, realmId=42684046-75b5-40df-a4f0-14c8126051b7, clientId=security-admin-console, userId=null, ipAddress=192.168.65.1, error=user_not_found, auth_method=openid-connect, auth_type=code, redirect_uri=http://localhost:8024/admin/master/console/#/master/authentication/policies, code_id=6d40cb3e-7892-4ae7-962c-180daced18ea, username=lucy
daniel-frak commented 5 months ago

Thank you for doing the work to document the issue and reproduce it!

From what I see in the logs, the first and last test cases are fine - the user is not found at all, so nothing is created in Keycloak. Indeed, though, it seems that the two "reset password" scenarios do find the user by e-mail, then, upon creating them, Keycloak returns the username with an incorrect case.

This will need some investigating to find the root cause of the case change, so that it can (hopefully) be fixed without workarounds. Unfortunately, I can't guarantee when I'll have the time to sit down with the code and provide a fix.

If anyone else feels like it, though, more help is always appreciated :)

daniel-frak commented 5 months ago

A (very) quick Google led me to this Stack Overflow issue:

https://stackoverflow.com/questions/69553369/how-to-access-the-original-case-sensitive-username-input-in-custom-user-storage

Which points to this piece of Keycloak code:

https://github.com/keycloak/keycloak/blob/bfce612641a70e106b20b136431f0e4046b5c37f/model/infinispan/src/main/java/org/keycloak/models/cache/infinispan/UserCacheSession.java#L243

It seems like converting all usernames to lowercase in the plugin might be the correct way to go...

Edit:

Apparently, "Case-sensitive usernames and emails are currently not supported":

https://keycloak.discourse.group/t/use-upcase-and-lowcase-for-username-and-email-fields-in-create-users/23462/2

At least the fix should be trivial, then, once I (or anyone else) get around to it.

felix-two-tone commented 3 months ago

Any progress on this? We are having the same issue with wordpress usernames that have uppercase letters

daniel-frak commented 3 months ago

Unfortunately, I didn't have the time to fix this yet.

However, I encourage you to create a Pull Request with the fix, if it's a pressing issue :)

christoph-daehne commented 2 months ago

As a local work-around: I added a small REST service in between the legacy system and Keycloak. There the usernames are lower-cases before sending them to the keycloak-user-migration User Federation.

Hence, the following happens: