Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Improve Spring Security config in samples #496

Open
zrbrown opened this issue Sep 23, 2022 · 4 comments
Open

Improve Spring Security config in samples #496

zrbrown opened this issue Sep 23, 2022 · 4 comments
Labels
status: waiting-for-triage An issue we've not yet triaged
Milestone
Triage Queue

Comments

@zrbrown
Copy link

zrbrown commented Sep 23, 2022

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.
@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged label Sep 23, 2022
@zrbrown
Copy link
Author

zrbrown commented Sep 23, 2022

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!

@rstoyanchev
Copy link
Contributor

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 rstoyanchev changed the title Spring Security authenticated() 401 Improve Spring Security config in samples Oct 10, 2022
@rstoyanchev rstoyanchev added this to the Triage Queue milestone Oct 10, 2022
@m-thirumal
Copy link

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

@m-thirumal
Copy link

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
status: waiting-for-triage An issue we've not yet triaged
Projects
None yet
Milestone
Triage Queue
Development

No branches or pull requests
4 participants
@rstoyanchev @zrbrown @m-thirumal @spring-projects-issues