Spring Security loadUserByUsername() method is not called and authentication is sucess for incorrect password

Question

I am implementing HTTP Basic auth scheme for my REST services using custom DAO UserDetailsService. However this overridden method is not getting called and authentication succeeds even if i send incorrect password to the API (through POSTMAN). Any inputs will be helpful.

My Application class

@SpringBootApplication(exclude = { SecurityAutoConfiguration.class })
@EnableNeo4jRepositories("galaxy.spring.data.neo4j.repositories")
@EnableWebSecurity
public class SampleMovieApplication extends WebSecurityConfigurerAdapter {

    public static String REALM = "REALM";
    @Autowired
    private static UserService userService;

    public static void main(String[] args) {
        ConfigurableApplicationContext configContext = 
                SpringApplication.run(SampleMovieApplication.class, args);
        configContext.getBean(RepoInit.class).fillWithTestdata();

    }
    @Override
    protected void configure(HttpSecurity httpSecurity) throws Exception {
        httpSecurity.cors().and()
                .authorizeRequests().anyRequest().fullyAuthenticated()
                .antMatchers("/galaxy/appuser/**").hasAnyRole("ADMIN","USER")
                .antMatchers("/galaxy/appadmin/**").hasRole("ADMIN")
                .and().csrf().disable()
                .httpBasic().realmName("REALM").authenticationEntryPoint(getBasicAuthEntryPoint());

    }


    @Bean
    public CustomBasicAuthenticationEntryPoint getBasicAuthEntryPoint() {
        return new CustomBasicAuthenticationEntryPoint();
    }

    @Override   
    protected void configure(AuthenticationManagerBuilder auth) throws Exception {
        System.out.println("Calling authenticator");
      auth.userDetailsService(userDetailsService()).passwordEncoder(passwordEncoder());
    }

    @Bean
    public UserDetailsService userDetailsService() {
      System.out.println(userService == null ? " userservice is null " : "userservice is not null");
      return new UserDetailsServiceImp(userService);
    };

    @Bean
    public BCryptPasswordEncoder passwordEncoder() {
      return new BCryptPasswordEncoder();
    };


}

My custom UserDetailsService class

public class UserDetailsServiceImp implements UserDetailsService {


    private UserService userService;

    public UserDetailsServiceImp(UserService userService) {
        this.userService = userService;
    }

    /*@Override
    public UserDetails loadUserByUsername(String username) throws UsernameNotFoundException {


        DomainUser user = findUserbyUername(username);

        UserBuilder builder = null;
        if (user != null) {
          builder = org.springframework.security.core.userdetails.User.withUsername(username);
          builder.password(new BCryptPasswordEncoder().encode(user.getPassword()));
          builder.roles("ROLE_" + user.getBelongsTo().get(0).getDomainUserGroup().getAuthorityname());
        } else {
          throw new UsernameNotFoundException("User not found.");
        }

        return builder.build();
    } */
    @Override
    public UserDetails loadUserByUsername(String username) throws UsernameNotFoundException {


        System.out.println("called load method");
        DomainUser user = null;
        Set<GrantedAuthority> grantedAuthorities = null;
        try
        {
            user = findUserbyUername(username);
            if(user == null)
                throw new UsernameNotFoundException("User " + username  + " not available");

            grantedAuthorities = new HashSet<>();

            grantedAuthorities.add(new SimpleGrantedAuthority("ROLE_" + 
            user.getBelongsTo().get(0).getDomainUserGroup().getAuthorityname()));

        }
        catch(Exception exp) {
            exp.printStackTrace();
        }
        System.out.println("Returning new userdetails");
        return new 
        org.springframework.security.core.userdetails.User(user.getName(), user.getPassword(), grantedAuthorities);
    }

    private DomainUser findUserbyUername(String username) {

        return userService.findByName(username);

    }
}

The SPRING SECURITY DEBUG LOG after posting a request

2020-05-03 11:06:12.884  INFO 19868 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2020-05-03 11:06:12.884  INFO 19868 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2020-05-03 11:06:12.906  INFO 19868 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 22 ms
2020-05-03 11:06:12.930 DEBUG 19868 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /galaxy/appadmin/usergroup at position 1 of 12 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
2020-05-03 11:06:12.930 DEBUG 19868 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /galaxy/appadmin/usergroup at position 2 of 12 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
2020-05-03 11:06:12.930 DEBUG 19868 --- [nio-8080-exec-1] w.c.HttpSessionSecurityContextRepository : Obtained a valid SecurityContext from SPRING_SECURITY_CONTEXT: 'org.springframework.security.core.context.SecurityContextImpl@452579c9: Authentication: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@452579c9: Principal: org.springframework.security.core.userdetails.User@586034f: Username: admin; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: ROLE_ADMIN; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@b364: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: null; Granted Authorities: ROLE_ADMIN'
2020-05-03 11:06:12.930 DEBUG 19868 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /galaxy/appadmin/usergroup at position 3 of 12 in additional filter chain; firing Filter: 'HeaderWriterFilter'
2020-05-03 11:06:12.930 DEBUG 19868 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /galaxy/appadmin/usergroup at position 4 of 12 in additional filter chain; firing Filter: 'CorsFilter'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /galaxy/appadmin/usergroup at position 5 of 12 in additional filter chain; firing Filter: 'LogoutFilter'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.web.util.matcher.OrRequestMatcher  : Trying to match using Ant [pattern='/logout', GET]
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'POST /galaxy/appadmin/usergroup' doesn't match 'GET /logout'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.web.util.matcher.OrRequestMatcher  : Trying to match using Ant [pattern='/logout', POST]
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/galaxy/appadmin/usergroup'; against '/logout'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.web.util.matcher.OrRequestMatcher  : Trying to match using Ant [pattern='/logout', PUT]
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'POST /galaxy/appadmin/usergroup' doesn't match 'PUT /logout'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.web.util.matcher.OrRequestMatcher  : Trying to match using Ant [pattern='/logout', DELETE]
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'POST /galaxy/appadmin/usergroup' doesn't match 'DELETE /logout'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.web.util.matcher.OrRequestMatcher  : No matches found
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /galaxy/appadmin/usergroup at position 6 of 12 in additional filter chain; firing Filter: 'BasicAuthenticationFilter'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.w.a.www.BasicAuthenticationFilter  : Basic Authentication Authorization header found for user 'admin'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /galaxy/appadmin/usergroup at position 7 of 12 in additional filter chain; firing Filter: 'RequestCacheAwareFilter'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.w.s.HttpSessionRequestCache        : saved request doesn't match
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /galaxy/appadmin/usergroup at position 8 of 12 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /galaxy/appadmin/usergroup at position 9 of 12 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.w.a.AnonymousAuthenticationFilter  : SecurityContextHolder not populated with anonymous token, as it already contained: 'org.springframework.security.authentication.UsernamePasswordAuthenticationToken@452579c9: Principal: org.springframework.security.core.userdetails.User@586034f: Username: admin; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: ROLE_ADMIN; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@b364: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: null; Granted Authorities: ROLE_ADMIN'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /galaxy/appadmin/usergroup at position 10 of 12 in additional filter chain; firing Filter: 'SessionManagementFilter'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /galaxy/appadmin/usergroup at position 11 of 12 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /galaxy/appadmin/usergroup at position 12 of 12 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.w.a.i.FilterSecurityInterceptor    : Secure object: FilterInvocation: URL: /galaxy/appadmin/usergroup; Attributes: [fullyAuthenticated]
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.w.a.i.FilterSecurityInterceptor    : Previously Authenticated: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@452579c9: Principal: org.springframework.security.core.userdetails.User@586034f: Username: admin; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: ROLE_ADMIN; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@b364: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: null; Granted Authorities: ROLE_ADMIN
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.access.vote.AffirmativeBased       : Voter: org.springframework.security.web.access.expression.WebExpressionVoter@6a8bc4e6, returned: 1
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.w.a.i.FilterSecurityInterceptor    : Authorization successful
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.w.a.i.FilterSecurityInterceptor    : RunAsManager did not change Authentication object
2020-05-03 11:06:12.945 DEBUG 19868 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /galaxy/appadmin/usergroup reached end of additional filter chain; proceeding with original chain
 DomainUserGroup request is testgroup3
2020-05-03 11:06:13.126 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.w.a.ExceptionTranslationFilter     : Chain processed normally
2020-05-03 11:06:13.126 DEBUG 19868 --- [nio-8080-exec-1] o.s.s.w.header.writers.HstsHeaderWriter  : Not injecting HSTS header since it did not match the requestMatcher org.springframework.security.web.header.writers.HstsHeaderWriter$SecureRequestMatcher@4aaae30c
2020-05-03 11:06:13.126 DEBUG 19868 --- [nio-8080-exec-1] s.s.w.c.SecurityContextPersistenceFilter : SecurityContextHolder now cleared, as request processing completed

Answer 1

Solved the problem. It is very funny that we have to invalidate the session in the controller (like we are logging out) and clear the secuirty context programatically. Now it is consistent and authenticates every request.

@PostMapping("/galaxy/appadmin/usergroup")
    public ResponseEntity<Object> createDomainUserGroup(@RequestBody 
            DomainUserGroup domainusergrp,HttpServletRequest request, HttpServletResponse response) {
        System.out.println(" DomainUserGroup request is "+ domainusergrp.getName());
        DomainUserGroup domainc = userGroupService.save(domainusergrp);
        URI location = ServletUriComponentsBuilder.fromCurrentRequest().path("/{id}").
                        buildAndExpand(domainc.getId()).toUri();
        SecurityContextHolder.clearContext();
        HttpSession session= request.getSession(false);
       if(session != null) {
           session.invalidate();
       }

        return ResponseEntity.created(location).build();
    }

Answer 2

Add this in SampleMovieApplication class...

@Autowired
    public void configureGlobalSecurity(AuthenticationManagerBuilder auth) throws Exception {
      auth.userDetailsService(userDetailsService()).passwordEncoder(passwordEncoder());
    }

Remove this:

@Override   
    protected void configure(AuthenticationManagerBuilder auth) throws Exception {
        System.out.println("Calling authenticator");
      auth.userDetailsService(userDetailsService()).passwordEncoder(passwordEncoder());
    }