Affects: 5.2 (I believe earlier versions are also affected)
When the dependency relationships between beans causes one or more beans to be ineligible for bean post-processing, info messages are logged:
2019-11-26 19:49:45.834 INFO 28828 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'playgroundApplication' of type [com.example.playground.PlaygroundApplication$$EnhancerBySpringCGLIB$$6f378901] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-11-26 19:49:45.837 INFO 28828 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.boot.actuate.autoconfigure.metrics.export.simple.SimpleMetricsExportAutoConfiguration' of type [org.springframework.boot.actuate.autoconfigure.metrics.export.simple.SimpleMetricsExportAutoConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-11-26 19:49:45.848 INFO 28828 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'management.metrics.export.simple-org.springframework.boot.actuate.autoconfigure.metrics.export.simple.SimpleProperties' of type [org.springframework.boot.actuate.autoconfigure.metrics.export.simple.SimpleProperties] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-11-26 19:49:45.851 INFO 28828 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'simpleConfig' of type [org.springframework.boot.actuate.autoconfigure.metrics.export.simple.SimplePropertiesConfigAdapter] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-11-26 19:49:45.853 INFO 28828 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.boot.actuate.autoconfigure.metrics.MetricsAutoConfiguration' of type [org.springframework.boot.actuate.autoconfigure.metrics.MetricsAutoConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-11-26 19:49:45.855 INFO 28828 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'micrometerClock' of type [io.micrometer.core.instrument.Clock$1] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-11-26 19:49:45.865 INFO 28828 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'simpleMeterRegistry' of type [io.micrometer.core.instrument.simple.SimpleMeterRegistry] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2019-11-26 19:49:45.878 INFO 28828 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'someAdvisor' of type [org.springframework.aop.support.DefaultPointcutAdvisor] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
From what I've seen these messages are often missed or presumed to be unimportant as they're at info level. I wonder if warn level would be more appropriate?
Beyond the level at which the messages are logged, the messages describe the problem but it's difficult to connect them to its cause. In this case, you have to know that AOP relies on proxies, that those proxies are created via a bean post-processor, and that any Advisor
beans are injected into the post-processor. This chain of events leads to eager initialization of the advisor and its dependencies.
I wonder if it would be possible to provide better diagnostics at runtime to explain why a bean is not eligible for bean post-processing? I'd also welcome some additions to the reference documentation that draw attention to the dangers of injecting dependencies into bean post-processors and also highlight where bean post-processing is used and the care that must then be taken when defining beans used by those post-processors.
Comment From: javolek
Could somebody here elaborate, why it is even possible to eagerly autowire dependencies into the bean-postprocessor. Wouldn't it be better to instantiate bean-postprocessors in another way or to disallow eager dependency instantiation? As far as I can understand this, the chances are high that something won't work as expected if this happens, while i.e. the autoproxying won't be done - the beans are autowirded without the proxy in between. This may result in somthing like the db-transaction missing on method marked as @Transactional or even worse - method security not being applied. Or am I wrong? Is this really such an Issue that doesn't deserve more attention?
Comment From: breun
I recently found literally thousands of info log messages from BeanPostProcessorChecker
in the logs of a build. This code base has lots of tests, so also lots of duplicate messages. We had been overlooking these messages for years. I've been able to fix ~95% by now, but once we reach 100% I was hoping to be able to make sure that we never make these mistakes again. As long as BeanPostProcessorChecker
only logs an info message, I guess new cases will get overlooked again.
@javolek I agree that it would be great if it would be just not possible for people that create their own BeanPostProcessor
beans to make this mistake, but do you have any concrete suggestions on how to achieve this?
As long as it's possible to get this wrong, Instead of an option to log at warn
or another level, I'd actually like the option to throw an exception, so we can force ourselves to fix this issue when it's triggered by an integration test.
Comment From: wilkinsona
Very nice! Thanks, @jhoeller.