SpringBoot 3.0.3 tracing with @EnableReactiveMethodSecurity

[ugurlu]

Hello,

We are testing micrometer reactive tracing.

If we add @EnableReactiveMethodSecurity annotation to our configuration we're not able to see traceId and spanId in logs.
If we comment out @EnableReactiveMethodSecurity context propogration works as expected but we're loosing method security.

If it helps, enabling reactive method security causes following additional logs

2023-02-24 12:44:22.530 [main] INFO  o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'org.springframework.boot.actuate.autoconfigure.observation.ObservationAutoConfiguration' of type [org.springframework.boot.actuate.autoconfigure.observation.ObservationAutoConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) {}
2023-02-24 12:44:22.546 [main] INFO  o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'observationRegistry' of type [io.micrometer.observation.SimpleObservationRegistry] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) {}

Thanks for your help.

[wilkinsona]

It's hard to help based on what you've described thus far. I can see that something is causing a couple of observability-related beans to be created too early, but I can't tell what that cause is or if it's the reason for your problem.
If you would like us to spend some more time investigating, please spend some time providing a complete yet minimal sample that reproduces the problem. You can share it with us by pushing it to a separate repository on GitHub or by zipping it up and attaching it to this issue.

[ugurlu]

You can observe behaviour on the attached file. TraceId is visible when

 curl -v http://localhost:8787/testmono1

is executed

2023-02-24T14:34:52.490+03:00  INFO [test-service,63f8a0dcced69e05a4af64c2068774bb,a4af64c2068774bb] 36100 --- [     parallel-1] com.example.demo.RestCtrl                : dummy
2023-02-24T14:34:52.497+03:00  INFO [test-service,63f8a0dcced69e05a4af64c2068774bb,a4af64c2068774bb] 36100 --- [     parallel-1] com.example.demo.RestCtrl                : dummy 2

When comment removed from line 17 of SecurityConfig.java log changes to

2023-02-24T14:34:17.028+03:00  INFO [test-service,NOIT,SSS] 40148 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.boot.actuate.autoconfigure.observation.ObservationAutoConfiguration' of type [org.springframework.boot.actuate.autoconfigure.observation.ObservationAutoConfiguration] is not eligible for getting 
processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2023-02-24T14:34:17.037+03:00  INFO [test-service,NOIT,SSS] 40148 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'observationRegistry' of type [io.micrometer.observation.SimpleObservationRegistry] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
..
..
..

2023-02-24T14:34:22.530+03:00  INFO [test-service,NOIT,SSS] 40148 --- [     parallel-1] com.example.demo.RestCtrl                : dummy
2023-02-24T14:34:22.536+03:00  INFO [test-service,NOIT,SSS] 40148 --- [     parallel-1] com.example.demo.RestCtrl                : dummy 2

EnableReactiveMethodSecurity.zip

[wilkinsona]

Thanks for the sample.

This looks like a bug in Spring Security. The preAuthorizeInterceptor bean defined in ReactiveAuthorizationManagerMethodSecurityConfiguration is an Advisor so it's created very early by the AOP infrastructure. It injects an ObjectProvider<ObservationRegistry> which should delay the creation of the ObservationRegistry. Unfortunately, this provider is passed into ReactiveAuthorizationManagerMethodSecurityConfiguration#manager which immediately calls getIfAvailable(). As a result the ObservationRegistry is created very early as part of setting up the AOP infrastructure and this prevents it from being post-processed correctly.

I have opened spring-projects/spring-security#12780 so that the Security team can investigate.

[ugurlu]

Thank you for the effort.