[keycloak-user] Introspection of RPT fails

Mon Jul 16 14:28:05 EDT 2018

Hi,

I've created https://issues.jboss.org/browse/KEYCLOAK-7864. Pull request
also sent with a fix.

The issue is that we were not setting the authorization claim to refresh
tokens issued via grant_type == refresh_token.

Thanks.
Pedro Igor

On Mon, Jul 16, 2018 at 8:54 AM, stefan.wachter <stefan.wachter at bosch-si.com
> wrote:

> 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> 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.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.clientId.web-gui for read.
>> Entry=ImmortalCacheEntry{key=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.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/aut
>> h/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
>> https://lists.jboss.org/mailman/listinfo/keycloak-user
>
>
>
>