Spring Securityウェブアプリケーションをデバッグする

# デバッグ出力を設定する

僕の[サンプルアプリケーション](https://qiita.com/saladlam/items/ce25e79dc2babcb453c3)を使って、やり方を示す。

まず、クラス"info.saladlam.example.spring.noticeboard.config.WebSecurityConfig"に、下のようにアノテーション@EnableWebSecurityに値を渡す

```java
@EnableWebSecurity(debug = true)
```

それからファイル"src/main/resources/application.properties"に、下のコードを入れる

```configuration
logging.level.org.springframework.security=debug
```

ブラウザでリンク"http://localhost:8080/"を開き、もし下のようなデバッグ出力を見れば、セットアップが完成した。

```
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
```

# デバッグ出力の意味

HTTPリクエストヘッダ

```
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
```

# ログインしないまま保護されたリソースをアクセスする

もし下の条件を満たすと、ユーザーが"http://localhost:8080/manage"にアクセスするができる
1. ユーザーがログインされたこと。そうではないと"http://localhost:8080/login"に転送する
2. ユーザーが"USER"権限を持っていること。

下はデバッグ出力。

```
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
```

デバッグ出力を見ると、アクセスコントロールが正しく設定されたことが分かった。

```
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
```

前アクセスしたリンクが記録され、そしてログインページに転送する。

```
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'
```

# オーセンティケーションが実行する

ユーザー名とパスワードを入力して、そしてオーセンティケーションがリンク"http://localhost:8080/loginHandler"に実行する。

下はデバッグ出力。

```
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
```

オーセンティケーションはUsernamePasswordAuthenticationFilterで処理された。ユーザーデータはデータベースに探し、"USER"権限を持っているユーザー"user1"が発見した。

```
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'
```

# ログイン、そして保護されたリソースをアクセスする

ユーザー"user1"がリンク"http://localhost:8080/manage"をアクセスする。下はデバッグ出力。

```
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
```

ユーザー認可が成功した。

```
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
```