Keycloak as broker - Token is no longer valid

705 views
Skip to first unread message

yan guitteaud

unread,
Feb 24, 2023, 3:08:38 PM2/24/23
to Keycloak User
Hey guys,

In my keycloak instance launched on a test server, i configured an identity provider nicely with well-known openid configuration.

When i try to connect to Keycloak client account home url (https://MY_KEYCLOAK_SERVER_URL/realms/MY_REALM_NAME/account/), i select my IDP and i'm well redirect to it's login page, i fill my user credentials and when i submit the page, i get this error :
"Unexpected error when authenticating with identity provider"

In keycloak server logs, i have this error :
2023-02-24 20:07:20,390 DEBUG [org.keycloak.services.scheduled.ScheduledTaskRunner] (Timer-0) Executed scheduled task AbstractLastSessionRefreshStoreFactory$$Lambda$1323/0x0000000840bb1c40
2023-02-24 20:07:22,496 DEBUG [org.keycloak.services.resources.SessionCodeChecks] (executor-thread-4) Will use client 'account-console' in back-to-application link
2023-02-24 20:07:22,497 DEBUG [org.keycloak.services.util.CookieHelper] (executor-thread-4) AUTH_SESSION_ID cookie found in the request header
2023-02-24 20:07:22,497 DEBUG [org.keycloak.services.util.CookieHelper] (executor-thread-4) AUTH_SESSION_ID cookie found in the cookie field
2023-02-24 20:07:22,497 DEBUG [org.keycloak.services.managers.AuthenticationSessionManager] (executor-thread-4) Found AUTH_SESSION_ID cookie with value bbf81d41-7623-4e17-a30b-2b68b9bd9679.app4-inte
gration-61742
2023-02-24 20:07:22,498 DEBUG [org.keycloak.services.resources.IdentityBrokerService] (executor-thread-4) Authorization code is valid.
2023-02-24 20:07:22,503 DEBUG [org.keycloak.connections.httpclient.DefaultHttpClientFactory] (executor-thread-4) Trying to use proxy mapping from env vars
2023-02-24 20:07:22,504 DEBUG [org.keycloak.connections.httpclient.DefaultHttpClientFactory] (executor-thread-4) httpProxy: null, noProxy: null
2023-02-24 20:07:22,506 WARN  [org.keycloak.connections.httpclient.DefaultHttpClientFactory] (executor-thread-4) TruststoreProvider is disabled
2023-02-24 20:07:23,451 DEBUG [org.keycloak.keys.infinispan.InfinispanPublicKeyStorageProvider] (executor-thread-4) Public keys retrieved successfully for model f41c2983-c1ee-467c-8771-af0735d6964b:
:idp::6ee65f96-d5ba-487c-9e14-5e1a4c0b3649. New kids: [ed3c42c210d4a942bcb9bb78b86ed339e657caf223916b9ddf5f7bb8218641845379c04ddbea1889e888b644850b387cded1a169f7af4e9545b53e43a7da82e6sig]
2023-02-24 20:07:23,457 ERROR [org.keycloak.broker.oidc.AbstractOAuth2IdentityProvider] (executor-thread-6) Failed to make identity provider oauth callback: org.keycloak.broker.provider.IdentityBrok
erException: Token is no longer valid

        at org.keycloak.broker.oidc.OIDCIdentityProvider.validateToken(OIDCIdentityProvider.java:629)
        at org.keycloak.broker.oidc.OIDCIdentityProvider.validateToken(OIDCIdentityProvider.java:607)
        at org.keycloak.broker.oidc.OIDCIdentityProvider.getFederatedIdentity(OIDCIdentityProvider.java:388)
        at org.keycloak.broker.oidc.AbstractOAuth2IdentityProvider$Endpoint.authResponse(AbstractOAuth2IdentityProvider.java:505)


With the identity provider workers, we tried to modify keycloak realm settings like :
  • Access Token Lifespan (2 days)
  • Access Token Lifespan For Implicit Flow   (4 days)
  • Client Login Timeout   (4 days)
  • User-Initiated Action Lifespan   (2 days)
  • Default Admin-Initiated Action Lifespan  (2 days)
I tried with keycloak version 20.0.2 and 21.0.0.

We passed theses values as days to be sure it was not a expiration token problem.
We verified the two server Keycloak and the IDP one, they have the same timezone, the redirect uri is well specified.
We checked also token signature validation.

At this point, we don't know what to do more to figure out this error ?
Can anyone please give an help ?

Prejish Nair

unread,
Nov 9, 2023, 12:37:27 AM11/9/23
to Keycloak User
Hi All,
I am Also facing somewhat similar issue.
Key
I have created 2 key cloak instances in docker container with different ports 8085:8080
8086:8080
KEYCLOAK_VERSION=22.0.1
One acts as a broker 
Another one acts as a provider
I followed the steps mentioned in this link

I login to 
http://localhost:8085/realms/keycloak-broker/account/#/
I see a very good option of my identity provider which I configured.
Screenshot 2023-11-08 at 18.51.37.png
Click on that keycloak-oidc which redirects me to the provider log in page and when I try to enter using the configured username and password I see below error 

Please let me know if anyone has faced similar problem.

Any help would be really appreciated 

2023-11-08 18:19:01 2023-11-08 17:19:01,260 ERROR [org.keycloak.broker.oidc.AbstractOAuth2IdentityProvider] (executor-thread-30) Failed to make identity provider oauth callback: org.apache.http.conn.HttpHostConnectException: Connect to localhost:8086 [localhost/127.0.0.1] failed: Connection refused
2023-11-08 18:19:01     at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:156)
2023-11-08 18:19:01     at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:376)
2023-11-08 18:19:01     at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:393)
2023-11-08 18:19:01     at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:236)
2023-11-08 18:19:01     at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
2023-11-08 18:19:01     at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
2023-11-08 18:19:01     at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
2023-11-08 18:19:01     at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
2023-11-08 18:19:01     at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
2023-11-08 18:19:01     at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
2023-11-08 18:19:01     at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
2023-11-08 18:19:01     at org.keycloak.broker.provider.util.SimpleHttp.makeRequest(SimpleHttp.java:292)
2023-11-08 18:19:01     at org.keycloak.broker.provider.util.SimpleHttp.asResponse(SimpleHttp.java:229)
2023-11-08 18:19:01     at org.keycloak.broker.provider.util.SimpleHttp.asString(SimpleHttp.java:221)
2023-11-08 18:19:01     at org.keycloak.broker.oidc.AbstractOAuth2IdentityProvider$Endpoint.authResponse(AbstractOAuth2IdentityProvider.java:503)
2023-11-08 18:19:01     at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2023-11-08 18:19:01     at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
2023-11-08 18:19:01     at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2023-11-08 18:19:01     at java.base/java.lang.reflect.Method.invoke(Method.java:568)
2023-11-08 18:19:01     at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:154)
2023-11-08 18:19:01     at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:118)
2023-11-08 18:19:01     at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:560)
2023-11-08 18:19:01     at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:452)
2023-11-08 18:19:01     at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:413)
2023-11-08 18:19:01     at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:321)
2023-11-08 18:19:01     at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:415)
2023-11-08 18:19:01     at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:378)
2023-11-08 18:19:01     at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:174)
2023-11-08 18:19:01     at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:142)
2023-11-08 18:19:01     at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:168)
2023-11-08 18:19:01     at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:131)
2023-11-08 18:19:01     at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:33)
2023-11-08 18:19:01     at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:429)
2023-11-08 18:19:01     at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:240)
2023-11-08 18:19:01     at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:154)
2023-11-08 18:19:01     at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:321)
2023-11-08 18:19:01     at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:157)
2023-11-08 18:19:01     at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:229)
2023-11-08 18:19:01     at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:82)
2023-11-08 18:19:01     at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:147)
2023-11-08 18:19:01     at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:84)
2023-11-08 18:19:01     at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:44)
2023-11-08 18:19:01     at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
2023-11-08 18:19:01     at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
2023-11-08 18:19:01     at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
2023-11-08 18:19:01     at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$1.handle(HttpServerCommonHandlers.java:58)
2023-11-08 18:19:01     at io.quarkus.vertx.http.runtime.options.HttpServerCommonHandlers$1.handle(HttpServerCommonHandlers.java:36)
2023-11-08 18:19:01     at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
2023-11-08 18:19:01     at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
2023-11-08 18:19:01     at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
2023-11-08 18:19:01     at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$0(QuarkusRequestFilter.java:82)
2023-11-08 18:19:01     at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
2023-11-08 18:19:01     at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
2023-11-08 18:19:01     at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
2023-11-08 18:19:01     at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
2023-11-08 18:19:01     at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
2023-11-08 18:19:01     at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
2023-11-08 18:19:01     at java.base/java.lang.Thread.run(Thread.java:833)
2023-11-08 18:19:01 Caused by: java.net.ConnectException: Connection refused
2023-11-08 18:19:01     at java.base/sun.nio.ch.Net.connect0(Native Method)
2023-11-08 18:19:01     at java.base/sun.nio.ch.Net.connect(Net.java:579)
2023-11-08 18:19:01     at java.base/sun.nio.ch.Net.connect(Net.java:568)
2023-11-08 18:19:01     at java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:593)
2023-11-08 18:19:01     at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327)
2023-11-08 18:19:01     at java.base/java.net.Socket.connect(Socket.java:633)
2023-11-08 18:19:01     at org.apache.http.conn.socket.PlainConnectionSocketFactory.connectSocket(PlainConnectionSocketFactory.java:75)
2023-11-08 18:19:01     at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142)
2023-11-08 18:19:01     ... 57 more
2023-11-08 18:19:01
2023-11-08 18:19:01 2023-11-08 17:19:01,262 WARN  [org.keycloak.events] (executor-thread-30) type=IDENTITY_PROVIDER_LOGIN_ERROR, realmId=5b47c62c-1bce-4cdc-9e3b-13614cfd4960, clientId=account-console, userId=null, ipAddress=172.19.0.1, error=identity_provider_login_failure, code_id=269f4049-3aaa-4c6d-af79-e2f9babda8e0

Reply all
Reply to author
Forward
0 new messages