Notice

I wrote this article and was originally published on Qiita on 9 September 2019.

Setup to show debug message

Name: Debugging Spring Security web application
Rating: 1.2 (4358 reviews)
Author: saladlam

I will show it by using my example application.

First on class "info.saladlam.example.spring.noticeboard.config.WebSecurityConfig", pass parameter into annotation @EnableWebSecurity as below

@EnableWebSecurity(debug = true)

Then on file "src/main/resources/application.properties", add following line

logging.level.org.springframework.security=debug

On browser open link "http://localhost:8080/", if you see log message likes below, setup is success.

2019-09-09 09:59:27.983  INFO 8052 --- [nio-8080-exec-4] Spring Security Debugger                 : 

************************************************************

Request received for GET '/':

org.apache.catalina.connector.RequestFacade@21984639

servletPath:/
pathInfo:null
headers: 
host: localhost:8080
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:69.0) Gecko/20100101 Firefox/69.0
accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
accept-language: zh-TW,zh;q=0.8,en-US;q=0.5,en;q=0.3
accept-encoding: gzip, deflate
referer: http://localhost:8080/manage
connection: keep-alive
cookie: JSESSIONID=5B745B47B9D5975FCA05D8755BB2D1D6
upgrade-insecure-requests: 1
cache-control: max-age=0


Security filter chain: [
  WebAsyncManagerIntegrationFilter
  SecurityContextPersistenceFilter
  HeaderWriterFilter
  CsrfFilter
  LogoutFilter
  UsernamePasswordAuthenticationFilter
  RequestCacheAwareFilter
  SecurityContextHolderAwareRequestFilter
  AnonymousAuthenticationFilter
  SessionManagementFilter
  ExceptionTranslationFilter
  FilterSecurityInterceptor
]


************************************************************


2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 1 of 12 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 2 of 12 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] w.c.HttpSessionSecurityContextRepository : No HttpSession currently exists
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] w.c.HttpSessionSecurityContextRepository : No SecurityContext was available from the HttpSession: null. A new one will be created.
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 3 of 12 in additional filter chain; firing Filter: 'HeaderWriterFilter'
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 4 of 12 in additional filter chain; firing Filter: 'CsrfFilter'
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 5 of 12 in additional filter chain; firing Filter: 'LogoutFilter'
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'GET /' doesn't match 'POST /logout'
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 6 of 12 in additional filter chain; firing Filter: 'UsernamePasswordAuthenticationFilter'
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'GET /' doesn't match 'POST /loginHandler'
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 7 of 12 in additional filter chain; firing Filter: 'RequestCacheAwareFilter'
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.s.HttpSessionRequestCache        : saved request doesn't match
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 8 of 12 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 9 of 12 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.a.AnonymousAuthenticationFilter  : Populated SecurityContextHolder with anonymous token: 'org.springframework.security.authentication.AnonymousAuthenticationToken@a0d1f6b9: Principal: anonymousUser; 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_ANONYMOUS'
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 10 of 12 in additional filter chain; firing Filter: 'SessionManagementFilter'
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.session.SessionManagementFilter  : Requested session ID 5B745B47B9D5975FCA05D8755BB2D1D6 is invalid.
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 11 of 12 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 12 of 12 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/'; against '/manage/*/approve'
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/'; against '/manage/**'
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.a.i.FilterSecurityInterceptor    : Public object - authentication not attempted
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / reached end of additional filter chain; proceeding with original chain
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : GET "/", parameters={}
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public java.lang.String info.saladlam.example.spring.noticeboard.controller.PublicController.index(org.springframework.ui.Model)
2019-09-09 09:59:27.986 DEBUG 8052 --- [nio-8080-exec-4] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL query
2019-09-09 09:59:27.986 DEBUG 8052 --- [nio-8080-exec-4] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL statement [SELECT * FROM message WHERE approved_by IS NOT NULL AND publish_date <= ? AND (remove_date IS NULL OR remove_date > ?) ORDER BY publish_date DESC]
2019-09-09 09:59:27.987 DEBUG 8052 --- [nio-8080-exec-4] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'ID' to property 'id' of type 'java.lang.Long'
2019-09-09 09:59:27.988 DEBUG 8052 --- [nio-8080-exec-4] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'PUBLISH_DATE' to property 'publishDate' of type 'java.time.LocalDateTime'
2019-09-09 09:59:27.988 DEBUG 8052 --- [nio-8080-exec-4] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'REMOVE_DATE' to property 'removeDate' of type 'java.time.LocalDateTime'
2019-09-09 09:59:27.988 DEBUG 8052 --- [nio-8080-exec-4] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'OWNER' to property 'owner' of type 'java.lang.String'
2019-09-09 09:59:27.988 DEBUG 8052 --- [nio-8080-exec-4] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'DESCRIPTION' to property 'description' of type 'java.lang.String'
2019-09-09 09:59:27.989 DEBUG 8052 --- [nio-8080-exec-4] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'APPROVED_BY' to property 'approvedBy' of type 'java.lang.String'
2019-09-09 09:59:27.989 DEBUG 8052 --- [nio-8080-exec-4] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'APPROVED_DATE' to property 'approvedDate' of type 'java.time.LocalDateTime'
2019-09-09 09:59:27.994 DEBUG 8052 --- [nio-8080-exec-4] o.s.w.s.v.ContentNegotiatingViewResolver : Selected 'text/html' given [text/html, application/xhtml+xml, application/xml;q=0.9, */*;q=0.8]
2019-09-09 09:59:28.003 DEBUG 8052 --- [nio-8080-exec-4] 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@2f3aea8b
2019-09-09 09:59:28.004 DEBUG 8052 --- [nio-8080-exec-4] w.c.HttpSessionSecurityContextRepository : SecurityContext is empty or contents are anonymous - context will not be stored in HttpSession.
2019-09-09 09:59:28.004 DEBUG 8052 --- [nio-8080-exec-4] o.s.web.servlet.DispatcherServlet        : Completed 200 OK
2019-09-09 09:59:28.004 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.a.ExceptionTranslationFilter     : Chain processed normally
2019-09-09 09:59:28.004 DEBUG 8052 --- [nio-8080-exec-4] s.s.w.c.SecurityContextPersistenceFilter : SecurityContextHolder now cleared, as request processing completed

Meaning of log message

Header information received with request

Request received for GET '/':

org.apache.catalina.connector.RequestFacade@21984639

servletPath:/
pathInfo:null
headers: 
host: localhost:8080
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:69.0) Gecko/20100101 Firefox/69.0
accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
accept-language: zh-TW,zh;q=0.8,en-US;q=0.5,en;q=0.3
accept-encoding: gzip, deflate
referer: http://localhost:8080/manage
connection: keep-alive
cookie: JSESSIONID=5B745B47B9D5975FCA05D8755BB2D1D6
upgrade-insecure-requests: 1
cache-control: max-age=0

What filter is included in security filter chain

Security filter chain: [
  WebAsyncManagerIntegrationFilter
  SecurityContextPersistenceFilter
  HeaderWriterFilter
  CsrfFilter
  LogoutFilter
  UsernamePasswordAuthenticationFilter
  RequestCacheAwareFilter
  SecurityContextHolderAwareRequestFilter
  AnonymousAuthenticationFilter
  SessionManagementFilter
  ExceptionTranslationFilter
  FilterSecurityInterceptor
]

What is done on each filter

2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 1 of 12 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 2 of 12 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] w.c.HttpSessionSecurityContextRepository : No HttpSession currently exists
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] w.c.HttpSessionSecurityContextRepository : No SecurityContext was available from the HttpSession: null. A new one will be created.
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 3 of 12 in additional filter chain; firing Filter: 'HeaderWriterFilter'
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 4 of 12 in additional filter chain; firing Filter: 'CsrfFilter'
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 5 of 12 in additional filter chain; firing Filter: 'LogoutFilter'
2019-09-09 09:59:27.983 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'GET /' doesn't match 'POST /logout'
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 6 of 12 in additional filter chain; firing Filter: 'UsernamePasswordAuthenticationFilter'
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'GET /' doesn't match 'POST /loginHandler'
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 7 of 12 in additional filter chain; firing Filter: 'RequestCacheAwareFilter'
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.s.HttpSessionRequestCache        : saved request doesn't match
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 8 of 12 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 9 of 12 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
2019-09-09 09:59:27.984 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.a.AnonymousAuthenticationFilter  : Populated SecurityContextHolder with anonymous token: 'org.springframework.security.authentication.AnonymousAuthenticationToken@a0d1f6b9: Principal: anonymousUser; 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_ANONYMOUS'
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 10 of 12 in additional filter chain; firing Filter: 'SessionManagementFilter'
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.session.SessionManagementFilter  : Requested session ID 5B745B47B9D5975FCA05D8755BB2D1D6 is invalid.
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 11 of 12 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / at position 12 of 12 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/'; against '/manage/*/approve'
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/'; against '/manage/**'
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.s.w.a.i.FilterSecurityInterceptor    : Public object - authentication not attempted
2019-09-09 09:59:27.985 DEBUG 8052 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : / reached end of additional filter chain; proceeding with original chain

Access protected resource without login

User can enter link "http://localhost:8080/manage" if following condition fulfilled.

User is logged in, otherwise redirect to "http://localhost:8080/login"
User has "USER" authority

Below is log message.

2019-09-09 10:23:23.418  INFO 8052 --- [nio-8080-exec-5] Spring Security Debugger                 : 

************************************************************

Request received for GET '/manage':

org.apache.catalina.connector.RequestFacade@21984639

servletPath:/manage
pathInfo:null
headers: 
host: localhost:8080
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:69.0) Gecko/20100101 Firefox/69.0
accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
accept-language: zh-TW,zh;q=0.8,en-US;q=0.5,en;q=0.3
accept-encoding: gzip, deflate
connection: keep-alive
cookie: JSESSIONID=5B745B47B9D5975FCA05D8755BB2D1D6
upgrade-insecure-requests: 1


Security filter chain: [
  WebAsyncManagerIntegrationFilter
  SecurityContextPersistenceFilter
  HeaderWriterFilter
  CsrfFilter
  LogoutFilter
  UsernamePasswordAuthenticationFilter
  RequestCacheAwareFilter
  SecurityContextHolderAwareRequestFilter
  AnonymousAuthenticationFilter
  SessionManagementFilter
  ExceptionTranslationFilter
  FilterSecurityInterceptor
]


************************************************************


2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy        : /manage at position 1 of 12 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy        : /manage at position 2 of 12 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] w.c.HttpSessionSecurityContextRepository : No HttpSession currently exists
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] w.c.HttpSessionSecurityContextRepository : No SecurityContext was available from the HttpSession: null. A new one will be created.
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy        : /manage at position 3 of 12 in additional filter chain; firing Filter: 'HeaderWriterFilter'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy        : /manage at position 4 of 12 in additional filter chain; firing Filter: 'CsrfFilter'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy        : /manage at position 5 of 12 in additional filter chain; firing Filter: 'LogoutFilter'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'GET /manage' doesn't match 'POST /logout'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy        : /manage at position 6 of 12 in additional filter chain; firing Filter: 'UsernamePasswordAuthenticationFilter'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'GET /manage' doesn't match 'POST /loginHandler'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy        : /manage at position 7 of 12 in additional filter chain; firing Filter: 'RequestCacheAwareFilter'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.s.HttpSessionRequestCache        : saved request doesn't match
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy        : /manage at position 8 of 12 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy        : /manage at position 9 of 12 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.a.AnonymousAuthenticationFilter  : Populated SecurityContextHolder with anonymous token: 'org.springframework.security.authentication.AnonymousAuthenticationToken@a0d1f6b9: Principal: anonymousUser; 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_ANONYMOUS'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy        : /manage at position 10 of 12 in additional filter chain; firing Filter: 'SessionManagementFilter'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.session.SessionManagementFilter  : Requested session ID 5B745B47B9D5975FCA05D8755BB2D1D6 is invalid.
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy        : /manage at position 11 of 12 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy        : /manage at position 12 of 12 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/manage'; against '/manage/*/approve'
2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/manage'; against '/manage/**'
2019-09-09 10:23:23.429 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.a.i.FilterSecurityInterceptor    : Secure object: FilterInvocation: URL: /manage; Attributes: [hasAuthority('USER')]
2019-09-09 10:23:23.429 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.a.i.FilterSecurityInterceptor    : Previously Authenticated: org.springframework.security.authentication.AnonymousAuthenticationToken@a0d1f6b9: Principal: anonymousUser; 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_ANONYMOUS
2019-09-09 10:23:23.429 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.access.vote.AffirmativeBased       : Voter: org.springframework.security.web.access.expression.WebExpressionVoter@20931c33, returned: -1
2019-09-09 10:23:23.429 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.a.ExceptionTranslationFilter     : Access is denied (user is anonymous); redirecting to authentication entry point

org.springframework.security.access.AccessDeniedException: Access is denied
    at org.springframework.security.access.vote.AffirmativeBased.decide(AffirmativeBased.java:84) ~[spring-security-core-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.access.intercept.AbstractSecurityInterceptor.beforeInvocation(AbstractSecurityInterceptor.java:233) ~[spring-security-core-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:124) ~[spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:91) ~[spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:119) ~[spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:137) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:170) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:116) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.csrf.CsrfFilter.doFilterInternal(CsrfFilter.java:100) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118) [spring-web-5.1.9.RELEASE.jar:5.1.9.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:74) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118) [spring-web-5.1.9.RELEASE.jar:5.1.9.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:56) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118) [spring-web-5.1.9.RELEASE.jar:5.1.9.RELEASE]
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:215) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:178) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.debug.DebugFilter.invokeWithWrappedRequest(DebugFilter.java:90) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.security.web.debug.DebugFilter.doFilter(DebugFilter.java:77) [spring-security-web-5.1.6.RELEASE.jar:5.1.6.RELEASE]
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:357) [spring-web-5.1.9.RELEASE.jar:5.1.9.RELEASE]
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:270) [spring-web-5.1.9.RELEASE.jar:5.1.9.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) [spring-web-5.1.9.RELEASE.jar:5.1.9.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118) [spring-web-5.1.9.RELEASE.jar:5.1.9.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:92) [spring-web-5.1.9.RELEASE.jar:5.1.9.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118) [spring-web-5.1.9.RELEASE.jar:5.1.9.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93) [spring-web-5.1.9.RELEASE.jar:5.1.9.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118) [spring-web-5.1.9.RELEASE.jar:5.1.9.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200) [spring-web-5.1.9.RELEASE.jar:5.1.9.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118) [spring-web-5.1.9.RELEASE.jar:5.1.9.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:490) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:853) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1587) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_222]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_222]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-9.0.22.jar:9.0.22]
    at java.lang.Thread.run(Thread.java:748) [na:1.8.0_222]

2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.util.matcher.AndRequestMatcher   : Trying to match using Ant [pattern='/**', GET]
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request '/manage' matched by universal pattern '/**'
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.util.matcher.AndRequestMatcher   : Trying to match using NegatedRequestMatcher [requestMatcher=Ant [pattern='/**/favicon.*']]
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/manage'; against '/**/favicon.*'
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.matcher.NegatedRequestMatcher  : matches = true
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.util.matcher.AndRequestMatcher   : Trying to match using NegatedRequestMatcher [requestMatcher=MediaTypeRequestMatcher [contentNegotiationStrategy=org.springframework.web.accept.ContentNegotiationManager@48bae240, matchingMediaTypes=[application/json], useEquals=false, ignoredMediaTypes=[*/*]]]
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.m.MediaTypeRequestMatcher      : httpRequestMediaTypes=[text/html, application/xhtml+xml, application/xml;q=0.9, */*;q=0.8]
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.m.MediaTypeRequestMatcher      : Processing text/html
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.m.MediaTypeRequestMatcher      : application/json .isCompatibleWith text/html = false
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.m.MediaTypeRequestMatcher      : Processing application/xhtml+xml
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.m.MediaTypeRequestMatcher      : application/json .isCompatibleWith application/xhtml+xml = false
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.m.MediaTypeRequestMatcher      : Processing application/xml;q=0.9
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.m.MediaTypeRequestMatcher      : application/json .isCompatibleWith application/xml;q=0.9 = false
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.m.MediaTypeRequestMatcher      : Processing */*;q=0.8
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.m.MediaTypeRequestMatcher      : Ignoring
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.m.MediaTypeRequestMatcher      : Did not match any media types
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.matcher.NegatedRequestMatcher  : matches = true
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.util.matcher.AndRequestMatcher   : Trying to match using NegatedRequestMatcher [requestMatcher=RequestHeaderRequestMatcher [expectedHeaderName=X-Requested-With, expectedHeaderValue=XMLHttpRequest]]
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.matcher.NegatedRequestMatcher  : matches = true
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.util.matcher.AndRequestMatcher   : All requestMatchers returned true
2019-09-09 10:23:23.440  INFO 8052 --- [nio-8080-exec-5] Spring Security Debugger                 : 

************************************************************

New HTTP session created: 600351D5D67C5EC315DCB96ED3AD3A79

Call stack: 

    at org.springframework.security.web.debug.Logger.info(Logger.java:44)
    at org.springframework.security.web.debug.DebugRequestWrapper.getSession(DebugFilter.java:166)
    at javax.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:250)
    at javax.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:250)
    at javax.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:250)
    at javax.servlet.http.HttpServletRequestWrapper.getSession(HttpServletRequestWrapper.java:250)
    at org.springframework.security.web.savedrequest.HttpSessionRequestCache.saveRequest(HttpSessionRequestCache.java:60)
    at org.springframework.security.web.access.ExceptionTranslationFilter.sendStartAuthentication(ExceptionTranslationFilter.java:211)
    at org.springframework.security.web.access.ExceptionTranslationFilter.handleSpringSecurityException(ExceptionTranslationFilter.java:185)
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:141)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:137)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:170)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:116)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.csrf.CsrfFilter.doFilterInternal(CsrfFilter.java:100)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:74)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:56)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:215)
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:178)
    at org.springframework.security.web.debug.DebugFilter.invokeWithWrappedRequest(DebugFilter.java:90)
    at org.springframework.security.web.debug.DebugFilter.doFilter(DebugFilter.java:77)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:357)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:270)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:92)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:490)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408)
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:853)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1587)
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)


************************************************************


2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.s.HttpSessionRequestCache        : DefaultSavedRequest added to Session: DefaultSavedRequest[http://localhost:8080/manage]
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.a.ExceptionTranslationFilter     : Calling Authentication entry point.
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.web.DefaultRedirectStrategy        : Redirecting to 'http://localhost:8080/login'
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] 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@2f3aea8b
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] w.c.HttpSessionSecurityContextRepository : SecurityContext is empty or contents are anonymous - context will not be stored in HttpSession.
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] s.s.w.c.SecurityContextPersistenceFilter : SecurityContextHolder now cleared, as request processing completed

From following log, I knew access control is correctly setup.

2019-09-09 10:23:23.418 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/manage'; against '/manage/**'
2019-09-09 10:23:23.429 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.a.i.FilterSecurityInterceptor    : Secure object: FilterInvocation: URL: /manage; Attributes: [hasAuthority('USER')]

Not login user is treated as anonymous user, and has no right to enter this link.

2019-09-09 10:23:23.429 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.a.i.FilterSecurityInterceptor    : Previously Authenticated: org.springframework.security.authentication.AnonymousAuthenticationToken@a0d1f6b9: Principal: anonymousUser; 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_ANONYMOUS
2019-09-09 10:23:23.429 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.access.vote.AffirmativeBased       : Voter: org.springframework.security.web.access.expression.WebExpressionVoter@20931c33, returned: -1
2019-09-09 10:23:23.429 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.a.ExceptionTranslationFilter     : Access is denied (user is anonymous); redirecting to authentication entry point

Save last visiting link into session and redirect to login page.

2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.s.HttpSessionRequestCache        : DefaultSavedRequest added to Session: DefaultSavedRequest[http://localhost:8080/manage]
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.w.a.ExceptionTranslationFilter     : Calling Authentication entry point.
2019-09-09 10:23:23.440 DEBUG 8052 --- [nio-8080-exec-5] o.s.s.web.DefaultRedirectStrategy        : Redirecting to 'http://localhost:8080/login'

Performing authentication

After entering username and password, authentication is processed by "http://localhost:8080/loginHandler".

Below is log message.

2019-09-09 10:49:50.803  INFO 8052 --- [io-8080-exec-10] Spring Security Debugger                 : 

************************************************************

Request received for POST '/loginHandler':

org.apache.catalina.connector.RequestFacade@21984639

servletPath:/loginHandler
pathInfo:null
headers: 
host: localhost:8080
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:69.0) Gecko/20100101 Firefox/69.0
accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
accept-language: zh-TW,zh;q=0.8,en-US;q=0.5,en;q=0.3
accept-encoding: gzip, deflate
content-type: application/x-www-form-urlencoded
content-length: 72
connection: keep-alive
referer: http://localhost:8080/login
cookie: JSESSIONID=600351D5D67C5EC315DCB96ED3AD3A79
upgrade-insecure-requests: 1


Security filter chain: [
  WebAsyncManagerIntegrationFilter
  SecurityContextPersistenceFilter
  HeaderWriterFilter
  CsrfFilter
  LogoutFilter
  UsernamePasswordAuthenticationFilter
  RequestCacheAwareFilter
  SecurityContextHolderAwareRequestFilter
  AnonymousAuthenticationFilter
  SessionManagementFilter
  ExceptionTranslationFilter
  FilterSecurityInterceptor
]


************************************************************


2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.security.web.FilterChainProxy        : /loginHandler at position 1 of 12 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.security.web.FilterChainProxy        : /loginHandler at position 2 of 12 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] w.c.HttpSessionSecurityContextRepository : HttpSession returned null object for SPRING_SECURITY_CONTEXT
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] w.c.HttpSessionSecurityContextRepository : No SecurityContext was available from the HttpSession: org.apache.catalina.session.StandardSessionFacade@c3207bc. A new one will be created.
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.security.web.FilterChainProxy        : /loginHandler at position 3 of 12 in additional filter chain; firing Filter: 'HeaderWriterFilter'
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.security.web.FilterChainProxy        : /loginHandler at position 4 of 12 in additional filter chain; firing Filter: 'CsrfFilter'
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.security.web.FilterChainProxy        : /loginHandler at position 5 of 12 in additional filter chain; firing Filter: 'LogoutFilter'
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/loginHandler'; against '/logout'
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.security.web.FilterChainProxy        : /loginHandler at position 6 of 12 in additional filter chain; firing Filter: 'UsernamePasswordAuthenticationFilter'
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/loginHandler'; against '/loginHandler'
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] w.a.UsernamePasswordAuthenticationFilter : Request is to process authentication
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.s.authentication.ProviderManager     : Authentication attempt using org.springframework.security.authentication.dao.DaoAuthenticationProvider
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL query
2019-09-09 10:49:50.806 DEBUG 8052 --- [io-8080-exec-10] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL statement [select username,password,enabled from users where username = ?]
2019-09-09 10:49:50.807 DEBUG 8052 --- [io-8080-exec-10] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL query
2019-09-09 10:49:50.807 DEBUG 8052 --- [io-8080-exec-10] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL statement [select username,authority from authorities where username = ?]
2019-09-09 10:49:50.902 DEBUG 8052 --- [io-8080-exec-10] s.CompositeSessionAuthenticationStrategy : Delegating to org.springframework.security.web.authentication.session.ChangeSessionIdAuthenticationStrategy@3b6c60ce
2019-09-09 10:49:50.902 DEBUG 8052 --- [io-8080-exec-10] s.CompositeSessionAuthenticationStrategy : Delegating to org.springframework.security.web.csrf.CsrfAuthenticationStrategy@7401adfd
2019-09-09 10:49:50.902 DEBUG 8052 --- [io-8080-exec-10] w.a.UsernamePasswordAuthenticationFilter : Authentication success. Updating SecurityContextHolder to contain: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@681dd55: Principal: org.springframework.security.core.userdetails.User@6a68dc6: Username: user1; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: USER; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffff4c9c: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: 600351D5D67C5EC315DCB96ED3AD3A79; Granted Authorities: USER
2019-09-09 10:49:50.902 DEBUG 8052 --- [io-8080-exec-10] RequestAwareAuthenticationSuccessHandler : Redirecting to DefaultSavedRequest Url: http://localhost:8080/manage
2019-09-09 10:49:50.902 DEBUG 8052 --- [io-8080-exec-10] o.s.s.web.DefaultRedirectStrategy        : Redirecting to 'http://localhost:8080/manage'
2019-09-09 10:49:50.902 DEBUG 8052 --- [io-8080-exec-10] 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@2f3aea8b
2019-09-09 10:49:50.902 DEBUG 8052 --- [io-8080-exec-10] w.c.HttpSessionSecurityContextRepository : SecurityContext 'org.springframework.security.core.context.SecurityContextImpl@681dd55: Authentication: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@681dd55: Principal: org.springframework.security.core.userdetails.User@6a68dc6: Username: user1; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: USER; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffff4c9c: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: 600351D5D67C5EC315DCB96ED3AD3A79; Granted Authorities: USER' stored to HttpSession: 'org.apache.catalina.session.StandardSessionFacade@c3207bc
2019-09-09 10:49:50.902 DEBUG 8052 --- [io-8080-exec-10] s.s.w.c.SecurityContextPersistenceFilter : SecurityContextHolder now cleared, as request processing completed

Authentication is handle by UsernamePasswordAuthenticationFilter. User information is query from database and know that "user1" with "USER" authority is login.

2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.security.web.FilterChainProxy        : /loginHandler at position 5 of 12 in additional filter chain; firing Filter: 'LogoutFilter'
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/loginHandler'; against '/logout'
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.security.web.FilterChainProxy        : /loginHandler at position 6 of 12 in additional filter chain; firing Filter: 'UsernamePasswordAuthenticationFilter'
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/loginHandler'; against '/loginHandler'
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] w.a.UsernamePasswordAuthenticationFilter : Request is to process authentication
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.s.authentication.ProviderManager     : Authentication attempt using org.springframework.security.authentication.dao.DaoAuthenticationProvider
2019-09-09 10:49:50.803 DEBUG 8052 --- [io-8080-exec-10] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL query
2019-09-09 10:49:50.806 DEBUG 8052 --- [io-8080-exec-10] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL statement [select username,password,enabled from users where username = ?]
2019-09-09 10:49:50.807 DEBUG 8052 --- [io-8080-exec-10] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL query
2019-09-09 10:49:50.807 DEBUG 8052 --- [io-8080-exec-10] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL statement [select username,authority from authorities where username = ?]
2019-09-09 10:49:50.902 DEBUG 8052 --- [io-8080-exec-10] s.CompositeSessionAuthenticationStrategy : Delegating to org.springframework.security.web.authentication.session.ChangeSessionIdAuthenticationStrategy@3b6c60ce
2019-09-09 10:49:50.902 DEBUG 8052 --- [io-8080-exec-10] s.CompositeSessionAuthenticationStrategy : Delegating to org.springframework.security.web.csrf.CsrfAuthenticationStrategy@7401adfd
2019-09-09 10:49:50.902 DEBUG 8052 --- [io-8080-exec-10] w.a.UsernamePasswordAuthenticationFilter : Authentication success. Updating SecurityContextHolder to contain: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@681dd55: Principal: org.springframework.security.core.userdetails.User@6a68dc6: Username: user1; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: USER; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffff4c9c: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: 600351D5D67C5EC315DCB96ED3AD3A79; Granted Authorities: USER

Redirect to previosly access link.

2019-09-09 10:49:50.902 DEBUG 8052 --- [io-8080-exec-10] RequestAwareAuthenticationSuccessHandler : Redirecting to DefaultSavedRequest Url: http://localhost:8080/manage
2019-09-09 10:49:50.902 DEBUG 8052 --- [io-8080-exec-10] o.s.s.web.DefaultRedirectStrategy        : Redirecting to 'http://localhost:8080/manage'

Access protected resource after login

User "user1" accesses link "http://localhost:8080/manage". Below is log message.

2019-09-09 10:49:50.902  INFO 8052 --- [nio-8080-exec-1] Spring Security Debugger                 : 

************************************************************

Request received for GET '/manage':

org.apache.catalina.connector.RequestFacade@21984639

servletPath:/manage
pathInfo:null
headers: 
host: localhost:8080
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:69.0) Gecko/20100101 Firefox/69.0
accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
accept-language: zh-TW,zh;q=0.8,en-US;q=0.5,en;q=0.3
accept-encoding: gzip, deflate
referer: http://localhost:8080/login
connection: keep-alive
cookie: JSESSIONID=3F88F4330263D74BA5E6182E4DE35D8B
upgrade-insecure-requests: 1


Security filter chain: [
  WebAsyncManagerIntegrationFilter
  SecurityContextPersistenceFilter
  HeaderWriterFilter
  CsrfFilter
  LogoutFilter
  UsernamePasswordAuthenticationFilter
  RequestCacheAwareFilter
  SecurityContextHolderAwareRequestFilter
  AnonymousAuthenticationFilter
  SessionManagementFilter
  ExceptionTranslationFilter
  FilterSecurityInterceptor
]


************************************************************


2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /manage at position 1 of 12 in additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /manage at position 2 of 12 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] w.c.HttpSessionSecurityContextRepository : Obtained a valid SecurityContext from SPRING_SECURITY_CONTEXT: 'org.springframework.security.core.context.SecurityContextImpl@681dd55: Authentication: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@681dd55: Principal: org.springframework.security.core.userdetails.User@6a68dc6: Username: user1; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: USER; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffff4c9c: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: 600351D5D67C5EC315DCB96ED3AD3A79; Granted Authorities: USER'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /manage at position 3 of 12 in additional filter chain; firing Filter: 'HeaderWriterFilter'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /manage at position 4 of 12 in additional filter chain; firing Filter: 'CsrfFilter'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /manage at position 5 of 12 in additional filter chain; firing Filter: 'LogoutFilter'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'GET /manage' doesn't match 'POST /logout'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /manage at position 6 of 12 in additional filter chain; firing Filter: 'UsernamePasswordAuthenticationFilter'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.u.matcher.AntPathRequestMatcher  : Request 'GET /manage' doesn't match 'POST /loginHandler'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /manage at position 7 of 12 in additional filter chain; firing Filter: 'RequestCacheAwareFilter'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.s.DefaultSavedRequest            : pathInfo: both null (property equals)
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.s.DefaultSavedRequest            : queryString: both null (property equals)
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.s.DefaultSavedRequest            : requestURI: arg1=/manage; arg2=/manage (property equals)
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.s.DefaultSavedRequest            : serverPort: arg1=8080; arg2=8080 (property equals)
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.s.DefaultSavedRequest            : requestURL: arg1=http://localhost:8080/manage; arg2=http://localhost:8080/manage (property equals)
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.s.DefaultSavedRequest            : scheme: arg1=http; arg2=http (property equals)
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.s.DefaultSavedRequest            : serverName: arg1=localhost; arg2=localhost (property equals)
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.s.DefaultSavedRequest            : contextPath: arg1=; arg2= (property equals)
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.s.DefaultSavedRequest            : servletPath: arg1=/manage; arg2=/manage (property equals)
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.s.HttpSessionRequestCache        : Removing DefaultSavedRequest from session if present
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /manage at position 8 of 12 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /manage at position 9 of 12 in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
2019-09-09 10:49:50.902 DEBUG 8052 --- [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@681dd55: Principal: org.springframework.security.core.userdetails.User@6a68dc6: Username: user1; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: USER; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffff4c9c: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: 600351D5D67C5EC315DCB96ED3AD3A79; Granted Authorities: USER'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /manage at position 10 of 12 in additional filter chain; firing Filter: 'SessionManagementFilter'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /manage at position 11 of 12 in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /manage at position 12 of 12 in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
2019-09-09 10:49:50.902 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/manage'; against '/manage/*/approve'
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.u.matcher.AntPathRequestMatcher  : Checking match of request : '/manage'; against '/manage/**'
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.a.i.FilterSecurityInterceptor    : Secure object: FilterInvocation: URL: /manage; Attributes: [hasAuthority('USER')]
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.a.i.FilterSecurityInterceptor    : Previously Authenticated: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@681dd55: Principal: org.springframework.security.core.userdetails.User@6a68dc6: Username: user1; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: USER; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffff4c9c: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: 600351D5D67C5EC315DCB96ED3AD3A79; Granted Authorities: USER
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.access.vote.AffirmativeBased       : Voter: org.springframework.security.web.access.expression.WebExpressionVoter@20931c33, returned: 1
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.a.i.FilterSecurityInterceptor    : Authorization successful
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.a.i.FilterSecurityInterceptor    : RunAsManager did not change Authentication object
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : /manage reached end of additional filter chain; proceeding with original chain
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : GET "/manage", parameters={}
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to public java.lang.String info.saladlam.example.spring.noticeboard.controller.PrivateController.manage(org.springframework.ui.Model)
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL query
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.jdbc.core.JdbcTemplate               : Executing prepared SQL statement [SELECT * FROM message WHERE owner = ? ORDER BY publish_date DESC]
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'ID' to property 'id' of type 'java.lang.Long'
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'PUBLISH_DATE' to property 'publishDate' of type 'java.time.LocalDateTime'
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'REMOVE_DATE' to property 'removeDate' of type 'java.time.LocalDateTime'
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'OWNER' to property 'owner' of type 'java.lang.String'
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'DESCRIPTION' to property 'description' of type 'java.lang.String'
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'APPROVED_BY' to property 'approvedBy' of type 'java.lang.String'
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.jdbc.core.BeanPropertyRowMapper      : Mapping column 'APPROVED_DATE' to property 'approvedDate' of type 'java.time.LocalDateTime'
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.w.s.v.ContentNegotiatingViewResolver : Selected 'text/html' given [text/html, application/xhtml+xml, application/xml;q=0.9, */*;q=0.8]
2019-09-09 10:49:50.933 DEBUG 8052 --- [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@2f3aea8b
2019-09-09 10:49:50.933 DEBUG 8052 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed 200 OK
2019-09-09 10:49:50.933 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.a.ExceptionTranslationFilter     : Chain processed normally
2019-09-09 10:49:50.933 DEBUG 8052 --- [nio-8080-exec-1] s.s.w.c.SecurityContextPersistenceFilter : SecurityContextHolder now cleared, as request processing completed

User pass authorization.

2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.a.i.FilterSecurityInterceptor    : Previously Authenticated: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@681dd55: Principal: org.springframework.security.core.userdetails.User@6a68dc6: Username: user1; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: USER; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@ffff4c9c: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: 600351D5D67C5EC315DCB96ED3AD3A79; Granted Authorities: USER
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.access.vote.AffirmativeBased       : Voter: org.springframework.security.web.access.expression.WebExpressionVoter@20931c33, returned: 1
2019-09-09 10:49:50.917 DEBUG 8052 --- [nio-8080-exec-1] o.s.s.w.a.i.FilterSecurityInterceptor    : Authorization successful