【JAVA】【SPRING】【源码】解决大量打印 is not eligible for getting processed ……

1,378 阅读10分钟

背景

项目尾声,打扫战场,开发都在收尾了,我这里也看看历史运维提出的问题,比如启动慢&&日志太多。

大量打印: is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)

问题样例日志(组件和业务类均涉及):

 - 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)
 - 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)
 - Bean 'propertiesMeterFilter' of type [org.springframework.boot.actuate.autoconfigure.metrics.PropertiesMeterFilter] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
 - Bean 'org.springframework.boot.actuate.autoconfigure.metrics.web.client.HttpClientMetricsAutoConfiguration' of type [org.springframework.boot.actuate.autoconfigure.metrics.web.client.HttpClientMetricsAutoConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligibl
 - Bean 'metricsHttpClientUriTagFilter' of type [io.micrometer.core.instrument.config.MeterFilter$9] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
 - Bean 'metricsHttpServerUriTagFilter' of type [io.micrometer.core.instrument.config.MeterFilter$9] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
 - Bean 'org.springframework.boot.actuate.autoconfigure.metrics.JvmMetricsAutoConfiguration' of type [org.springframework.boot.actuate.autoconfigure.metrics.JvmMetricsAutoConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)

总结导图

排查过程

1、直接接DEBUG目标类

  • 可以看到直接原因if判断了3个条件。

其中的 instanceof BeanPostProcessor 一般为false,可忽略。

isInfrastructureBean如字面意思,判断是不是基础设施bean,系统的运行基石。我们使用的Bean一般为false,可忽略。发散【1】关于RootBeanDefinition

所以一般场景是最后一个条件导致的大量打印,当前工厂已注册的PostProcessor数量少于目标数量时,则打印。

image.png

  • 那么我们看下这个目标count哪里来的,在构造方法断点,找到入口。
  • 发散【2】:在定位的过程中,发现了下图断点进入了两次,两次的相关参数比如postProcessorNames也不一样,发散的点我们单独讨论。

image.png 这个方法将创建系统内的各BeanPostProcessor实现bean,count的计算就是系统已有的一些spring基础的postProcessor和将创建的bean数量,再加1,这个1就是checker自身。这个计算方法没有问题。

org.springframework.context.support.PostProcessorRegistrationDelegate#registerBeanPostProcessors(org.springframework.beans.factory.config.ConfigurableListableBeanFactory, org.springframework.context.support.AbstractApplicationContext)

image.png

  • 既然count的算法没问题,那为什么总是会判断到当前已有postProcessor数量小于目标count呢?

我们可以认为上图 注册PostProcessor的方法分几步:

(1)注册一个checker,也就是引发我们问题的直接源头。

(2)把系统里的全部postProcessor实现类,排序,分类为内部、优先、可排序、不排序几种,最后合并加到factory里。

(3)最后添加一个用于冗余保障listener全部注册到applicationContext应用上下文的探测器(实现了PostProcessor)。发散【3】: 为什么要这个postProcessor来冗余做listener的注册,以及这个postProcessor的说明。

beanFactory.addBeanPostProcessor(new ApplicationListenerDetector(applicationContext));

image.png

  • 经过断点及观察日志,问题正是出在了(3)这步,addBeanPostProcessor后,数量没变。
  • (其实这里误判了,根源不是这个,但引出了一些发散点还挺不错的)

2、问题溯源

2.1、堆栈的源头(误判)

  • 定位了直接导致的是add后数量没变,为什么?

  • 原因是在add时BeanFactory实际上已经有了这个bean,而这个类又重写了HashCode和Equals方法,那自然add时判重就没变。如图 image.png

  • 但是为什么会出现已有了还再add,结果算目标count时还没考虑到这种场景呢,为什么Spring框架会出现这个“低级失误”?

  • (因为是自己误判了啊,上面算count本身就没算最后一步的add,也就是(3)提的add后可能大于count,是有冗余的,问题根本不在这。而且源码也不知道为什么要在prepareBeanFactory时已经add过了,这里还要add,草台班子)

  • 当时仍然继续查了:想要回答这个问题,就必须结合上面提到的发散【3】和发散【2】才可以做出判断

2.1.1 发散【2】SpringBoot/Cloud的两阶段启动溯源
  • 源自SpringBoot启动流程中:prepareEnvironment image.png

  • 第一次启动refreshContext的原因是SpringCloud监听环境准备事件,分布式和单例的区别所以要提前监听事件准备自己的特殊环境。 最后倒数2行还会merge回主application,就是个搭桥了,具体实现按需求来,不纠结

  • 所以cloud自己构建了另一个SpringBootApplication指定了自己的参数,进行run(args) image.png

  • 继续执行和普通springbootApplication的启动流程一样,refreshContext,然后就到了引发直接问题的postProcessor那里。 注意这个obtainFreshBeanFactory,cloud构造的这个applicaation.run用的工厂是Genric实现一次性refresh,这都是细节了,总之和后面二阶段启动不是同一个,也就按理说不会影响。 image.png

  • 那么为什么会有两阶段启动?

原因大概是从源码命名和大概的结构,推测是cloud需要初始化一些自己的上下文信息,从源码上看,在一阶段启动后还加了个关闭自己的context的监听,相当于给springboot打cloud补丁了。

image.png

理解这个多就差不多该收了,不能无限发散抠别人代码,很没意义,非要一模一样吗?

人的精力是有限的,各司其职,可靠调用,管理同理。不能抠细节。

读源码很重要的就是自己的思路首先要在日常中练出来足够正确明晰,然后核心是对于英译中的合理使用,命名是很重要的东西,你要把源码框架当成现实中的工厂,语义上对了,那就对了一大半!

因为啊,没有成体系的资料,即使有也没有那么充足的时间,即使时间够这个时代做抠源码细节的回报率也……所以我们很多时候是在用自己的思路去试去拟合源码的思路,大道至简殊途同归。时间到了积累够了自然就会了,祛魅的过程。

理解到了思路和架构,聚焦对我们主要问题的影响,就ok了。收!

2.1.2 发散【3】ApplicationListenerDetector的目的
  • 根据源码注释

image.png

概括就是两个点:

(1)用于监听全部BeanPostProcessor实现类bean,因为spring通过getBeanOfType的获取是可能遗漏的不可靠的,冗余保障全部注册到工厂。

找源码得到说明,人家就这么设计的,没兼容内部/嵌套bean这个模式,那咋办嘛,打补丁呗,唉。 image.png

(2)看不懂他在写什么意思:DisposableBeanAdapter是spring对各种需要destroy方法的bean的适配,看源码是在doCreateBean时判断bean自身是否要加入工厂的disposableBeans销毁list。

判断依据:either DestructionAwareBeanPostProcessor or 有自己写的destory方法/close方法,这个只是更规范。唉……一堆历史遗留隐式也没个说明Note。

1、因为这个listener是直接new的,根本不会被扫描为beanPostProcessor走create bean然后add入工厂的流程,就就没被spring框架发现并加入工厂纳管,这写了个寂寞…… add的代码图自己向上找。

PS:启动后专门debug看了工厂,确实disposableBeans没有纳管它。

2、不知道他这里纠结序列化的目的是什么,后面水一篇吧。

2.1.3 结论(误判)
  • 知道了两阶段启动对于第二次的工厂以及postProcessors没有影响,只是cloud的补丁
  • 知道了最后加的这个listener兼postProcessor的目的,目的合理。
  • 但其实方法刚开始还没执行到添加时,就已经有了如图,这个类属于是spring内部的。根本不需要最后add一下。

又不是不能用,多一个add怎么了!spring不也是这样的各顾各的。

开玩笑的啦,只是说去逆向纠结小点没有意义,每个人都有自己的实现方式,别太丑陋能用就行。

image.png

  • 这个listener重写了equals和hashcode,所以add时判重了,就没进入,合理。

image.png

  • 误判啊!!!合理个XX啊,这时候确定了add不进去了,才意识到上面计算目标postProcessor的count就出错了,人家算的时候就没带这个listener(不在potProcessorNames里),进不进去都不该出问题啊。

2.2、堆栈的根源(真正原因)

  • 比对postProcessorNames和factory已有的processors
  • 如图,比对得知是DubboConfigEarlyInitializationPostProcessor导致的问题
    • 前面误判还是有一点用的,有的bean自定义equals&hashcode,有的是默认的引用。 image.png

Dubbo这个类实现了BD注册器加载+Bean工厂加载+Bean加载,三种后置处理器 image.png 虽然写了2次,但理论上做好了判断最终只注册一次,也许不是dubbo的锅? image.png 最终结果:DubboConfigEarlyInitializationPostProcessor对于BeanFactoryPostProcessor和BeanDefinitionRegistryPostProcessor的实现被(invokeBeanFactory),在spring启动流程中在【registerBeanPostProcessor】前。 导致DubboConfigEarlyInitializationPostProcessor提前注册进去,进而导致计算的count不准 image.png

image.png

2.3、解决

遇事不决类加载器,重写Dubbo这个类/或者打补丁,但这是实现方式,具体实现什么内容呢?

那就要弄清楚Dubbo这个Early它为什么要Early

它里面initFactory就真的只是做init下,注册自己进factory。

其罪一,不规范的接入框架,没有按照spring的模式让spring进行注册。 image.png

看样子也只是为了监听所有bean使用dubbo注解的情况,所以要尽可能早于业务bean进行注册启用,下面那个addConfig先不关注它 image.png

尽可能早,这就可以扣题了

is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)的中文意思

大概为不能处理全部bean:不符合由所有BeanPostProcessors处理的条件(例如:不符合自动代理的条件)

如果你去Debug看那些打印这个日志的bean的加载,会发现是因为BeanPostProcessor中也会用到bean,而bean加载进入工厂归根结底是要有先后顺序的,所以在我们注册postProcessor的过程中涉及的bean,就不会被所有postProcessor处理到

存在少量打印是合理的提示信息,我们要解决的是异常导致所有bean都打印!

所以看样子这个Dubbo类功能也是比较简单的,那就好改了

  • 目标:保证count计算正确
  • 方式1:改动spring注册那里的话,不论是改算法还是改add,都会为了dubbo的类特化侵入框架,破坏代码优雅(优雅又称鲁棒)
  • 方式2:改动Dubbo这个类内部逻辑,符合spring框架注册,不要自己注册。spring自然就自洽了。

当然选2了,遇事不决类加载器,相同包名下复制这个类,删除initFactory的逻辑那行。收工一切正常!

image.png

但方案2又引出新问题,如何让dubbo尽可能最早注册,很显然@Order可以,但是。。不规范使用一用就是HIGHEST,就很搞笑,没法保证真的第一个。

这事其实也无所谓,项目内规范,不要同时实现postProcessor和dubbo注解就好了,顺带一提dubbo-spring-boot-starter用到2.7.14

2.4、回归

1、所以我大胆的说啊,dependency的版本,一方面是安全可靠的版本,另一方面可能就是类似不大不小的问题坑被踩的经验版本吧,即又不是不能用

2、看源码真的不要真的看源码,看结构,看命名,看说明注释才是重点!看别人代码死路一条。

3、最后还随意在Dubbo包下翻了翻,就很老生常谈。

比如看了个Adaptive注解,一了解才知道是动态路由provider的多种实现的,类似这样字面意思的优秀代码,各类组件框架还有很多是肯定的。但没错,这是好源码,但从产品项目工程的角度说,这种诉求完全可以用需求单、配置清单上线规范管控住就好了。

即使你用优秀代码实现动态了,最后是不是还要上线流程,那为什么不写死个ifelse呢,甚至更可控好定位。对于一般人来说,技术已死,需求至上。

更进一步说即使做到了热更新,那变更这个事本身还是要走上线流程的,说到底对于各类容器化平台来说,停机上线和你热更新配置代码,真的差别不大。

总结

  • Dead Dubbo 大云时代,http yes, 能不用就别用
  • 引入经过充分使用验证的依赖,如果没有,就要求开启trace日志认真检查启动,尽量避免奇怪的问题。