search

keycloak / keycloak

Open Source Identity and Access Management For Modern Applications and Services
https://www.keycloak.org
Apache License 2.0
23.09k stars 6.72k forks source link

403 Forbidden when authorizing in multitenancy keycloak with credentials #15391

Closed kelfhk closed 7 months ago

kelfhk commented 1 year ago

Area

authentication

Describe the bug

I was trying to follow the same multitenancy setup as the official documentation, but with credentials in my keycloak.json file, but keycloak does not seem to authorize access token properly.

It appears to call the resolve function of my customized KeycloakConfigResolver multiple times. It does authorize the token at the first time it calls to resolve, but it then shows 'Failed to verify token' every time after that.

And at the end, it fails to verify my access token.

Version

18.0.2

Expected behavior

Without my customized KeycloakConfigResolver, it authorizes my access token successfully.

And even with the default implementation of KeycloakConfigResolver, KeycloakSpringBootConfigResolver(), it manages to authorize my access token successfully.

I was expecting the same behavior happened to my customized resolver.

Actual behavior

The complete log of the events is shown as below:

2022-11-07 14:02:13.185 DEBUG 4492 --- [nio-8080-exec-2] o.k.adapters.PreAuthActionsHandler       : adminRequest http://localhost:8080/api/user/admin/users?access_token={access_token}
2022-11-07 14:02:13.189 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Using provider 'secret' for authentication of client {client}
2022-11-07 14:02:13.191 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.191 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.192 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.193 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.193 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.193 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.195 DEBUG 4492 --- [nio-8080-exec-2] o.k.adapters.PreAuthActionsHandler       : checkCorsPreflight http://localhost:8080/api/user/admin/users?access_token={access_token}
2022-11-07 14:02:13.203 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.BearerTokenRequestAuthenticator    : Verifying access_token
2022-11-07 14:02:13.212 DEBUG 4492 --- [nio-8080-exec-2] o.keycloak.adapters.KeycloakDeployment   : Resolving URLs from http://localhost:8443/realms/{realm}/.well-known/openid-configuration
2022-11-07 14:02:13.354  INFO 4492 --- [nio-8080-exec-2] o.keycloak.adapters.KeycloakDeployment   : Loaded URLs from http://localhost:8443/realms/{realm}.well-known/openid-configuration
2022-11-07 14:02:13.441 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.rotation.JWKPublicKeyLocator       : Realm public keys successfully retrieved for client {client}. New kids: [{kid}]
2022-11-07 14:02:13.446 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.BearerTokenRequestAuthenticator    : successful authorized
2022-11-07 14:02:13.448 DEBUG 4492 --- [nio-8080-exec-2] o.k.adapters.RequestAuthenticator        : QueryParamAuth AUTHENTICATED
2022-11-07 14:02:13.453 DEBUG 4492 --- [nio-8080-exec-2] o.k.adapters.RequestAuthenticator        : User {kc_id} invoking http://localhost:8080/api/user/admin/users?access_token={access_token}
2022-11-07 14:02:13.454 DEBUG 4492 --- [nio-8080-exec-2] .k.a.t.AbstractAuthenticatedActionsValve : AuthenticatedActionsValve.invoke /api/user/admin/users
2022-11-07 14:02:13.456 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.AuthenticatedActionsHandler        : AuthenticatedActionsValve.invoke http://localhost:8080/api/user/admin/users?access_token={access_token}
2022-11-07 14:02:13.482  INFO 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Paths provided in configuration.
2022-11-07 14:02:13.483 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Trying to find resource with name [user-resource] for path [/api/user/admin/*].
2022-11-07 14:02:13.534 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Trying to find resource with name [user-resource] for path [/api/user/manager/*].
2022-11-07 14:02:13.545 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Trying to find resource with name [user-resource] for path [/api/user/worker/*].
2022-11-07 14:02:13.552 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Trying to find resource with name [job-resource] for path [/api/job/*].
2022-11-07 14:02:13.565 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Initialization complete. Path configurations:
2022-11-07 14:02:13.565 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : PathConfig{name='user-resource', type='null', path='/api/user/admin/*', scopes=[], id='82df8be1-6890-4866-9e57-5b2c7e60b243', enforcerMode='ENFORCING'}
2022-11-07 14:02:13.565 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : PathConfig{name='user-resource', type='null', path='/api/user/manager/*', scopes=[], id='82df8be1-6890-4866-9e57-5b2c7e60b243', enforcerMode='ENFORCING'}
2022-11-07 14:02:13.565 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : PathConfig{name='user-resource', type='null', path='/api/user/worker/*', scopes=[], id='82df8be1-6890-4866-9e57-5b2c7e60b243', enforcerMode='ENFORCING'}
2022-11-07 14:02:13.565 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : PathConfig{name='job-resource', type='null', path='/api/job/*', scopes=[], id='5ed211e2-84ac-441b-b281-0d38d24baa23', enforcerMode='ENFORCING'}
2022-11-07 14:02:13.569 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.AuthenticatedActionsHandler        : Origin: null uri: http://localhost:8080/api/user/admin/users?access_token={access_token}
2022-11-07 14:02:13.570 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.AuthenticatedActionsHandler        : cors validation not needed as we are not a secure session or origin header was null: http://localhost:8080/api/user/admin/users?access_token={access_token}
2022-11-07 14:02:13.570 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Policy enforcement is enabled. Enforcing policy decisions for path [http://localhost:8080/api/user/admin/users?access_token={access_token}].
2022-11-07 14:02:13.577 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.AbstractPolicyEnforcer           : Checking permissions for path [http://localhost:8080/api/user/admin/users?access_token={access_token}] with config [PathConfig{name='user-resource', type='null', path='/api/user/admin/*', scopes=[], id='82df8be1-6890-4866-9e57-5b2c7e60b243', enforcerMode='ENFORCING'}].
2022-11-07 14:02:13.579 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.KeycloakAdapterPolicyEnforcer    : Obtaining authorization for authenticated user.
2022-11-07 14:02:13.599 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.AbstractPolicyEnforcer           : Authorization GRANTED for path [PathConfig{name='user-resource', type='null', path='/api/user/admin/*', scopes=[], id='82df8be1-6890-4866-9e57-5b2c7e60b243', enforcerMode='ENFORCING'}]. Permissions [[Permission {id=82df8be1-6890-4866-9e57-5b2c7e60b243, name=user-resource, scopes=[admin-scope]}]].
2022-11-07 14:02:13.599 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Policy enforcement result for path [http://localhost:8080/api/user/admin/users?access_token={access_token}] is : GRANTED
2022-11-07 14:02:13.599 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Returning authorization context with permissions:
2022-11-07 14:02:13.599 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Permission {id=82df8be1-6890-4866-9e57-5b2c7e60b243, name=user-resource, scopes=[admin-scope]}
2022-11-07 14:02:13.600  INFO 4492 --- [nio-8080-exec-2] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2022-11-07 14:02:13.601  INFO 4492 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-11-07 14:02:13.602  INFO 4492 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet        : Completed initialization in 1 ms
2022-11-07 14:02:13.627 DEBUG 4492 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Securing GET /api/user/admin/users?access_token={access_token}
2022-11-07 14:02:13.633 DEBUG 4492 --- [nio-8080-exec-2] s.s.w.c.SecurityContextPersistenceFilter : Set SecurityContextHolder to empty SecurityContext
Start Header-based resolving
2022-11-07 14:02:13.651 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Using provider 'secret' for authentication of client '{client}'
2022-11-07 14:02:13.651 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.651 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.651 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.652 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.652 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.652 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
Start Header-based resolving
2022-11-07 14:02:13.668 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Using provider 'secret' for authentication of client '{client}'
2022-11-07 14:02:13.669 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.669 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.669 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.669 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.670 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.670 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.670 DEBUG 4492 --- [nio-8080-exec-2] o.k.adapters.PreAuthActionsHandler       : adminRequest http://localhost:8080/api/user/admin/users?access_token={access_token}
Start Header-based resolving
2022-11-07 14:02:13.683 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Using provider 'secret' for authentication of client '{client}'
2022-11-07 14:02:13.685 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.685 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.685 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.686 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.686 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.686 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.687 DEBUG 4492 --- [nio-8080-exec-2] f.KeycloakAuthenticationProcessingFilter : Attempting Keycloak authentication
Start Header-based resolving
2022-11-07 14:02:13.703 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Using provider 'secret' for authentication of client '{client}'
2022-11-07 14:02:13.704 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.704 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.704 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.709 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.710 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.712 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.714 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.BearerTokenRequestAuthenticator    : Verifying access_token
2022-11-07 14:02:13.715 DEBUG 4492 --- [nio-8080-exec-2] o.keycloak.adapters.KeycloakDeployment   : Resolving URLs from http://localhost:8443/realms/{realm}/.well-known/openid-configuration
2022-11-07 14:02:13.731  INFO 4492 --- [nio-8080-exec-2] o.keycloak.adapters.KeycloakDeployment   : Loaded URLs from http://localhost:8443/realms/{realm}/.well-known/openid-configuration
2022-11-07 14:02:13.745 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.rotation.JWKPublicKeyLocator       : Realm public keys successfully retrieved for client {client}. New kids: [{kid}]
2022-11-07 14:02:13.747 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.BearerTokenRequestAuthenticator    : Failed to verify token
2022-11-07 14:02:13.747 DEBUG 4492 --- [nio-8080-exec-2] o.k.adapters.RequestAuthenticator        : QueryParamAuth auth FAILED
2022-11-07 14:02:13.747 DEBUG 4492 --- [nio-8080-exec-2] f.KeycloakAuthenticationProcessingFilter : Auth outcome: FAILED
2022-11-07 14:02:13.754  INFO 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : No path provided in configuration.
2022-11-07 14:02:13.755  INFO 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Querying the server for all resources associated with this application.
2022-11-07 14:02:13.803 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Initialization complete. Path configurations:
2022-11-07 14:02:13.803 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : PathConfig{name='user-resource', type='null', path='/api/user/*', scopes=[worker-scope, admin-scope, manager-scope], id='82df8be1-6890-4866-9e57-5b2c7e60b243', enforcerMode='ENFORCING'}
2022-11-07 14:02:13.804 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : PathConfig{name='Default Resource', type='urn:springboot-keycloak:resources:default', path='/*', scopes=[], id='fc175fdc-2aaf-4301-b249-a4a87f24eb52', enforcerMode='ENFORCING'}
2022-11-07 14:02:13.804 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : PathConfig{name='job-resource', type='null', path='/api/job/*', scopes=[manager-scope], id='5ed211e2-84ac-441b-b281-0d38d24baa23', enforcerMode='ENFORCING'}
2022-11-07 14:02:13.808 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Policy enforcement is enabled. Enforcing policy decisions for path [http://localhost:8080/api/user/admin/users?access_token={access_token}].
2022-11-07 14:02:13.810 DEBUG 4492 --- [nio-8080-exec-2] w.c.HttpSessionSecurityContextRepository : Did not store empty SecurityContext
2022-11-07 14:02:13.810 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Policy enforcement result for path [http://localhost:8080/api/user/admin/users?access_token={access_token}] is : DENIED
2022-11-07 14:02:13.810 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Returning authorization context with permissions:
2022-11-07 14:02:13.811 DEBUG 4492 --- [nio-8080-exec-2] w.c.HttpSessionSecurityContextRepository : Did not store empty SecurityContext
2022-11-07 14:02:13.811 DEBUG 4492 --- [nio-8080-exec-2] s.s.w.c.SecurityContextPersistenceFilter : Cleared SecurityContextHolder to complete request
2022-11-07 14:02:13.814 DEBUG 4492 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Securing GET /error?access_token={access_token}
2022-11-07 14:02:13.814 DEBUG 4492 --- [nio-8080-exec-2] s.s.w.c.SecurityContextPersistenceFilter : Set SecurityContextHolder to empty SecurityContext
Start Header-based resolving
2022-11-07 14:02:13.819 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Using provider 'secret' for authentication of client '{client}'
2022-11-07 14:02:13.820 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.820 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.820 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.821 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.822 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.822 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
Start Header-based resolving
2022-11-07 14:02:13.829 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Using provider 'secret' for authentication of client '{client}'
2022-11-07 14:02:13.830 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.830 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.830 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.831 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.831 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.831 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.831 DEBUG 4492 --- [nio-8080-exec-2] o.k.adapters.PreAuthActionsHandler       : adminRequest http://localhost:8080/error?access_token={access_token}
Start Header-based resolving
2022-11-07 14:02:13.836 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Using provider 'secret' for authentication of client '{client}'
2022-11-07 14:02:13.837 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.837 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.837 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.839 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.839 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.839 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.840 DEBUG 4492 --- [nio-8080-exec-2] f.KeycloakAuthenticationProcessingFilter : Attempting Keycloak authentication
Start Header-based resolving
2022-11-07 14:02:13.847 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Using provider 'secret' for authentication of client '{client}'
2022-11-07 14:02:13.847 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.847 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.848 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.848 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret
2022-11-07 14:02:13.848 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider jwt
2022-11-07 14:02:13.848 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.a.ClientCredentialsProviderUtils   : Loaded clientCredentialsProvider secret-jwt
2022-11-07 14:02:13.849 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.BearerTokenRequestAuthenticator    : Verifying access_token
2022-11-07 14:02:13.849 DEBUG 4492 --- [nio-8080-exec-2] o.keycloak.adapters.KeycloakDeployment   : Resolving URLs from http://localhost:8443/realms/{realm}/.well-known/openid-configuration
2022-11-07 14:02:13.859  INFO 4492 --- [nio-8080-exec-2] o.keycloak.adapters.KeycloakDeployment   : Loaded URLs from http://localhost:8443/realms/{realm}/.well-known/openid-configuration
2022-11-07 14:02:13.865 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.rotation.JWKPublicKeyLocator       : Realm public keys successfully retrieved for client {client}. New kids: [{kid}]
2022-11-07 14:02:13.865 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.BearerTokenRequestAuthenticator    : Failed to verify token
2022-11-07 14:02:13.865 DEBUG 4492 --- [nio-8080-exec-2] o.k.adapters.RequestAuthenticator        : QueryParamAuth auth FAILED
2022-11-07 14:02:13.865 DEBUG 4492 --- [nio-8080-exec-2] f.KeycloakAuthenticationProcessingFilter : Auth outcome: FAILED
2022-11-07 14:02:13.870  INFO 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : No path provided in configuration.
2022-11-07 14:02:13.870  INFO 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Querying the server for all resources associated with this application.
2022-11-07 14:02:13.914 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Initialization complete. Path configurations:
2022-11-07 14:02:13.915 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : PathConfig{name='user-resource', type='null', path='/api/user/*', scopes=[worker-scope, admin-scope, manager-scope], id='82df8be1-6890-4866-9e57-5b2c7e60b243', enforcerMode='ENFORCING'}
2022-11-07 14:02:13.915 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : PathConfig{name='Default Resource', type='urn:springboot-keycloak:resources:default', path='/*', scopes=[], id='fc175fdc-2aaf-4301-b249-a4a87f24eb52', enforcerMode='ENFORCING'}
2022-11-07 14:02:13.915 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : PathConfig{name='job-resource', type='null', path='/api/job/*', scopes=[manager-scope], id='5ed211e2-84ac-441b-b281-0d38d24baa23', enforcerMode='ENFORCING'}
2022-11-07 14:02:13.916 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Policy enforcement is enabled. Enforcing policy decisions for path [http://localhost:8080/error?access_token={access_token}].
2022-11-07 14:02:13.916 DEBUG 4492 --- [nio-8080-exec-2] w.c.HttpSessionSecurityContextRepository : Did not store empty SecurityContext
2022-11-07 14:02:13.917 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Policy enforcement result for path [http://localhost:8080/error?access_token={access_token}] is : DENIED
2022-11-07 14:02:13.917 DEBUG 4492 --- [nio-8080-exec-2] o.k.a.authorization.PolicyEnforcer       : Returning authorization context with permissions:
2022-11-07 14:02:13.917 DEBUG 4492 --- [nio-8080-exec-2] w.c.HttpSessionSecurityContextRepository : Did not store empty SecurityContext
2022-11-07 14:02:13.917 DEBUG 4492 --- [nio-8080-exec-2] s.s.w.c.SecurityContextPersistenceFilter : Cleared SecurityContextHolder to complete request

You can see the first authentication is success, then every after that returns Failed to verify token from o.k.a.BearerTokenRequestAuthenticator. But I am sure that the token was not expired by then.

How to Reproduce?

Here's my customized head-based keycloakconfigresolver

@Configuration
public class HeaderBasedConfigResolver implements KeycloakConfigResolver {

  @Override
  public KeycloakDeployment resolve(Request request) {
    System.out.println("Start Header-based resolving");
    String realm = request.getHeader("realm");
    File file = new File("realm_json/" + realm + "-keycloak.json");
    InputStream is = null;
    try {
      is = new FileInputStream(file);
    } catch (FileNotFoundException e) {
      throw new RuntimeException(e);
    }
    return KeycloakDeploymentBuilder.build(is);
  }

}

With the function to initialized the bean

@Bean
@ConditionalOnMissingBean(HeaderBasedConfigResolver.class)
public KeycloakConfigResolver keycloakConfigResolver() {
    return new HeaderBasedConfigResolver();
}

And the keycloak json I added credentials into

{
  "realm": "{realm}",
  "auth-server-url": "http://localhost:8443/",
  "ssl-required": "external",
  "resource": "{client}",
  "verify-token-audience": true,
  "credentials": {
    "secret": "{secret}"
  },
  "confidential-port": 0,
  "policy-enforcer": {}
}

A simple keycloak configuration with credentials and controller should be able to test it

@RestController
public class TestController {

    @GetMapping("test")
    public String testMultiTenancy() {
        return "Test";
    }
}

Anything else?

No response

mposolda commented 1 year ago

Thanks for the report, but unfortunately due the amount of other reported issues and other priorities, Keycloak team does not have time to properly triage this bug. So preliminary added to Backlog for now. It will be helpful if:

keycloak-github-bot[bot] commented 7 months ago

Thanks for reporting this issue. However, after review this is not considered a valid issue, or has been recently resolved.

As the issue is not valid it will be automatically closed.

mposolda commented 7 months ago

I've closed this as this issue is in fact "Out of date". Keycoak OIDC adapters are deprecated and likely will be removed and we're not going to add any further improvements to them. Please consider switch to Elytron OIDC adapter (if your application is on Wildfly application server) and open bug/rfe against it if you have further questions related to this.