[keycloak-user] Introspection of RPT fails
stefan.wachter
stefan.wachter at bosch-si.com
Mon Jul 16 07:54:56 EDT 2018
Any news on this? Should I file a ticket?
Best regards,
*Stefan Wachter
INST-ICM/BSV-BS*
Tel. +49(711)811-58477
*Be**QIK
*
Am 10.07.2018 um 17:33 schrieb Pedro Igor Silva:
> Will check this out. Thanks for the report.
>
> On Tue, Jul 10, 2018 at 4:57 AM, stefan.wachter
> <stefan.wachter at bosch-si.com <mailto:stefan.wachter at bosch-si.com>> wrote:
>
> Hi,
>
> I have difficulties in determining the cause why introspection of
> an RPT
> fails. The RPT can be introspected a couple of times before it
> fails. In
> the log shown below I grepped for "task-26" that seems to have
> handled
> the failed introspection request.
>
> I have the impression that the problem is related to token
> refreshments.
> If the "Access Token Lifespan" is set to a smaller value (e.g. 1
> minute), then the failure happens earlier. In particular, it seems
> that
> after the SECOND set of token refreshments the introspection
> fails. In
> detail:
>
> There are 3 tokens (together with their refresh tokens) involved:
>
> 1. An IdToken that is used for logging into the web application. The
> IdToken is used when a Ticket is exchanged for an RPT (the IdToken is
> set as the "claim_token" parameter in the token request).
>
> 2. An RPT.
>
> 3. A PAT
>
> When a request hits the application after the tokens have expired the
> first time all tokens are refreshed in turn and the introspection
> succeedes. Yet, if a request hits the application after the tokens
> have
> expired the second time then all tokens are refreshed again (using
> the
> refresh tokens that were returned on the first refreshment). The
> following RPT introspection however, fails.
>
> Has anyone experienced the same failure?
>
> Thanks for you attention
>
> Stefan
>
>
>
> 06:46:12,779 DEBUG
> [org.keycloak.authorization.protection.introspect.RPTIntrospectionProvider]
>
> (default task-26) Introspecting requesting party token
> 06:46:12,779 TRACE [org.keycloak.keys.DefaultKeyManager] (default
> task-26) Active key found: realm=device
> kid=t00ewHrCADcXjvvIFBWQrZnOWiBTVBoyt0-UOzBP7w0 algorithm=RS256
> 06:46:12,779 TRACE [org.keycloak.keys.DefaultKeyManager] (default
> task-26) Active key found: realm=device
> kid=ae1f030a-b3a5-4c9a-875a-a0802119fa2a algorithm=HS256
> 06:46:12,779 TRACE [org.keycloak.keys.DefaultKeyManager] (default
> task-26) Active key found: realm=device
> kid=2aefcc15-33cf-45f6-a4bf-88535501712c algorithm=AES
> 06:46:12,779 TRACE [org.keycloak.keys.DefaultKeyManager] (default
> task-26) Active key realm=device
> kid=t00ewHrCADcXjvvIFBWQrZnOWiBTVBoyt0-UOzBP7w0 algorithm=RS256
> 06:46:12,780 TRACE
> [org.infinispan.interceptors.InvocationContextInterceptor] (default
> task-26) Invoked with command GetKeyValueCommand
> {key=device.client.query.by
> <http://device.client.query.by>.clientId.web-gui, flags=null} and
> InvocationContext
> [org.infinispan.context.SingleKeyNonTxInvocationContext at 6cb8a247]
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Exists in context? null
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Retrieved from container
> ImmortalCacheEntry{key=device.client.query.by.clientId.web-gui,
> value=0}
> (ignoreOwnership=false, isLocal=true)
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Wrap device.client.query.by
> <http://device.client.query.by>.clientId.web-gui for read.
> Entry=ImmortalCacheEntry{key=device.client.query.by
> <http://device.client.query.by>.clientId.web-gui,
> value=0}
> 06:46:12,780 TRACE [org.infinispan.interceptors.CallInterceptor]
> (default task-26) Executing command: GetKeyValueCommand
> {key=device.client.query.by
> <http://device.client.query.by>.clientId.web-gui, flags=null}.
> 06:46:12,780 TRACE
> [org.infinispan.util.concurrent.locks.impl.DefaultLockManager]
> (default
> task-26) Release locks for keys=[]. owner=null
> 06:46:12,780 TRACE
> [org.keycloak.models.cache.infinispan.RealmCacheSession] (default
> task-26) client by name cache hit: web-gui
> 06:46:12,780 TRACE
> [org.infinispan.interceptors.InvocationContextInterceptor] (default
> task-26) Invoked with command GetKeyValueCommand
> {key=b5f94341-0d4c-4280-94e1-10b6771cd66c, flags=null} and
> InvocationContext
> [org.infinispan.context.SingleKeyNonTxInvocationContext at 3a2141a6]
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Exists in context? null
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Retrieved from container
> ImmortalCacheEntry{key=b5f94341-0d4c-4280-94e1-10b6771cd66c, value=0}
> (ignoreOwnership=false, isLocal=true)
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Wrap b5f94341-0d4c-4280-94e1-10b6771cd66c for read.
> Entry=ImmortalCacheEntry{key=b5f94341-0d4c-4280-94e1-10b6771cd66c,
> value=0}
> 06:46:12,780 TRACE [org.infinispan.interceptors.CallInterceptor]
> (default task-26) Executing command: GetKeyValueCommand
> {key=b5f94341-0d4c-4280-94e1-10b6771cd66c, flags=null}.
> 06:46:12,780 TRACE
> [org.infinispan.util.concurrent.locks.impl.DefaultLockManager]
> (default
> task-26) Release locks for keys=[]. owner=null
> 06:46:12,780 TRACE
> [org.keycloak.models.cache.infinispan.RealmCacheSession] (default
> task-26) client by id cache hit: web-gui
> 06:46:12,780 TRACE
> [org.infinispan.interceptors.InvocationContextInterceptor] (default
> task-26) Invoked with command GetKeyValueCommand {key=device,
> flags=null} and InvocationContext
> [org.infinispan.context.SingleKeyNonTxInvocationContext at 2f9442f3]
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Exists in context? null
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Retrieved from container ImmortalCacheEntry{key=device,
> value=0} (ignoreOwnership=false, isLocal=true)
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Wrap device for read.
> Entry=ImmortalCacheEntry{key=device, value=0}
> 06:46:12,780 TRACE [org.infinispan.interceptors.CallInterceptor]
> (default task-26) Executing command: GetKeyValueCommand {key=device,
> flags=null}.
> 06:46:12,780 TRACE
> [org.infinispan.util.concurrent.locks.impl.DefaultLockManager]
> (default
> task-26) Release locks for keys=[]. owner=null
> 06:46:12,780 TRACE
> [org.keycloak.models.cache.infinispan.RealmCacheSession] (default
> task-26) by id cache hit: device
> 06:46:12,780 TRACE
> [org.infinispan.interceptors.InvocationContextInterceptor] (default
> task-26) Invoked with command GetKeyValueCommand
> {key=b5f94341-0d4c-4280-94e1-10b6771cd66c, flags=null} and
> InvocationContext
> [org.infinispan.context.SingleKeyNonTxInvocationContext at 30227841]
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Exists in context? null
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Retrieved from container
> ImmortalCacheEntry{key=b5f94341-0d4c-4280-94e1-10b6771cd66c, value=0}
> (ignoreOwnership=false, isLocal=true)
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Wrap b5f94341-0d4c-4280-94e1-10b6771cd66c for read.
> Entry=ImmortalCacheEntry{key=b5f94341-0d4c-4280-94e1-10b6771cd66c,
> value=0}
> 06:46:12,780 TRACE [org.infinispan.interceptors.CallInterceptor]
> (default task-26) Executing command: GetKeyValueCommand
> {key=b5f94341-0d4c-4280-94e1-10b6771cd66c, flags=null}.
> 06:46:12,780 TRACE
> [org.infinispan.util.concurrent.locks.impl.DefaultLockManager]
> (default
> task-26) Release locks for keys=[]. owner=null
> 06:46:12,780 TRACE
> [org.keycloak.models.cache.infinispan.RealmCacheSession] (default
> task-26) client by id cache hit: web-gui
> 06:46:12,780 TRACE
> [org.infinispan.interceptors.InvocationContextInterceptor] (default
> task-26) Invoked with command GetKeyValueCommand {key=device,
> flags=null} and InvocationContext
> [org.infinispan.context.SingleKeyNonTxInvocationContext at 19214e98]
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Exists in context? null
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Retrieved from container ImmortalCacheEntry{key=device,
> value=0} (ignoreOwnership=false, isLocal=true)
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Wrap device for read.
> Entry=ImmortalCacheEntry{key=device, value=0}
> 06:46:12,780 TRACE [org.infinispan.interceptors.CallInterceptor]
> (default task-26) Executing command: GetKeyValueCommand {key=device,
> flags=null}.
> 06:46:12,780 TRACE
> [org.infinispan.util.concurrent.locks.impl.DefaultLockManager]
> (default
> task-26) Release locks for keys=[]. owner=null
> 06:46:12,780 TRACE
> [org.keycloak.models.cache.infinispan.RealmCacheSession] (default
> task-26) by id cache hit: device
> 06:46:12,780 DEBUG
> [org.keycloak.models.sessions.infinispan.InfinispanUserSessionProvider]
>
> (default task-26)
> getUserSessionWithPredicate(a3320548-da14-4e0c-adc1-5616c9d0c23b):
> found
> in local cache
> 06:46:12,780 TRACE
> [org.keycloak.models.cache.infinispan.UserCacheSession] (default
> task-26) getuserById d22c43c4-04fb-4756-82d6-fc9fe3bd9e8c
> 06:46:12,780 TRACE
> [org.infinispan.interceptors.InvocationContextInterceptor] (default
> task-26) Invoked with command GetKeyValueCommand
> {key=d22c43c4-04fb-4756-82d6-fc9fe3bd9e8c, flags=null} and
> InvocationContext
> [org.infinispan.context.SingleKeyNonTxInvocationContext at 29bd006b]
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Exists in context? null
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Retrieved from container
> ImmortalCacheEntry{key=d22c43c4-04fb-4756-82d6-fc9fe3bd9e8c, value=0}
> (ignoreOwnership=false, isLocal=true)
> 06:46:12,780 TRACE [org.infinispan.container.EntryFactoryImpl]
> (default
> task-26) Wrap d22c43c4-04fb-4756-82d6-fc9fe3bd9e8c for read.
> Entry=ImmortalCacheEntry{key=d22c43c4-04fb-4756-82d6-fc9fe3bd9e8c,
> value=0}
> 06:46:12,780 TRACE [org.infinispan.interceptors.CallInterceptor]
> (default task-26) Executing command: GetKeyValueCommand
> {key=d22c43c4-04fb-4756-82d6-fc9fe3bd9e8c, flags=null}.
> 06:46:12,780 TRACE
> [org.infinispan.util.concurrent.locks.impl.DefaultLockManager]
> (default
> task-26) Release locks for keys=[]. owner=null
> 06:46:12,780 TRACE
> [org.keycloak.models.cache.infinispan.UserCacheSession] (default
> task-26) getuserById d22c43c4-04fb-4756-82d6-fc9fe3bd9e8c
> 06:46:12,780 TRACE
> [org.keycloak.models.cache.infinispan.UserCacheSession] (default
> task-26) return managedusers
> 06:46:12,781 TRACE [org.keycloak.events] (default task-26)
> type=INTROSPECT_TOKEN_ERROR, realmId=device,
> clientId=resource-server,
> userId=null, ipAddress=139.15.216.71, error=invalid_request,
> detail='Failed to introspect token.',
> client_auth_method=client-secret,
> requestUri=https://keycloak.apps.de1.bosch-iot-cloud.com/auth/realms/device/protocol/openid-connect/token/introspect
> <https://keycloak.apps.de1.bosch-iot-cloud.com/auth/realms/device/protocol/openid-connect/token/introspect>,
>
> cookies=[]
>
> --
>
> Best regards,
>
> *Stefan Wachter
> INST-ICM/BSV-BS*
>
> Tel. +49(711)811-58477
>
> *Be**QIK
> *
>
> _______________________________________________
> keycloak-user mailing list
> keycloak-user at lists.jboss.org <mailto:keycloak-user at lists.jboss.org>
> https://lists.jboss.org/mailman/listinfo/keycloak-user
> <https://lists.jboss.org/mailman/listinfo/keycloak-user>
>
>
More information about the keycloak-user
mailing list