Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Spring Boot Keycloak - authenticates three times per request

We are using Spring Boot 2.1.8 with Undertow and are using Keycloak to authenticate. Each request needs authentication but the servlet calls Keycloak for authentication three times at different points in the Servlet pipeline or filters.

I have seen this behaviour in the logs for both Basic Auth and Bearer token via Postman.

Any ideas on why this could happen?? It is hurting performance for us.

KeyCloak config

@KeycloakConfiguration
public class KeycloakSecurityConfig extends KeycloakWebSecurityConfigurerAdapter {

    private static final String READ_WRITE = "WRITE_USER";
    private static final String READ = "READ_USER";

    @Autowired
    public void configureGlobal(AuthenticationManagerBuilder auth) throws Exception {
        KeycloakAuthenticationProvider keycloakAuthenticationProvider = keycloakAuthenticationProvider();
        keycloakAuthenticationProvider.setGrantedAuthoritiesMapper(new SimpleAuthorityMapper());
        auth.authenticationProvider(keycloakAuthenticationProvider);
    }

    @Bean
    @Override
    protected SessionAuthenticationStrategy sessionAuthenticationStrategy() {
        return new RegisterSessionAuthenticationStrategy(new SessionRegistryImpl());
    }

    @Override
    protected void configure(HttpSecurity http) throws Exception {
        //super.configure(http);
        http.sessionManagement().sessionCreationPolicy(SessionCreationPolicy.STATELESS)
            .sessionAuthenticationStrategy(sessionAuthenticationStrategy())
            .and()
            .addFilterBefore(keycloakPreAuthActionsFilter(), LogoutFilter.class)
            .addFilterBefore(keycloakAuthenticationProcessingFilter(), X509AuthenticationFilter.class)
            .authorizeRequests()
            //.exceptionHandling().authenticationEntryPoint(authenticationEntryPoint())
            .antMatchers(HttpMethod.GET).hasAnyRole(READ, READ_WRITE)
            .antMatchers(HttpMethod.POST).hasRole(READ_WRITE)
            .antMatchers(HttpMethod.PATCH).hasRole(READ_WRITE)
            .antMatchers(HttpMethod.PUT).hasRole(READ_WRITE)
            .antMatchers(HttpMethod.DELETE).hasRole(READ_WRITE)
            .and().csrf().disable();
    }

    @Override
    public void configure(WebSecurity web) throws Exception {
         web.ignoring()
             .antMatchers(HttpMethod.OPTIONS)
             .antMatchers(
                     "/actuator/health", 
                     "/swagger-ui.html", 
                     "/webjars/springfox-swagger-ui/**", 
                     "/swagger-resources/**", 
                     "/v2/api-docs/**");
    }
}

Also WebConfig:

@Configuration
public class WebConfig implements WebMvcConfigurer {

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(new RequestIdInterceptor());
    }

    @Bean
    public KeycloakSpringBootConfigResolver KeycloakConfigResolver() {
        return new KeycloakSpringBootConfigResolver();
    }
}

EDIT: Here are the logs. org.keycloak:TRACE and org.springframework.security:TRACE

2019-10-21 18:29:01.648 -DEBUG 98529 --- o.k.adapters.PreAuthActionsHandler       adminRequest http://localhost:8084/service/api/111
2019-10-21 18:29:01.651 -DEBUG 98529 --- o.k.adapters.PreAuthActionsHandler       adminRequest http://localhost:8084/service/api/111
2019-10-21 18:29:01.652 -TRACE 98529 --- o.k.adapters.RequestAuthenticator        --> authenticate()
2019-10-21 18:29:01.652 -TRACE 98529 --- o.k.adapters.RequestAuthenticator        try bearer
2019-10-21 18:29:01.653 -TRACE 98529 --- o.k.adapters.RequestAuthenticator        try query paramter auth
2019-10-21 18:29:01.653 -TRACE 98529 --- o.k.adapters.RequestAuthenticator        try basic auth
2019-10-21 18:29:01.824 -DEBUG 98529 --- o.k.a.BearerTokenRequestAuthenticator    Verifying access_token
2019-10-21 18:29:01.825 -TRACE 98529 --- o.k.a.BearerTokenRequestAuthenticator      access_token: INSERT BEARER TOKEN HERE.signature
2019-10-21 18:29:01.827 -DEBUG 98529 --- o.k.a.BearerTokenRequestAuthenticator    successful authorized
2019-10-21 18:29:01.827 -DEBUG 98529 --- o.k.adapters.RequestAuthenticator        BasicAuth AUTHENTICATED
2019-10-21 18:29:01.827 -TRACE 98529 --- o.k.a.RefreshableKeycloakSecurityContext checking whether to refresh.
2019-10-21 18:29:01.827 -TRACE 98529 --- org.keycloak.adapters.AdapterUtils       useResourceRoleMappings
2019-10-21 18:29:01.827 -TRACE 98529 --- org.keycloak.adapters.AdapterUtils       Setting roles: 
2019-10-21 18:29:01.827 -TRACE 98529 --- org.keycloak.adapters.AdapterUtils          role: SCAN_USER
2019-10-21 18:29:01.827 -DEBUG 98529 --- o.k.adapters.RequestAuthenticator        User 'scantest' invoking 'http://localhost:8084/service/api/111' on client 'clientname'
2019-10-21 18:29:01.827 -DEBUG 98529 --- o.k.a.AuthenticatedActionsHandler        AuthenticatedActionsValve.invoke http://localhost:8084/service/api/111
2019-10-21 18:29:01.827 -DEBUG 98529 --- o.k.a.AuthenticatedActionsHandler        Policy enforcement is disabled.
2019-10-21 18:29:01.827 -DEBUG 98529 --- o.k.a.AuthenticatedActionsHandler        AuthenticatedActionsValve.invoke http://localhost:8084/service/api/111
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.k.a.AuthenticatedActionsHandler        Policy enforcement is disabled.
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.w.u.matcher.AntPathRequestMatcher  Request 'GET /api/111' doesn't match 'OPTIONS /**'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.w.u.matcher.AntPathRequestMatcher  Checking match of request : '/api/111'; against '/actuator/health'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.w.u.matcher.AntPathRequestMatcher  Checking match of request : '/api/111'; against '/swagger-ui.html'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.w.u.matcher.AntPathRequestMatcher  Checking match of request : '/api/111'; against '/webjars/springfox-swagger-ui/**'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.w.u.matcher.AntPathRequestMatcher  Checking match of request : '/api/111'; against '/swagger-resources/**'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.w.u.matcher.AntPathRequestMatcher  Checking match of request : '/api/111'; against '/v2/api-docs/**'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.security.web.FilterChainProxy        /api/111 at position 1 of 12 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.security.web.FilterChainProxy        /api/111 at position 2 of 12 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.security.web.FilterChainProxy        /api/111 at position 3 of 12 in additional filter chain; firing Filter: 'HeaderWriterFilter'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.security.web.FilterChainProxy        /api/111 at position 4 of 12 in additional filter chain; firing Filter: 'KeycloakPreAuthActionsFilter'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.k.adapters.PreAuthActionsHandler       adminRequest http://localhost:8084/service/api/111
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.security.web.FilterChainProxy        /api/111 at position 5 of 12 in additional filter chain; firing Filter: 'LogoutFilter'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.web.util.matcher.OrRequestMatcher  Trying to match using Ant [pattern='/logout', GET]
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.w.u.matcher.AntPathRequestMatcher  Checking match of request : '/api/111'; against '/logout'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.web.util.matcher.OrRequestMatcher  Trying to match using Ant [pattern='/logout', POST]
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.w.u.matcher.AntPathRequestMatcher  Request 'GET /api/111' doesn't match 'POST /logout'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.web.util.matcher.OrRequestMatcher  Trying to match using Ant [pattern='/logout', PUT]
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.w.u.matcher.AntPathRequestMatcher  Request 'GET /api/111' doesn't match 'PUT /logout'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.web.util.matcher.OrRequestMatcher  Trying to match using Ant [pattern='/logout', DELETE]
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.w.u.matcher.AntPathRequestMatcher  Request 'GET /api/111' doesn't match 'DELETE /logout'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.web.util.matcher.OrRequestMatcher  No matches found
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.security.web.FilterChainProxy        /api/111 at position 6 of 12 in additional filter chain; firing Filter: 'KeycloakAuthenticationProcessingFilter'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.web.util.matcher.OrRequestMatcher  Trying to match using Ant [pattern='/sso/login']
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.w.u.matcher.AntPathRequestMatcher  Checking match of request : '/api/111'; against '/sso/login'
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.web.util.matcher.OrRequestMatcher  Trying to match using RequestHeaderRequestMatcher [expectedHeaderName=Authorization, expectedHeaderValue=null]
2019-10-21 18:29:01.828 -DEBUG 98529 --- o.s.s.web.util.matcher.OrRequestMatcher  matched
2019-10-21 18:29:01.828 -DEBUG 98529 --- f.KeycloakAuthenticationProcessingFilter Request is to process authentication
2019-10-21 18:29:01.828 -DEBUG 98529 --- f.KeycloakAuthenticationProcessingFilter Attempting Keycloak authentication
2019-10-21 18:29:01.828 -TRACE 98529 --- o.k.adapters.RequestAuthenticator        --> authenticate()
2019-10-21 18:29:01.829 -TRACE 98529 --- o.k.adapters.RequestAuthenticator        try bearer
2019-10-21 18:29:01.829 -TRACE 98529 --- o.k.adapters.RequestAuthenticator        try query paramter auth
2019-10-21 18:29:01.829 -TRACE 98529 --- o.k.adapters.RequestAuthenticator        try basic auth
2019-10-21 18:29:01.970 -DEBUG 98529 --- o.k.a.BearerTokenRequestAuthenticator    Verifying access_token
2019-10-21 18:29:01.970 -TRACE 98529 --- o.k.a.BearerTokenRequestAuthenticator      access_token:  INSERT BEARER TOKEN HERE.signature
2019-10-21 18:29:01.971 -DEBUG 98529 --- o.k.a.BearerTokenRequestAuthenticator    successful authorized
2019-10-21 18:29:01.971 -DEBUG 98529 --- o.k.adapters.RequestAuthenticator        BasicAuth AUTHENTICATED
2019-10-21 18:29:01.971 -TRACE 98529 --- o.k.a.RefreshableKeycloakSecurityContext checking whether to refresh.
2019-10-21 18:29:01.971 -TRACE 98529 --- org.keycloak.adapters.AdapterUtils       useResourceRoleMappings
2019-10-21 18:29:01.971 -TRACE 98529 --- org.keycloak.adapters.AdapterUtils       Setting roles: 
2019-10-21 18:29:01.971 -TRACE 98529 --- org.keycloak.adapters.AdapterUtils          role: SCAN_USER
2019-10-21 18:29:01.971 -DEBUG 98529 --- a.s.a.SpringSecurityRequestAuthenticator Completing bearer authentication. Bearer roles: [SCAN_USER] 
2019-10-21 18:29:01.971 -DEBUG 98529 --- o.k.adapters.RequestAuthenticator        User 'scantest' invoking 'http://localhost:8084/service/api/111' on client 'clientname'
2019-10-21 18:29:01.971 -DEBUG 98529 --- f.KeycloakAuthenticationProcessingFilter Auth outcome: AUTHENTICATED
2019-10-21 18:29:01.971 -DEBUG 98529 --- o.s.s.authentication.ProviderManager     Authentication attempt using org.keycloak.adapters.springsecurity.authentication.KeycloakAuthenticationProvider
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.core.session.SessionRegistryImpl   Registering session MYs36v2qRDjsrESJs7dMO4CdBuQjrO0kDF0ZUy7L, for principal scantest
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.core.session.SessionRegistryImpl   Removing session MYs36v2qRDjsrESJs7dMO4CdBuQjrO0kDF0ZUy7L from set of registered sessions
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.core.session.SessionRegistryImpl   Removing session MYs36v2qRDjsrESJs7dMO4CdBuQjrO0kDF0ZUy7L from principal's set of registered sessions
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.core.session.SessionRegistryImpl   Removing principal scantest from registry
2019-10-21 18:29:01.972 -TRACE 98529 --- o.s.s.core.session.SessionRegistryImpl   Sessions used by 'scantest' : []
2019-10-21 18:29:01.972 -TRACE 98529 --- o.s.s.core.session.SessionRegistryImpl   Sessions used by 'scantest' : [MYs36v2qRDjsrESJs7dMO4CdBuQjrO0kDF0ZUy7L]
2019-10-21 18:29:01.972 -DEBUG 98529 --- f.KeycloakAuthenticationProcessingFilter Authentication success using bearer token/basic authentication. Updating SecurityContextHolder to contain: org.keycloak.adapters.springsecurity.token.KeycloakAuthenticationToken@2f5132da: Principal: scantest; Credentials: [PROTECTED]; Authenticated: true; Details: org.keycloak.adapters.springsecurity.account.SimpleKeycloakAccount@592730ab; Granted Authorities: ROLE_SCAN_USER
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.security.web.FilterChainProxy        /api/111 at position 7 of 12 in additional filter chain; firing Filter: 'RequestCacheAwareFilter'
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.security.web.FilterChainProxy        /api/111 at position 8 of 12 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.security.web.FilterChainProxy        /api/111 at position 9 of 12 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.w.a.AnonymousAuthenticationFilter  SecurityContextHolder not populated with anonymous token, as it already contained: 'org.keycloak.adapters.springsecurity.token.KeycloakAuthenticationToken@2f5132da: Principal: scantest; Credentials: [PROTECTED]; Authenticated: true; Details: org.keycloak.adapters.springsecurity.account.SimpleKeycloakAccount@592730ab; Granted Authorities: ROLE_SCAN_USER'
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.security.web.FilterChainProxy        /api/111 at position 10 of 12 in additional filter chain; firing Filter: 'SessionManagementFilter'
2019-10-21 18:29:01.972 -DEBUG 98529 --- s.CompositeSessionAuthenticationStrategy Delegating to org.springframework.security.web.authentication.session.RegisterSessionAuthenticationStrategy@556aed22
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.core.session.SessionRegistryImpl   Registering session MYs36v2qRDjsrESJs7dMO4CdBuQjrO0kDF0ZUy7L, for principal scantest
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.core.session.SessionRegistryImpl   Removing session MYs36v2qRDjsrESJs7dMO4CdBuQjrO0kDF0ZUy7L from set of registered sessions
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.core.session.SessionRegistryImpl   Removing session MYs36v2qRDjsrESJs7dMO4CdBuQjrO0kDF0ZUy7L from principal's set of registered sessions
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.core.session.SessionRegistryImpl   Removing principal scantest from registry
2019-10-21 18:29:01.972 -TRACE 98529 --- o.s.s.core.session.SessionRegistryImpl   Sessions used by 'scantest' : []
2019-10-21 18:29:01.972 -TRACE 98529 --- o.s.s.core.session.SessionRegistryImpl   Sessions used by 'scantest' : [MYs36v2qRDjsrESJs7dMO4CdBuQjrO0kDF0ZUy7L]
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.security.web.FilterChainProxy        /api/111 at position 11 of 12 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.security.web.FilterChainProxy        /api/111 at position 12 of 12 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.w.u.matcher.AntPathRequestMatcher  Request '/api/111' matched by universal pattern '/**'
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.w.a.i.FilterSecurityInterceptor    Secure object: FilterInvocation: URL: /api/111; Attributes: [hasAnyAuthority('ROLE_SCAN_USER','ROLE_WRITE_USER')]
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.w.a.i.FilterSecurityInterceptor    Previously Authenticated: org.keycloak.adapters.springsecurity.token.KeycloakAuthenticationToken@2f5132da: Principal: scantest; Credentials: [PROTECTED]; Authenticated: true; Details: org.keycloak.adapters.springsecurity.account.SimpleKeycloakAccount@592730ab; Granted Authorities: ROLE_SCAN_USER
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.access.vote.AffirmativeBased       Voter: org.springframework.security.web.access.expression.WebExpressionVoter@1bc888f1, returned: 1
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.w.a.i.FilterSecurityInterceptor    Authorization successful
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.s.w.a.i.FilterSecurityInterceptor    RunAsManager did not change Authentication object
2019-10-21 18:29:01.972 -DEBUG 98529 --- o.s.security.web.FilterChainProxy        /api/111 reached end of additional filter chain; proceeding with original chain
2019-10-21 18:29:01.973 -DEBUG 98529 --- o.s.s.web.util.matcher.OrRequestMatcher  Trying to match using Ant [pattern='/sso/login']
2019-10-21 18:29:01.973 -DEBUG 98529 --- o.s.s.w.u.matcher.AntPathRequestMatcher  Checking match of request : '/api/111'; against '/sso/login'
2019-10-21 18:29:01.973 -DEBUG 98529 --- o.s.s.web.util.matcher.OrRequestMatcher  Trying to match using RequestHeaderRequestMatcher [expectedHeaderName=Authorization, expectedHeaderValue=null]
2019-10-21 18:29:01.973 -DEBUG 98529 --- o.s.s.web.util.matcher.OrRequestMatcher  matched
2019-10-21 18:29:01.973 -DEBUG 98529 --- f.KeycloakAuthenticationProcessingFilter Request is to process authentication
2019-10-21 18:29:01.973 -DEBUG 98529 --- f.KeycloakAuthenticationProcessingFilter Attempting Keycloak authentication
2019-10-21 18:29:01.973 -TRACE 98529 --- o.k.adapters.RequestAuthenticator        --> authenticate()
2019-10-21 18:29:01.973 -TRACE 98529 --- o.k.adapters.RequestAuthenticator        try bearer
2019-10-21 18:29:01.973 -TRACE 98529 --- o.k.adapters.RequestAuthenticator        try query paramter auth
2019-10-21 18:29:01.973 -TRACE 98529 --- o.k.adapters.RequestAuthenticator        try basic auth
2019-10-21 18:29:02.114 -DEBUG 98529 --- o.k.a.BearerTokenRequestAuthenticator    Verifying access_token
2019-10-21 18:29:02.114 -TRACE 98529 --- o.k.a.BearerTokenRequestAuthenticator      access_token:  INSERT BEARER TOKEN HERE.signature
2019-10-21 18:29:02.116 -DEBUG 98529 --- o.k.a.BearerTokenRequestAuthenticator    successful authorized
2019-10-21 18:29:02.116 -DEBUG 98529 --- o.k.adapters.RequestAuthenticator        BasicAuth AUTHENTICATED
2019-10-21 18:29:02.116 -TRACE 98529 --- o.k.a.RefreshableKeycloakSecurityContext checking whether to refresh.
2019-10-21 18:29:02.116 -TRACE 98529 --- org.keycloak.adapters.AdapterUtils       useResourceRoleMappings
2019-10-21 18:29:02.116 -TRACE 98529 --- org.keycloak.adapters.AdapterUtils       Setting roles: 
2019-10-21 18:29:02.116 -TRACE 98529 --- org.keycloak.adapters.AdapterUtils          role: SCAN_USER
2019-10-21 18:29:02.116 -DEBUG 98529 --- a.s.a.SpringSecurityRequestAuthenticator Completing bearer authentication. Bearer roles: [SCAN_USER] 
2019-10-21 18:29:02.116 -DEBUG 98529 --- o.k.adapters.RequestAuthenticator        User 'scantest' invoking 'http://localhost:8084/service/api/111' on client 'clientname'
2019-10-21 18:29:02.116 -DEBUG 98529 --- f.KeycloakAuthenticationProcessingFilter Auth outcome: AUTHENTICATED
2019-10-21 18:29:02.116 -DEBUG 98529 --- o.s.s.authentication.ProviderManager     Authentication attempt using org.keycloak.adapters.springsecurity.authentication.KeycloakAuthenticationProvider
2019-10-21 18:29:02.117 -DEBUG 98529 --- o.s.s.core.session.SessionRegistryImpl   Registering session MYs36v2qRDjsrESJs7dMO4CdBuQjrO0kDF0ZUy7L, for principal scantest
2019-10-21 18:29:02.117 -DEBUG 98529 --- o.s.s.core.session.SessionRegistryImpl   Removing session MYs36v2qRDjsrESJs7dMO4CdBuQjrO0kDF0ZUy7L from set of registered sessions
2019-10-21 18:29:02.117 -DEBUG 98529 --- o.s.s.core.session.SessionRegistryImpl   Removing session MYs36v2qRDjsrESJs7dMO4CdBuQjrO0kDF0ZUy7L from principal's set of registered sessions
2019-10-21 18:29:02.117 -DEBUG 98529 --- o.s.s.core.session.SessionRegistryImpl   Removing principal scantest from registry
2019-10-21 18:29:02.117 -TRACE 98529 --- o.s.s.core.session.SessionRegistryImpl   Sessions used by 'scantest' : []
2019-10-21 18:29:02.117 -TRACE 98529 --- o.s.s.core.session.SessionRegistryImpl   Sessions used by 'scantest' : [MYs36v2qRDjsrESJs7dMO4CdBuQjrO0kDF0ZUy7L]
2019-10-21 18:29:02.117 -DEBUG 98529 --- f.KeycloakAuthenticationProcessingFilter Authentication success using bearer token/basic authentication. Updating SecurityContextHolder to contain: org.keycloak.adapters.springsecurity.token.KeycloakAuthenticationToken@156b8e00: Principal: scantest; Credentials: [PROTECTED]; Authenticated: true; Details: org.keycloak.adapters.springsecurity.account.SimpleKeycloakAccount@42235f32; Granted Authorities: ROLE_SCAN_USER
2019-10-21 18:29:02.117 -DEBUG 98529 --- o.k.adapters.PreAuthActionsHandler       adminRequest http://localhost:8084/service/api/111
2019-10-21 18:29:02.117 -DEBUG 98529 --- o.k.a.AuthenticatedActionsHandler        AuthenticatedActionsValve.invoke http://localhost:8084/service/api/111
2019-10-21 18:29:02.117 -DEBUG 98529 --- o.k.a.AuthenticatedActionsHandler        Policy enforcement is disabled.
like image 248
Martin Avatar asked Oct 21 '19 17:10

Martin


2 Answers

This is not an optimal solution as it doesn't address the root cause. But this fix/hack worked for us.

public class OurKeycloakAuthenticationProcessingFilter extends KeycloakAuthenticationProcessingFilter {

    public OurKeycloakAuthenticationProcessingFilter(AuthenticationManager authenticationManager) {
        super(authenticationManager);
    }

    @Override
    public Authentication attemptAuthentication(HttpServletRequest request, HttpServletResponse response)
            throws AuthenticationException, IOException, ServletException {

        LOG.info("OurKeycloakAuthenticationProcessingFilter...");
        if (SecurityContextHolder.getContext().getAuthentication() != null && SecurityContextHolder.getContext().getAuthentication().isAuthenticated()) {
            LOG.info("OurKeycloakAuthenticationProcessingFilter. We are already authenticated");
            return SecurityContextHolder.getContext().getAuthentication();
        }
        return super.attemptAuthentication(request, response);
    }

}

And then add this to the KeycloakSecurityConfig class:

    @Bean
    @Primary
    @Override
    protected KeycloakAuthenticationProcessingFilter keycloakAuthenticationProcessingFilter() throws Exception {
        KeycloakAuthenticationProcessingFilter filter = new OurKeycloakAuthenticationProcessingFilter(authenticationManagerBean());
        filter.setSessionAuthenticationStrategy(sessionAuthenticationStrategy());
        return filter;
    }
like image 137
Martin Avatar answered Sep 27 '22 21:09

Martin


I came across this while reading the documentation for Keycloak:

https://github.com/keycloak/keycloak-documentation/blob/master/securing_apps/topics/oidc/java/spring-security-adapter.adoc#avoid-double-bean-registration.

You can try following the recommendation from the documentation and see if that helps your issue.

Spring Boot attempts to eagerly register filter beans with the web application context. Therefore, when running the Keycloak Spring Security adapter in a Spring Boot environment, it may be necessary to add FilterRegistrationBeans to your security configuration to prevent the Keycloak filters from being registered twice.

Spring Boot 2.1 also disables spring.main.allow-bean-definition-overriding by default. This can mean that an BeanDefinitionOverrideException will be encountered if a Configuration class extending KeycloakWebSecurityConfigurerAdapter registers a bean that is already detected by a @ComponentScan. This can be avoided by overriding the registration to use the Boot-specific @ConditionalOnMissingBean annotation, as with HttpSessionManager below.

@Configuration
@EnableWebSecurity
public class SecurityConfig extends KeycloakWebSecurityConfigurerAdapter
{
    ...

    @Bean
    public FilterRegistrationBean keycloakAuthenticationProcessingFilterRegistrationBean(
            KeycloakAuthenticationProcessingFilter filter) {
        FilterRegistrationBean registrationBean = new FilterRegistrationBean(filter);
        registrationBean.setEnabled(false);
        return registrationBean;
    }

    @Bean
    public FilterRegistrationBean keycloakPreAuthActionsFilterRegistrationBean(
            KeycloakPreAuthActionsFilter filter) {
        FilterRegistrationBean registrationBean = new FilterRegistrationBean(filter);
        registrationBean.setEnabled(false);
        return registrationBean;
    }

    @Bean
    public FilterRegistrationBean keycloakAuthenticatedActionsFilterBean(
            KeycloakAuthenticatedActionsFilter filter) {
        FilterRegistrationBean registrationBean = new FilterRegistrationBean(filter);
        registrationBean.setEnabled(false);
        return registrationBean;
    }

    @Bean
    public FilterRegistrationBean keycloakSecurityContextRequestFilterBean(
        KeycloakSecurityContextRequestFilter filter) {
        FilterRegistrationBean registrationBean = new FilterRegistrationBean(filter);
        registrationBean.setEnabled(false);
        return registrationBean;
    }

    @Bean
    @Override
    @ConditionalOnMissingBean(HttpSessionManager.class)
    protected HttpSessionManager httpSessionManager() {
        return new HttpSessionManager();
    }
    ...
}
like image 31
rlowe8123 Avatar answered Sep 27 '22 23:09

rlowe8123