search

daniel-frak / keycloak-user-migration

A Keycloak plugin for migrating users from legacy systems
MIT License
287 stars 131 forks source link

KC UI fails if migration API isn't running (dev mode) #75

Open kennymac opened 1 year ago

kennymac commented 1 year ago

Hi Daniel,

I have a local docker-compose KC 19.0.1 with plugin loaded, and noticed when setting up users in the KC UI that create user fails if the migration API isn't available -

Error logged is

2023-02-25 02:47:47,382 ERROR [org.keycloak.services.error.KeycloakErrorHandler] (executor-thread-13) Uncaught server error: com.danielfrak.code.keycloak.providers.rest.exceptions.RestUserProviderException: com.danielfrak.code.keycloak.providers.rest.rest.http.HttpRequestException: An error occurred while making a HTTP request: GET http://host.docker.internal:5000/api/usermigration/user1@example.com HTTP/1.1

With the API running, creating a new user works ok, even if the API returns a non-200 code.

Is this behaviour by design? The concern is KC availability will be impacted, e.g. whenever the API is being deployed.

What would you advise? Thanks v much for a fantastic utility!

Ken

kennymac commented 1 year ago

The error log

keycloak19                | 2023-03-01 23:05:11,802 ERROR [org.keycloak.services.error.KeycloakErrorHandler] (executor-thread-5) Uncaught server error: com.danielfrak.code.keycloak.providers.rest.exceptions.RestUserProviderException: com.danielfrak.code.keycloak.providers.rest.rest.http.HttpRequestException: An error occurred while making a HTTP request: GET http://host.docker.internal:5000/api/keycloak/usermigration/testuser_1234 HTTP/1.1
keycloak19                |     at com.danielfrak.code.keycloak.providers.rest.rest.RestUserService.findLegacyUser(RestUserService.java:80)
keycloak19                |     at com.danielfrak.code.keycloak.providers.rest.rest.RestUserService.findByUsername(RestUserService.java:66)
keycloak19                |     at com.danielfrak.code.keycloak.providers.rest.LegacyProvider.lambda$getUserByUsername$0(LegacyProvider.java:50)
keycloak19                |     at com.danielfrak.code.keycloak.providers.rest.LegacyProvider.getUserModel(LegacyProvider.java:54)
keycloak19                |     at com.danielfrak.code.keycloak.providers.rest.LegacyProvider.getUserByUsername(LegacyProvider.java:50)
keycloak19                |     at org.keycloak.storage.user.UserLookupProvider.getUserByUsername(UserLookupProvider.java:62)
keycloak19                |     at org.keycloak.storage.UserStorageManager.lambda$getUserByUsername$16(UserStorageManager.java:334)
keycloak19                |     at org.keycloak.utils.ServicesUtils.lambda$timeBoundOne$1(ServicesUtils.java:84)
keycloak19                |     at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
keycloak19                |     at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:177)
keycloak19                |     at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:195)
keycloak19                |     at java.base/java.util.stream.SortedOps$RefSortingSink.end(SortedOps.java:400)
keycloak19                |     at java.base/java.util.stream.Sink$ChainedReference.end(Sink.java:258)
keycloak19                |     at java.base/java.util.stream.Sink$ChainedReference.end(Sink.java:258)
keycloak19                |     at java.base/java.util.stream.AbstractPipeline.copyIntoWithCancel(AbstractPipeline.java:503)
keycloak19                |     at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:488)
keycloak19                |     at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474)
keycloak19                |     at java.base/java.util.stream.FindOps$FindOp.evaluateSequential(FindOps.java:150)
keycloak19                |     at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
keycloak19                |     at java.base/java.util.stream.ReferencePipeline.findFirst(ReferencePipeline.java:543)
keycloak19                |     at org.keycloak.storage.UserStorageManager.getUserByUsername(UserStorageManager.java:334)
keycloak19                |     at org.keycloak.models.cache.infinispan.UserCacheSession.getUserByUsername(UserCacheSession.java:268)
keycloak19                |     at org.keycloak.services.resources.admin.UsersResource.createUser(UsersResource.java:134)
keycloak19                |     at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
keycloak19                |     at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
keycloak19                |     at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
keycloak19                |     at java.base/java.lang.reflect.Method.invoke(Method.java:566)
keycloak19                |     at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:170)
keycloak19                |     at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:130)
keycloak19                |     at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:660)
keycloak19                |     at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:524)
keycloak19                |     at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:474)
keycloak19                |     at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
keycloak19                |     at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:476)
keycloak19                |     at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:434)
keycloak19                |     at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:192)
keycloak19                |     at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
keycloak19                |     at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
keycloak19                |     at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
keycloak19                |     at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
keycloak19                |     at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:141)
keycloak19                |     at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:32)
keycloak19                |     at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:492)
keycloak19                |     at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:261)
keycloak19                |     at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:161)
keycloak19                |     at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
keycloak19                |     at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:164)
keycloak19                |     at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:247)
keycloak19                |     at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
keycloak19                |     at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:151)
keycloak19                |     at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:82)
keycloak19                |     at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:42)
keycloak19                |     at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
keycloak19                |     at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
keycloak19                |     at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
keycloak19                |     at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:67)
keycloak19                |     at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:55)
keycloak19                |     at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
keycloak19                |     at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
keycloak19                |     at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
keycloak19                |     at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:380)
keycloak19                |     at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:358)
keycloak19                |     at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
keycloak19                |     at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
keycloak19                |     at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
keycloak19                |     at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$1(QuarkusRequestFilter.java:90)
keycloak19                |     at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
keycloak19                |     at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
keycloak19                |     at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
keycloak19                |     at io.quarkus.vertx.core.runtime.VertxCoreRecorder$13.runWith(VertxCoreRecorder.java:545)
keycloak19                |     at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2449)
keycloak19                |     at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1478)
keycloak19                |     at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
keycloak19                |     at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
keycloak19                |     at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
keycloak19                |     at java.base/java.lang.Thread.run(Thread.java:829)
keycloak19                | Caused by: com.danielfrak.code.keycloak.providers.rest.rest.http.HttpRequestException: An error occurred while making a HTTP request: GET http://host.docker.internal:5000/api/keycloak/usermigration/testteacher_cleqacs3b0005kr3j5l6fm8em HTTP/1.1
keycloak19                |     at com.danielfrak.code.keycloak.providers.rest.rest.http.HttpClient.execute(HttpClient.java:69)
keycloak19                |     at com.danielfrak.code.keycloak.providers.rest.rest.http.HttpClient.get(HttpClient.java:57)
keycloak19                |     at com.danielfrak.code.keycloak.providers.rest.rest.RestUserService.findLegacyUser(RestUserService.java:73)
keycloak19                |     ... 75 more
keycloak19                | Caused by: org.apache.http.conn.HttpHostConnectException: Connect to host.docker.internal:5000 [host.docker.internal/192.168.65.2] failed: Connection refused (Connection refused)
keycloak19                |     at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:156)
keycloak19                |     at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)
keycloak19                |     at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)
keycloak19                |     at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)
keycloak19                |     at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
keycloak19                |     at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
keycloak19                |     at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
keycloak19                |     at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
keycloak19                |     at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
keycloak19                |     at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
keycloak19                |     at com.danielfrak.code.keycloak.providers.rest.rest.http.HttpClient.execute(HttpClient.java:65)
keycloak19                |     ... 77 more
keycloak19                | Caused by: java.net.ConnectException: Connection refused (Connection refused)
keycloak19                |     at java.base/java.net.PlainSocketImpl.socketConnect(Native Method)
keycloak19                |     at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:412)
keycloak19                |     at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:255)
keycloak19                |     at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:237)
keycloak19                |     at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
keycloak19                |     at java.base/java.net.Socket.connect(Socket.java:609)
keycloak19                |     at org.apache.http.conn.socket.PlainConnectionSocketFactory.connectSocket(PlainConnectionSocketFactory.java:75)
keycloak19                |     at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)
keycloak19                |     ... 87 more
daniel-frak commented 1 year ago

I honestly haven't given much thought to the probability of the migration API not being available, as I didn't think the plugin would be used at any other time than during logging in (the Keycloak docs for the interfaces aren't the best).

Just to be sure, do I understand correctly that the issue is Keycloak calling the migration API when creating a user through the Keycloak UI?

Off the top of my head, it should be fairly easy to modify RestUserService::findLegacyUser to return an empty Optional if the remote service can't be reached, though I'm not sure if I'll have the time to do that soon, and then there's the problem of not being notified that the server is down. I suppose this could be remedied by logging an error before returning an empty Optional.

On the other hand, the best solution would be to make Keycloak not use RestUserService in instances other than logging in, but I'm not sure if that is possible.

The problem definitely needs some investigating. If it's urgent, feel free to take a look at the code yourself, probably starting with LegacyProvider :)