Entra ID IDP: Timeout and transaction issues on login completion

Getting advice
1

Hello everyone,

I am currently setting up Entra ID as an identity provider for my Keycloak 25.0.1 instance. I have followed the instructions in this tutorial and the redirection to Entra ID is already successful. I can select the account in the Entra tenant, login with MFA and also accept the permission prompt.

However, when Entra ID redirects the user back to https://<keycloak-url>/realms/<realm-name>/broker/<idp-name>/endpoint, the request times out since Keycloak does not respond within ~30 seconds.

While the logs show no error message directly when this happens, some time later, I can see several logs (INFO/WARN/ERROR) from com.arjuna.ats.arjuna regarding transaction issues. The following logs might be indicating that an issue occurs when Keycloak performs an HTTP request to Entra ID (since AbstractOAuth2IdentityProvider is near the end of the stack):

com.arjuna.ats.arjuna WARN:
ARJUNA012117: TransactionReaper::check processing TX 2a05d0140403ff02:-3186fffffffffffe:afe9:668bd295:39 in state  RUN

com.arjuna.ats.arjuna INFO:
ARJUNA012404: Action id 2a05d0140403ff02:-3186fffffffffffe:afe9:668bd295:39 - thread executor-thread-1 at time 11:55:48.852 had stackTrace java.base/sun.nio.ch.Net.connect0(Native Method)
java.base/sun.nio.ch.Net.connect(Net.java:589)
java.base/sun.nio.ch.Net.connect(Net.java:578)
java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:583)
java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)
java.base/java.net.Socket.connect(Socket.java:751)
org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:368)
org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)
org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)
org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)
org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)
org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
org.keycloak.broker.provider.util.SimpleHttp.makeRequest(SimpleHttp.java:326)
org.keycloak.broker.provider.util.SimpleHttp.asResponse(SimpleHttp.java:256)
org.keycloak.broker.oidc.AbstractOAuth2IdentityProvider$Endpoint.authResponse(AbstractOAuth2IdentityProvider.java:545)
org.keycloak.broker.oidc.AbstractOAuth2IdentityProvider$Endpoint$quarkusrestinvoker$authResponse_ab908fbdd086ee82e140d8a818c077362a2d04b4.invoke(Unknown Source)
org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582)
org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
java.base/java.lang.Thread.run(Thread.java:1583)

com.arjuna.ats.arjuna WARN:
ARJUNA012095: Abort of action id 2a05d0140403ff02:-3186fffffffffffe:afe9:668bd295:39 invoked while multiple threads active within it.

There are more logs for the transaction between these, but I dont want to pollute this post unless the information is needed.

In some occasions, the following log also appears (formatted for readability) and seems to indicate that the login procedure is taking too long(?):

org.keycloak.broker.oidc.AbstractOAuth2IdentityProvider ERROR:
Unexpected response from token endpoint https://login.microsoftonline.com/<tenant-id>/oauth2/v2.0/token.
status=400,
response={
  "error": "invalid_grant",
  "error_description": "AADSTS70008: The provided authorization code or refresh token has expired due to inactivity. Send a new interactive authorization request for this user and resource.",
  "error_codes": [70008],
  "timestamp": "-",
  "trace_id": "-",
  "correlation_id": "-",
  "error_uri": "https://login.microsoftonline.com/error?code=70008",
}

I am unsure where to continue with the debugging as I lack knowledge of the Keycloak internals that are involved here. Can this be an issue with the identity provider configuration or is it an issue of the Keycloak setup itself (such as resources or similar)?

Any help would be very appreciated. Best regards,
Janek

2

From your posted stacktrace, I‘d assume that your KC server can‘t reach properly EntraID, likely due to https problems (that‘s what the logs say…)

3

Hi, thanks for your reply.
I was thinking about this possibility too, but based on the last error log message in my post, it seems like it does get a 400 BAD REQUEST response from the Entra token endpoint.

Since the Keycloak image does not contain utilities like curl, I wasnt able to verify the connectivity directly from Keycloak yet, but I can at least say that other pods in my cluster can reach the Entra endpoints.

4

I was able to get some further insight. I now configured a fresh Keycloak instance and tried to set up the Identity Provider via the admin console UI (previously, I imported it via the files). When I inserted the Discovery endpoint (https://login.microsoftonline.com/<tenant-id>/v2.0/.well-known/openid-configuration), the call to Keycloaks /import-config endpoint took 60 seconds and was then timed out by my load balancer.

The Keycloak logs show the already known errors:

{
  "timestamp": "2024-07-09T07:01:18.284437418Z",
  "sequence": 10086,
  "loggerClassName": "com.arjuna.ats.arjuna.logging.arjunaI18NLogger_$logger",
  "loggerName": "com.arjuna.ats.arjuna",
  "level": "WARN",
  "message": "ARJUNA012117: TransactionReaper::check processing TX 2a05d0140403ff02:-3b46ffffffffffff:8ac5:668cddc2:13b in state  RUN",
  "threadName": "Transaction Reaper",
  "threadId": 52,
  "mdc": {},
  "ndc": "",
  "hostName": "dev-keycloak-5dfb95b46c-b6m25",
  "processName": "QuarkusEntryPoint",
  "processId": 1
}
{
  "timestamp": "2024-07-09T07:01:18.286552663Z",
  "sequence": 10087,
  "loggerClassName": "com.arjuna.ats.arjuna.logging.arjunaI18NLogger_$logger",
  "loggerName": "com.arjuna.ats.arjuna",
  "level": "INFO",
  "message": "ARJUNA012404: Action id 2a05d0140403ff02:-3b46ffffffffffff:8ac5:668cddc2:13b - thread executor-thread-10 at time 06:59:18.286 had stackTrace java.base/sun.nio.ch.Net.connect0(Native Method)\njava.base/sun.nio.ch.Net.connect(Net.java:589)\njava.base/sun.nio.ch.Net.connect(Net.java:578)\njava.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:583)\njava.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)\njava.base/java.net.Socket.connect(Socket.java:751)\norg.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:368)\norg.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)\norg.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)\norg.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)\norg.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)\norg.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)\norg.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)\norg.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)\norg.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)\norg.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)\norg.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)\norg.keycloak.connections.httpclient.DefaultHttpClientFactory$1.getString(DefaultHttpClientFactory.java:123)\norg.keycloak.services.resources.admin.IdentityProvidersResource.importFrom(IdentityProvidersResource.java:158)\norg.keycloak.services.resources.admin.IdentityProvidersResource$quarkusrestinvoker$importFrom_a2928105606b1cfb77befafeb917cf58b5abe0c4.invoke(Unknown Source)\norg.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)\nio.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)\norg.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)\nio.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582)\norg.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)\norg.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)\norg.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)\norg.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)\nio.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)\njava.base/java.lang.Thread.run(Thread.java:1583)\n",
  "threadName": "Transaction Reaper Worker 0",
  "threadId": 53,
  "mdc": {},
  "ndc": "",
  "hostName": "dev-keycloak-5dfb95b46c-b6m25",
  "processName": "QuarkusEntryPoint",
  "processId": 1
}
{
  "timestamp": "2024-07-09T07:01:18.287201233Z",
  "sequence": 10088,
  "loggerClassName": "com.arjuna.ats.arjuna.logging.arjunaI18NLogger_$logger",
  "loggerName": "com.arjuna.ats.arjuna",
  "level": "INFO",
  "message": "ARJUNA012404: Action id 2a05d0140403ff02:-3b46ffffffffffff:8ac5:668cddc2:13b - thread executor-thread-10 at time 06:59:48.285 had stackTrace java.base/sun.nio.ch.Net.connect0(Native Method)\njava.base/sun.nio.ch.Net.connect(Net.java:589)\njava.base/sun.nio.ch.Net.connect(Net.java:578)\njava.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:583)\njava.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)\njava.base/java.net.Socket.connect(Socket.java:751)\norg.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:368)\norg.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)\norg.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)\norg.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)\norg.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)\norg.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)\norg.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)\norg.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)\norg.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)\norg.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)\norg.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)\norg.keycloak.connections.httpclient.DefaultHttpClientFactory$1.getString(DefaultHttpClientFactory.java:123)\norg.keycloak.services.resources.admin.IdentityProvidersResource.importFrom(IdentityProvidersResource.java:158)\norg.keycloak.services.resources.admin.IdentityProvidersResource$quarkusrestinvoker$importFrom_a2928105606b1cfb77befafeb917cf58b5abe0c4.invoke(Unknown Source)\norg.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)\nio.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)\norg.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)\nio.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582)\norg.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)\norg.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)\norg.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)\norg.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)\nio.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)\njava.base/java.lang.Thread.run(Thread.java:1583)\n",
  "threadName": "Transaction Reaper Worker 0",
  "threadId": 53,
  "mdc": {},
  "ndc": "",
  "hostName": "dev-keycloak-5dfb95b46c-b6m25",
  "processName": "QuarkusEntryPoint",
  "processId": 1
}
{
  "timestamp": "2024-07-09T07:01:18.287664951Z",
  "sequence": 10089,
  "loggerClassName": "com.arjuna.ats.arjuna.logging.arjunaI18NLogger_$logger",
  "loggerName": "com.arjuna.ats.arjuna",
  "level": "INFO",
  "message": "ARJUNA012404: Action id 2a05d0140403ff02:-3b46ffffffffffff:8ac5:668cddc2:13b - thread executor-thread-10 at time 07:00:18.285 had stackTrace java.base/sun.nio.ch.Net.connect0(Native Method)\njava.base/sun.nio.ch.Net.connect(Net.java:589)\njava.base/sun.nio.ch.Net.connect(Net.java:578)\njava.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:583)\njava.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)\njava.base/java.net.Socket.connect(Socket.java:751)\norg.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:368)\norg.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)\norg.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)\norg.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)\norg.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)\norg.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)\norg.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)\norg.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)\norg.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)\norg.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)\norg.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)\norg.keycloak.connections.httpclient.DefaultHttpClientFactory$1.getString(DefaultHttpClientFactory.java:123)\norg.keycloak.services.resources.admin.IdentityProvidersResource.importFrom(IdentityProvidersResource.java:158)\norg.keycloak.services.resources.admin.IdentityProvidersResource$quarkusrestinvoker$importFrom_a2928105606b1cfb77befafeb917cf58b5abe0c4.invoke(Unknown Source)\norg.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)\nio.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)\norg.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)\nio.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582)\norg.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)\norg.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)\norg.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)\norg.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)\nio.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)\njava.base/java.lang.Thread.run(Thread.java:1583)\n",
  "threadName": "Transaction Reaper Worker 0",
  "threadId": 53,
  "mdc": {},
  "ndc": "",
  "hostName": "dev-keycloak-5dfb95b46c-b6m25",
  "processName": "QuarkusEntryPoint",
  "processId": 1
}
{
  "timestamp": "2024-07-09T07:01:18.288084838Z",
  "sequence": 10090,
  "loggerClassName": "com.arjuna.ats.arjuna.logging.arjunaI18NLogger_$logger",
  "loggerName": "com.arjuna.ats.arjuna",
  "level": "INFO",
  "message": "ARJUNA012404: Action id 2a05d0140403ff02:-3b46ffffffffffff:8ac5:668cddc2:13b - thread executor-thread-10 at time 07:00:48.286 had stackTrace java.base/sun.nio.ch.Net.connect0(Native Method)\njava.base/sun.nio.ch.Net.connect(Net.java:589)\njava.base/sun.nio.ch.Net.connect(Net.java:578)\njava.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:583)\njava.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)\njava.base/java.net.Socket.connect(Socket.java:751)\norg.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:368)\norg.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)\norg.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)\norg.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)\norg.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)\norg.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)\norg.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)\norg.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)\norg.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)\norg.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)\norg.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)\norg.keycloak.connections.httpclient.DefaultHttpClientFactory$1.getString(DefaultHttpClientFactory.java:123)\norg.keycloak.services.resources.admin.IdentityProvidersResource.importFrom(IdentityProvidersResource.java:158)\norg.keycloak.services.resources.admin.IdentityProvidersResource$quarkusrestinvoker$importFrom_a2928105606b1cfb77befafeb917cf58b5abe0c4.invoke(Unknown Source)\norg.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)\nio.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)\norg.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)\nio.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582)\norg.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)\norg.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)\norg.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)\norg.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)\nio.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)\njava.base/java.lang.Thread.run(Thread.java:1583)\n",
  "threadName": "Transaction Reaper Worker 0",
  "threadId": 53,
  "mdc": {},
  "ndc": "",
  "hostName": "dev-keycloak-5dfb95b46c-b6m25",
  "processName": "QuarkusEntryPoint",
  "processId": 1
}
{
  "timestamp": "2024-07-09T07:01:18.291995172Z",
  "sequence": 10091,
  "loggerClassName": "com.arjuna.ats.arjuna.logging.arjunaI18NLogger_$logger",
  "loggerName": "com.arjuna.ats.arjuna",
  "level": "WARN",
  "message": "ARJUNA012095: Abort of action id 2a05d0140403ff02:-3b46ffffffffffff:8ac5:668cddc2:13b invoked while multiple threads active within it.",
  "threadName": "Transaction Reaper Worker 0",
  "threadId": 53,
  "mdc": {},
  "ndc": "",
  "hostName": "dev-keycloak-5dfb95b46c-b6m25",
  "processName": "QuarkusEntryPoint",
  "processId": 1
}
{
  "timestamp": "2024-07-09T07:01:18.292464125Z",
  "sequence": 10092,
  "loggerClassName": "com.arjuna.ats.arjuna.logging.arjunaI18NLogger_$logger",
  "loggerName": "com.arjuna.ats.arjuna",
  "level": "WARN",
  "message": "ARJUNA012381: Action id 2a05d0140403ff02:-3b46ffffffffffff:8ac5:668cddc2:13b completed with multiple threads - thread executor-thread-10 was in progress with java.base/sun.nio.ch.Net.connect0(Native Method)\njava.base/sun.nio.ch.Net.connect(Net.java:589)\njava.base/sun.nio.ch.Net.connect(Net.java:578)\njava.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:583)\njava.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)\njava.base/java.net.Socket.connect(Socket.java:751)\norg.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:368)\norg.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)\norg.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)\norg.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)\norg.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)\norg.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)\norg.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)\norg.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)\norg.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)\norg.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)\norg.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)\norg.keycloak.connections.httpclient.DefaultHttpClientFactory$1.getString(DefaultHttpClientFactory.java:123)\norg.keycloak.services.resources.admin.IdentityProvidersResource.importFrom(IdentityProvidersResource.java:158)\norg.keycloak.services.resources.admin.IdentityProvidersResource$quarkusrestinvoker$importFrom_a2928105606b1cfb77befafeb917cf58b5abe0c4.invoke(Unknown Source)\norg.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)\nio.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)\norg.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)\nio.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582)\norg.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)\norg.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)\norg.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)\norg.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)\nio.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)\njava.base/java.lang.Thread.run(Thread.java:1583)\n",
  "threadName": "Transaction Reaper Worker 0",
  "threadId": 53,
  "mdc": {},
  "ndc": "",
  "hostName": "dev-keycloak-5dfb95b46c-b6m25",
  "processName": "QuarkusEntryPoint",
  "processId": 1
}
{
  "timestamp": "2024-07-09T07:01:18.292726433Z",
  "sequence": 10093,
  "loggerClassName": "com.arjuna.ats.arjuna.logging.arjunaI18NLogger_$logger",
  "loggerName": "com.arjuna.ats.arjuna",
  "level": "WARN",
  "message": "ARJUNA012108: CheckedAction::check - atomic action 2a05d0140403ff02:-3b46ffffffffffff:8ac5:668cddc2:13b aborting with 1 threads active!",
  "threadName": "Transaction Reaper Worker 0",
  "threadId": 53,
  "mdc": {},
  "ndc": "",
  "hostName": "dev-keycloak-5dfb95b46c-b6m25",
  "processName": "QuarkusEntryPoint",
  "processId": 1
}
{
  "timestamp": "2024-07-09T07:01:18.292932536Z",
  "sequence": 10094,
  "loggerClassName": "com.arjuna.ats.arjuna.logging.arjunaI18NLogger_$logger",
  "loggerName": "com.arjuna.ats.arjuna",
  "level": "WARN",
  "message": "ARJUNA012121: TransactionReaper::doCancellations worker Thread[#53,Transaction Reaper Worker 0,5,main] successfully canceled TX 2a05d0140403ff02:-3b46ffffffffffff:8ac5:668cddc2:13b",
  "threadName": "Transaction Reaper Worker 0",
  "threadId": 53,
  "mdc": {},
  "ndc": "",
  "hostName": "dev-keycloak-5dfb95b46c-b6m25",
  "processName": "QuarkusEntryPoint",
  "processId": 1
}

I tried to use the Google OIDC Well-Known-Endpoint (https://accounts.google.com/.well-known/openid-configuration) and observed the same behaviour, except for the logs (none appeared).

I furthermore set up a custom Keycloak image that has wget installed, used kubectl exec to get into the Keycloak pod and tested the connectivity for Entra ID - worked correctly.

bash-5.1$ wget -O - https://login.microsoftonline.com/<tenant-id>/v2.0/.well-known/openid-configuration
--2024-07-09 07:45:46--  https://login.microsoftonline.com/<tenant-id>/v2.0/.well-known/openid-configuration
Resolving login.microsoftonline.com (login.microsoftonline.com)... 2603:1027:1:d8::5, 2603:1026:3000:d0::d, 2603:1027:1:d8::9, ...
Connecting to login.microsoftonline.com (login.microsoftonline.com)|2603:1027:1:d8::5|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 1753 (1.7K) [application/json]
Saving to: ‘STDOUT’

<entra response here>   

2024-07-09 07:45:47 (112 MB/s) - written to stdout [1753/1753]

Finally, I configured the IDP by manually setting the token and authorization endpoint instead of using the discovery mechanism, but the issue from my original post remains.

5

Update: I was able to resolve the issue - the initial comment regarding the network connectivity was the right path. I hope this description helps anyone in the future.

Problem:
The issue was buried in the fact that I am using an IPv6-only cluster in which DNS/NAT64 is used to allow clients to access IPv4-only pages. Keycloak seemed to attempt accessing Entra ID with IPv4, which simply resulted in the call failing because the pod has no IPv4 address.

Interestingly, the call seems to “haning” instead of being cancelled. When forcing wget to use IPv4 with --inet4-only, the same behaviour is observed, so I assume its no issue specific to Keycloak.

Resolution:
I used the java.net.preferIPv6Addresses system property to enforce Keycloak to prefer using IPv6, which solved the issue. Unfortunately, the only docs I can find on IPv6 (Configuring Keycloak for production - Keycloak) only mention the listener, but not the sender aspect (maybe because it should be obvious to someone with more Java networking experience).