spring-graphql icon indicating copy to clipboard operation
spring-graphql copied to clipboard
verified publisher icon spring-projects

Improve Spring Security config in samples

Open zrbrown opened this issue 3 years ago • 4 comments

I'm having an issue using Spring Boot 3.0.0-M5 with Spring GraphQL where all authenticated webmvc calls return a 401. I've recreated it using the webmvc-http-security sample (though I wasn't actually able to run it out of this project based on the readme command - I copied the classes/resources over to a new maven project instead to get it running). To recreate:

  1. In SecurityConfig, change the permitAll() to authenticated()
  2. (optionally) In SecurityConfig remove @EnableGlobalMethodSecurity and in SalaryService remove PreAuthorize and Secured (just to remove authorization as a factor)
  3. Run the server and send a graphql query with Basic Auth for one of the users (e.g. admin/admin)

No matter what's requested, a 401 is returned. I've dug into this a bit, and it seems like the reason lies with the async context the request is handled in. I can fix it by changing to use webflux (dependency, annotation, security config), but by then I've just recreated the webflux-security sample.

The trace logs indicate that the GraphQL query executed just fine (and debugging confirms it), but notice that once the async state changes from DISPATCHING to DISPATCHED, the security context gets lost and an anonymous user is set. This does happen after the AsyncContextImpl$DebugException is logged, so maybe that has something to do with it?

2022-09-23T14:37:59.215-05:00 DEBUG 126118 --- [     parallel-1] n.graphql.execution.Execution            : Executing '30466b7a-54de-be2c-4bbd-3244e7892130' query operation: 'QUERY' using 'graphql.execution.AsyncExecutionStrategy' execution strategy
2022-09-23T14:37:59.219-05:00 TRACE 126118 --- [     parallel-1] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'salaryController'
2022-09-23T14:37:59.219-05:00 TRACE 126118 --- [     parallel-1] o.s.graphql.data.method.HandlerMethod    : Arguments: []
2022-09-23T14:37:59.220-05:00 DEBUG 126118 --- [     parallel-1] .i.d.DataLoaderDispatcherInstrumentation : Dispatching data loaders ([])
2022-09-23T14:37:59.221-05:00 DEBUG 126118 --- [     parallel-1] graphql.execution.ExecutionStrategy      : '30466b7a-54de-be2c-4bbd-3244e7892130' completing field '/employees'...
2022-09-23T14:37:59.226-05:00 DEBUG 126118 --- [     parallel-1] graphql.execution.ExecutionStrategy      : '30466b7a-54de-be2c-4bbd-3244e7892130' completing field '/employees[0]/id'...
2022-09-23T14:37:59.227-05:00 DEBUG 126118 --- [     parallel-1] graphql.execution.ExecutionStrategy      : '30466b7a-54de-be2c-4bbd-3244e7892130' completing field '/employees[0]/name'...
2022-09-23T14:37:59.229-05:00 DEBUG 126118 --- [     parallel-1] .i.d.DataLoaderDispatcherInstrumentation : Dispatching data loaders ([])
2022-09-23T14:37:59.229-05:00 DEBUG 126118 --- [     parallel-1] graphql.GraphQL                          : Execution '30466b7a-54de-be2c-4bbd-3244e7892130' completed with zero errors
2022-09-23T14:37:59.230-05:00 DEBUG 126118 --- [     parallel-1] o.s.g.server.webmvc.GraphQlHttpHandler   : Execution complete
2022-09-23T14:37:59.231-05:00 DEBUG 126118 --- [     parallel-1] o.s.w.c.request.async.WebAsyncManager    : Async result set, dispatch to /graphql
2022-09-23T14:37:59.232-05:00 DEBUG 126118 --- [     parallel-1] o.apache.catalina.core.AsyncContextImpl  : Req: 1e9abcac  CReq: 32f23793  RP: 5f6f5afa  Stage: 7  Thread:           parallel-1  State:                  N/A  Method: dispatch     URI: /graphql

org.apache.catalina.core.AsyncContextImpl$DebugException: null
	at org.apache.catalina.core.AsyncContextImpl.logDebug(AsyncContextImpl.java:514) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:185) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:178) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:172) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.springframework.security.web.servletapi.HttpServlet3RequestFactory$SecurityContextAsyncContext.dispatch(HttpServlet3RequestFactory.java:316) ~[spring-security-web-6.0.0-M7.jar:6.0.0-M7]
	at org.springframework.web.context.request.async.StandardServletAsyncWebRequest.dispatch(StandardServletAsyncWebRequest.java:132) ~[spring-web-6.0.0-M6.jar:6.0.0-M6]
	at org.springframework.web.context.request.async.WebAsyncManager.setConcurrentResultAndDispatch(WebAsyncManager.java:400) ~[spring-web-6.0.0-M6.jar:6.0.0-M6]
	at org.springframework.web.context.request.async.WebAsyncManager.lambda$startDeferredResultProcessing$8(WebAsyncManager.java:468) ~[spring-web-6.0.0-M6.jar:6.0.0-M6]
	at org.springframework.web.context.request.async.DeferredResult.setResultInternal(DeferredResult.java:267) ~[spring-web-6.0.0-M6.jar:6.0.0-M6]
	at org.springframework.web.context.request.async.DeferredResult.setResult(DeferredResult.java:238) ~[spring-web-6.0.0-M6.jar:6.0.0-M6]
	at org.springframework.web.servlet.function.DefaultAsyncServerResponse.lambda$createDeferredResult$0(DefaultAsyncServerResponse.java:165) ~[spring-webmvc-6.0.0-M6.jar:6.0.0-M6]
	at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:841) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2147) ~[na:na]
	at reactor.core.publisher.MonoToCompletableFuture.onNext(MonoToCompletableFuture.java:64) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:245) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.MonoFlatMap$FlatMapInner.onNext(MonoFlatMap.java:305) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:122) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.MonoCompletionStage$MonoCompletionStageSubscription.accept(MonoCompletionStage.java:116) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.MonoCompletionStage$MonoCompletionStageSubscription.accept(MonoCompletionStage.java:62) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.uniWhenCompleteStage(CompletableFuture.java:887) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:2325) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:144) ~[na:na]
	at reactor.core.publisher.MonoCompletionStage$MonoCompletionStageSubscription.request(MonoCompletionStage.java:139) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.request(FluxMapFuseable.java:171) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.FluxMap$MapSubscriber.request(FluxMap.java:164) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.MonoFlatMap$FlatMapInner.onSubscribe(MonoFlatMap.java:291) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.FluxMap$MapSubscriber.onSubscribe(FluxMap.java:92) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onSubscribe(FluxMapFuseable.java:96) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.MonoCompletionStage.subscribe(MonoCompletionStage.java:53) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.MonoDeferContextual.subscribe(MonoDeferContextual.java:55) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:165) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.MonoDelay$MonoDelayRunnable.propagateDelay(MonoDelay.java:271) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.publisher.MonoDelay$MonoDelayRunnable.run(MonoDelay.java:286) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:68) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at reactor.core.scheduler.SchedulerTask.call(SchedulerTask.java:28) ~[reactor-core-3.5.0-M6.jar:3.5.0-M6]
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[na:na]
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[na:na]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[na:na]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[na:na]
	at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]

2022-09-23T14:37:59.233-05:00 DEBUG 126118 --- [     parallel-1] org.apache.coyote.AsyncStateMachine      : Changing async state from [STARTED] to [DISPATCHING]
2022-09-23T14:37:59.233-05:00 DEBUG 126118 --- [nio-8080-exec-2] o.a.c.authenticator.AuthenticatorBase    : Security checking request POST /graphql
2022-09-23T14:37:59.234-05:00 DEBUG 126118 --- [nio-8080-exec-2] org.apache.catalina.realm.RealmBase      :   No applicable constraints defined
2022-09-23T14:37:59.234-05:00 DEBUG 126118 --- [nio-8080-exec-2] o.a.c.authenticator.AuthenticatorBase    : Not subject to any constraint
2022-09-23T14:37:59.234-05:00 DEBUG 126118 --- [nio-8080-exec-2] o.apache.catalina.core.StandardWrapper   :   Returning non-STM instance
2022-09-23T14:37:59.234-05:00 DEBUG 126118 --- [nio-8080-exec-2] o.apache.catalina.core.AsyncContextImpl  : Req: 1e9abcac  CReq: 32f23793  RP: 5f6f5afa  Stage: 3  Thread: http-nio-8080-exec-2  State:                  N/A  Method: intDispatch  URI: /graphql

org.apache.catalina.core.AsyncContextImpl$DebugException: null
	at org.apache.catalina.core.AsyncContextImpl.logDebug(AsyncContextImpl.java:514) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.catalina.core.AsyncContextImpl.doInternalDispatch(AsyncContextImpl.java:349) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:194) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:119) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:246) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.coyote.AbstractProcessor.dispatch(AbstractProcessor.java:241) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:59) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:867) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1762) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-10.0.23.jar:10.0.23]
	at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]

2022-09-23T14:37:59.234-05:00 DEBUG 126118 --- [nio-8080-exec-2] org.apache.coyote.AsyncStateMachine      : Changing async state from [DISPATCHING] to [DISPATCHED]
2022-09-23T14:37:59.235-05:00 DEBUG 126118 --- [nio-8080-exec-2] o.apache.catalina.core.StandardWrapper   :   Returning non-STM instance
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.b.w.s.f.OrderedRequestContextFilter  : Bound request context to thread: SecurityContextHolderAwareRequestWrapper[ org.springframework.security.web.header.HeaderWriterFilter$HeaderWriterRequest@75c13c67]
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Trying to match request against DefaultSecurityFilterChain [RequestMatcher=any request, Filters=[org.springframework.security.web.session.DisableEncodeUrlFilter@e91b4f4, org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@2ffe243f, org.springframework.security.web.context.SecurityContextHolderFilter@4733f6f5, org.springframework.security.web.header.HeaderWriterFilter@5f59ea8c, org.springframework.security.web.authentication.logout.LogoutFilter@6ec63f8, org.springframework.security.web.authentication.www.BasicAuthenticationFilter@66522ead, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@438c9aa7, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@3453acd2, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@58ae402b, org.springframework.security.web.session.SessionManagementFilter@3b42121d, org.springframework.security.web.access.ExceptionTranslationFilter@53d9826f, org.springframework.security.web.access.intercept.FilterSecurityInterceptor@51fc862e]] (1/1)
2022-09-23T14:37:59.235-05:00 DEBUG 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Securing POST /graphql
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Invoking DisableEncodeUrlFilter (1/12)
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Invoking WebAsyncManagerIntegrationFilter (2/12)
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Invoking SecurityContextHolderFilter (3/12)
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Invoking HeaderWriterFilter (4/12)
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Invoking LogoutFilter (5/12)
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.s.w.a.logout.LogoutFilter            : Did not match request to Or [Ant [pattern='/logout', GET], Ant [pattern='/logout', POST], Ant [pattern='/logout', PUT], Ant [pattern='/logout', DELETE]]
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Invoking BasicAuthenticationFilter (6/12)
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Invoking RequestCacheAwareFilter (7/12)
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.s.w.s.HttpSessionRequestCache        : matchingRequestParameterName is required for getMatchingRequest to lookup a value, but not provided
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Invoking SecurityContextHolderAwareRequestFilter (8/12)
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Invoking AnonymousAuthenticationFilter (9/12)
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Invoking SessionManagementFilter (10/12)
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Invoking ExceptionTranslationFilter (11/12)
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Invoking FilterSecurityInterceptor (12/12)
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.s.w.a.AnonymousAuthenticationFilter  : Set SecurityContextHolder to AnonymousAuthenticationToken [Principal=anonymousUser, Credentials=[PROTECTED], Authenticated=true, Details=WebAuthenticationDetails [RemoteIpAddress=127.0.0.1, SessionId=57F3999E4F78BB5799937CEA75C3CEBE], Granted Authorities=[ROLE_ANONYMOUS]]
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.s.w.a.AnonymousAuthenticationFilter  : Set SecurityContextHolder to AnonymousAuthenticationToken [Principal=anonymousUser, Credentials=[PROTECTED], Authenticated=true, Details=WebAuthenticationDetails [RemoteIpAddress=127.0.0.1, SessionId=57F3999E4F78BB5799937CEA75C3CEBE], Granted Authorities=[ROLE_ANONYMOUS]]
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.s.w.a.i.FilterSecurityInterceptor    : Did not re-authenticate AnonymousAuthenticationToken [Principal=anonymousUser, Credentials=[PROTECTED], Authenticated=true, Details=WebAuthenticationDetails [RemoteIpAddress=127.0.0.1, SessionId=57F3999E4F78BB5799937CEA75C3CEBE], Granted Authorities=[ROLE_ANONYMOUS]] before authorizing
2022-09-23T14:37:59.235-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.s.w.a.i.FilterSecurityInterceptor    : Authorizing filter invocation [POST /graphql] with attributes [authenticated]
2022-09-23T14:37:59.236-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.s.w.a.expression.WebExpressionVoter  : Voted to deny authorization
2022-09-23T14:37:59.236-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.s.w.a.i.FilterSecurityInterceptor    : Failed to authorize filter invocation [POST /graphql] with attributes [authenticated] using AffirmativeBased [DecisionVoters=[org.springframework.security.web.access.expression.WebExpressionVoter@136ccbfe], AllowIfAllAbstainDecisions=false]
2022-09-23T14:37:59.236-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'delegatingApplicationListener'
2022-09-23T14:37:59.236-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'startupTimeMetrics'
2022-09-23T14:37:59.236-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'springApplicationAdminRegistrar'
2022-09-23T14:37:59.236-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.s.w.a.AnonymousAuthenticationFilter  : Set SecurityContextHolder to AnonymousAuthenticationToken [Principal=anonymousUser, Credentials=[PROTECTED], Authenticated=true, Details=WebAuthenticationDetails [RemoteIpAddress=127.0.0.1, SessionId=57F3999E4F78BB5799937CEA75C3CEBE], Granted Authorities=[ROLE_ANONYMOUS]]
2022-09-23T14:37:59.236-05:00 TRACE 126118 --- [nio-8080-exec-2] o.s.s.w.a.ExceptionTranslationFilter     : Sending AnonymousAuthenticationToken [Principal=anonymousUser, Credentials=[PROTECTED], Authenticated=true, Details=WebAuthenticationDetails [RemoteIpAddress=127.0.0.1, SessionId=57F3999E4F78BB5799937CEA75C3CEBE], Granted Authorities=[ROLE_ANONYMOUS]] to authentication entry point since access is denied

org.springframework.security.access.AccessDeniedException: Access is denied

Thanks for looking at this! Other than this issue, I've been able to upgrade to Boot 3 with ease.

zrbrown avatar Sep 23 '22 19:09 zrbrown

I solved the problem - turns out I needed to permit the route pattern:

                .authorizeRequests(requests -> requests
                        .mvcMatchers("/**").permitAll()
                        .anyRequest().authenticated()
                )

I don't recall having to do this before (did Spring Security change to require it?), but in any case this fixes it.

I think that in the spirit of having a more realistic example though, the sample project's SecurityConfig should be updated to reflect the above snippet. Might save someone else some time in the future!

zrbrown avatar Sep 23 '22 21:09 zrbrown

Thanks for the report. Keep in mind the samples aren't going to remain as they are. They are also no longer building in the 1.1.x branch, but but we could make an update in the 1.0.x branch.

@rwinch, any feedback from your side, on whether something changed, and if it makes sense to update the sample, irrespective?

rstoyanchev avatar Oct 10 '22 09:10 rstoyanchev

I am facing the same issue and added `permitAll()' but did not fix the problem

thirumalx avatar Nov 29 '22 10:11 thirumalx

I guess it's fixed in 3.0.1. After upgrading to 3.0.1, I am not facing the issue

thirumalx avatar Dec 26 '22 06:12 thirumalx