Re: [keycloak-user] Introspection of RPT fails

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@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@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@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@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@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@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/devi..., cookies=[]