Spring FactoryBean 创建的 Advisor 无法应用于增强

最近的工作重心是帮助公司做日志统一格式方面的工作。也就是规范日志，之前的日志文件只分为了 error.log 和 info.log。现在要把它更为细为分以下几种：

more business log：细粒度的业务日志文件区分(Dao、Manage、Service、Web)
method digest log：方法级别的日志摘要(对应业务日志的摘要日志)
a call chain profile log：当前系统一次整个完整调用的层级概要图

这种不仅可以在排查问题更加方便，同时也可以通过监控方法摘要日志文件当某个方法调用时间达到设置的阈值时还可以进行报警。

1、出现问题

在实现方法摘要日志时，实现原理就通过实现 org.aopalliance.intercept.MethodInterceptor 定义增强通知打印出调用的哪个方法、是否成功返回结果、消耗时间、请求参数及响应参数。然后通过 Spring AOP 的切面表达式来对具体包中的 Spring Bean 进行增强。最开始的版本如下：

@Configuration
public class DigestLogConfig {

	@Bean
	public Advisor serviceDigestLogAdvisor(){
		BasicDigestLogInterceptor basicDigestLogInterceptor = new BasicDigestLogInterceptor("SERVICE-DIGEST-LOGGER");
		AspectJExpressionPointcut aspectJExpressionPointcut = new AspectJExpressionPointcut();
		aspectJExpressionPointcut.setExpression("within(com.fintech.query.service.impl.*)");
		DefaultBeanFactoryPointcutAdvisor advisor = new DefaultBeanFactoryPointcutAdvisor();
		advisor.setAdvice(basicDigestLogInterceptor);
		advisor.setPointcut(aspectJExpressionPointcut);
		return advisor;
	}
}

这样业务方就需要关注以下几个类：

BasicDigestLogInterceptor：日志框架提供的增强类，具体的增强通知
AspectJExpressionPointcut ： Spring 框架提供的切面类，哪些 bean 对象可以被增强
DefaultBeanFactoryPointcutAdvisor：Spring 框架提供的类，用于保存通知类以及切面类

其实对于日志框架使用方，它的关注点就 2 个：这个日志应该打印到定义的哪个文件中以及哪些类应该被增强。对于日志框架使用者来说它应该只需要关注日志框架提供的类，对于 Spring 框架的类应该日志lksa内部其实而不应该使用者关注。这就是最小依赖原则，这样出现问题的概率也会最小。所以决定使用 Spring FactoryBean 来创建这个通知。用户只需要定义需要打印的日志名称以及需要增强的 spring bean 的切面表达式就可以了。所以我就定义了以下这个 FactoryBean。

public class DigestLoggerFactoryBen implements FactoryBean<Advisor> {

	private String loggerName;
	private String aspectjExpression;

	public DigestLoggerFactoryBen(){}
	
	public DigestLoggerFactoryBen(String loggerName, String aspectjExpression) {
		this.loggerName = loggerName;
		this.aspectjExpression = aspectjExpression;
	}

	public void setLoggerName(String loggerName) {
		this.loggerName = loggerName;
	}

	public void setAspectjExpression(String aspectjExpression) {
		this.aspectjExpression = aspectjExpression;
	}

	@Override
	public Advisor getObject() throws Exception {
		Assert.hasText(this.loggerName, "loggerName must not be empty");
		Assert.hasText(this.aspectjExpression, "aspectjExpression must not be empty");
		BasicDigestLogInterceptor basicDigestLogInterceptor = new BasicDigestLogInterceptor(loggerName);
		AspectJExpressionPointcut aspectJExpressionPointcut = new AspectJExpressionPointcut();
		aspectJExpressionPointcut.setExpression(aspectjExpression);
		DefaultBeanFactoryPointcutAdvisor advisor = new DefaultBeanFactoryPointcutAdvisor();
		advisor.setAdvice(basicDigestLogInterceptor);
		advisor.setPointcut(aspectJExpressionPointcut);
		return advisor;
	}

	@Override
	public Class<?> getObjectType() {
		return Advisor.class;
	}

	@Override
	public boolean isSingleton() {
		return true;
	}

}

如果不了解 Spring Factory 的朋友，可以看之前这篇文章 – Spring bean 之 FactoryBean 。

那么对于之前的配置方式就可以修改成以下这种方式：

@Configuration
public class DigestLogConfig {

	@Bean
	public DigestLoggerFactoryBen serviceDigestLogAdvisor(){
		DigestLoggerFactoryBen loggerFactoryBen = new DigestLoggerFactoryBen();
		loggerFactoryBen.setLoggerName("SERVICE-DIGEST-LOGGER");
		loggerFactoryBen.setAspectjExpression("within(com.fintech.query.service.impl.*)");
		return loggerFactoryBen;
	}

}

日志框架使用者只需要配置提供的 DigestLoggerFactoryBen 这样对它就友好多了。但是我在测试的时候发现日志并没有打印到对应的文件当中。

2、诊断问题

通过 debug 源码跟踪到了 BeanFactoryAdvisorRetrievalHelper。

public class BeanFactoryAdvisorRetrievalHelper {

	private static final Log logger = LogFactory.getLog(BeanFactoryAdvisorRetrievalHelper.class);

	private final ConfigurableListableBeanFactory beanFactory;

	private String[] cachedAdvisorBeanNames;


	/**
	 * Create a new BeanFactoryAdvisorRetrievalHelper for the given BeanFactory.
	 * @param beanFactory the ListableBeanFactory to scan
	 */
	public BeanFactoryAdvisorRetrievalHelper(ConfigurableListableBeanFactory beanFactory) {
		Assert.notNull(beanFactory, "ListableBeanFactory must not be null");
		this.beanFactory = beanFactory;
	}


	/**
	 * Find all eligible Advisor beans in the current bean factory,
	 * ignoring FactoryBeans and excluding beans that are currently in creation.
	 * @return the list of {@link org.springframework.aop.Advisor} beans
	 * @see #isEligibleBean
	 */
	public List<Advisor> findAdvisorBeans() {
		// Determine list of advisor bean names, if not cached already.
		String[] advisorNames = null;
		synchronized (this) {
			advisorNames = this.cachedAdvisorBeanNames;
			if (advisorNames == null) {
				// Do not initialize FactoryBeans here: We need to leave all regular beans
				// uninitialized to let the auto-proxy creator apply to them!
				advisorNames = BeanFactoryUtils.beanNamesForTypeIncludingAncestors(
						this.beanFactory, Advisor.class, true, false);
				this.cachedAdvisorBeanNames = advisorNames;
			}
		}
		if (advisorNames.length == 0) {
			return new LinkedList<Advisor>();
		}

		List<Advisor> advisors = new LinkedList<Advisor>();
		for (String name : advisorNames) {
			if (isEligibleBean(name)) {
				if (this.beanFactory.isCurrentlyInCreation(name)) {
					if (logger.isDebugEnabled()) {
						logger.debug("Skipping currently created advisor '" + name + "'");
					}
				}
				else {
					try {
						advisors.add(this.beanFactory.getBean(name, Advisor.class));
					}
					catch (BeanCreationException ex) {
						Throwable rootCause = ex.getMostSpecificCause();
						if (rootCause instanceof BeanCurrentlyInCreationException) {
							BeanCreationException bce = (BeanCreationException) rootCause;
							if (this.beanFactory.isCurrentlyInCreation(bce.getBeanName())) {
								if (logger.isDebugEnabled()) {
									logger.debug("Skipping advisor '" + name +
											"' with dependency on currently created bean: " + ex.getMessage());
								}
								// Ignore: indicates a reference back to the bean we're trying to advise.
								// We want to find advisors other than the currently created bean itself.
								continue;
							}
						}
						throw ex;
					}
				}
			}
		}
		return advisors;
	}

	/**
	 * Determine whether the aspect bean with the given name is eligible.
	 * <p>The default implementation always returns {@code true}.
	 * @param beanName the name of the aspect bean
	 * @return whether the bean is eligible
	 */
	protected boolean isEligibleBean(String beanName) {
		return true;
	}

}

当 Spring 框架启动时，在初始化第一个 bean 的时候通过 BeanFactoryUtils#beanNamesForTypeIncludingAncestors 方法去拿定义到 Spring 容器当中的 Advisor所有的 beanName。然后就缓存下到属性 cachedAdvisorBeanNames 当中。后续的 spring bean 创建需要通知类型的 bean 名称直接从这个缓存中获取就可以了。

注意：它的第三个参数是不允许这个 bean 提前暴露，也就是说如果这个 bean 没有被初始化就不会拿这个 bean。

继续跟踪源码到了 DefaultListableBeanFactory#doGetBeanNamesForType ：


	private String[] doGetBeanNamesForType(ResolvableType type, boolean includeNonSingletons, boolean allowEagerInit) {
		List<String> result = new ArrayList<String>();

		// Check all bean definitions.
		for (String beanName : this.beanDefinitionNames) {
			// Only consider bean as eligible if the bean name
			// is not defined as alias for some other bean.
			if (!isAlias(beanName)) {
				try {
					RootBeanDefinition mbd = getMergedLocalBeanDefinition(beanName);
					// Only check bean definition if it is complete.
					if (!mbd.isAbstract() && (allowEagerInit ||
							((mbd.hasBeanClass() || !mbd.isLazyInit() || isAllowEagerClassLoading())) &&
									!requiresEagerInitForType(mbd.getFactoryBeanName()))) {
						// In case of FactoryBean, match object created by FactoryBean.
						boolean isFactoryBean = isFactoryBean(beanName, mbd);
						BeanDefinitionHolder dbd = mbd.getDecoratedDefinition();
						boolean matchFound =
								(allowEagerInit || !isFactoryBean ||
										(dbd != null && !mbd.isLazyInit()) || containsSingleton(beanName)) &&
								(includeNonSingletons ||
										(dbd != null ? mbd.isSingleton() : isSingleton(beanName))) &&
								isTypeMatch(beanName, type);
						if (!matchFound && isFactoryBean) {
							// In case of FactoryBean, try to match FactoryBean instance itself next.
							beanName = FACTORY_BEAN_PREFIX + beanName;
							matchFound = (includeNonSingletons || mbd.isSingleton()) && isTypeMatch(beanName, type);
						}
						if (matchFound) {
							result.add(beanName);
						}
					}
				}
				catch (CannotLoadBeanClassException ex) {
					if (allowEagerInit) {
						throw ex;
					}
					// Probably contains a placeholder: let's ignore it for type matching purposes.
					if (this.logger.isDebugEnabled()) {
						this.logger.debug("Ignoring bean class loading failure for bean '" + beanName + "'", ex);
					}
					onSuppressedException(ex);
				}
				catch (BeanDefinitionStoreException ex) {
					if (allowEagerInit) {
						throw ex;
					}
					// Probably contains a placeholder: let's ignore it for type matching purposes.
					if (this.logger.isDebugEnabled()) {
						this.logger.debug("Ignoring unresolvable metadata in bean definition '" + beanName + "'", ex);
					}
					onSuppressedException(ex);
				}
			}
		}

		// Check manually registered singletons too.
		for (String beanName : this.manualSingletonNames) {
			try {
				// In case of FactoryBean, match object created by FactoryBean.
				if (isFactoryBean(beanName)) {
					if ((includeNonSingletons || isSingleton(beanName)) && isTypeMatch(beanName, type)) {
						result.add(beanName);
						// Match found for this bean: do not match FactoryBean itself anymore.
						continue;
					}
					// In case of FactoryBean, try to match FactoryBean itself next.
					beanName = FACTORY_BEAN_PREFIX + beanName;
				}
				// Match raw bean instance (might be raw FactoryBean).
				if (isTypeMatch(beanName, type)) {
					result.add(beanName);
				}
			}
			catch (NoSuchBeanDefinitionException ex) {
				// Shouldn't happen - probably a result of circular reference resolution...
				if (logger.isDebugEnabled()) {
					logger.debug("Failed to check manually registered singleton with name '" + beanName + "'", ex);
				}
			}
		}

		return StringUtils.toStringArray(result);
	}

这个方法很长，我们主要是关注点停留在第一个 for 循环。下面我简单讲解一下它的逻辑：

遍历注册到 Spring 容器当中的 Spring Bean 定义的名称
并且当前的 bean 名称不是 alias 也就是别名
通过这个 spring bean 名称获取到这个 BeanDefinition 也就是这个 bean 的定义
接着是一段复杂逻辑判断(可以忽略，之前定义的 DigestLoggerFactoryBen 是满足的)
然后判断这个 Spring bean 是不是 FactoryBean
接着又是一段复杂的逻辑判断：如下：

allowEagerInit || !isFactoryBean || (dbd != null && !mbd.isLazyInit()) || containsSingleton(beanName))
(includeNonSingletons || (dbd != null ? mbd.isSingleton() : isSingleton(beanName)))
isTypeMatch(beanName, type);
他们三者的关系是且的关系。当进行第一段逻辑判断的时候：
1.1 allowEagerInit ：是否允许提前暴露，之前已经提过了是 false
1.2 !isFactoryBean ：这个 bean 是非 FactoryBean，也是 false
1.3 判断这个 BeanDefinition 非空且是非是非懒加载，结果它是空。所以也是 false
1.4 判断已经初始化的单例对象是否包含这个 bean，因为这个第一次初始化的时候就会调用获取 Advisor 的 bean 对象且要求不能提前暴露。所以已经初始化的单例对象只有 spring 框架的一些内部对象。所有也是 false。
所以就进入到!matchFound && isFactoryBean 这段逻辑。(includeNonSingletons || mbd.isSingleton()) && isTypeMatch(beanName, type)
4.1 (includeNonSingletons || mbd.isSingleton()) ：传入的是允许非单例对象并且定义的这个 DigestLoggerFactoryBen 对象是单例的，所以满足条件。
4.2 但是需要把当前的 beanName 加上& 前缀看是否能够在容器中是否有 $beanName 有对象存在，显然结果是 false。

综上所述：我们定义的 DigestLoggerFactoryBen 这个 bean，当 Spring 获取通知列表的时候得不到它的。提高用户的可用性使用 FactoryBean 这种方法来定义 Advisor 显示是行不通的。那么有什么方式来解决这个问题呢？

3、梳理

我们重新来思考梳理一下这个问题：

日志框架使用者 --> 只需要关注，日志名称的定义以及切面表达式的定义
Spring 框架 --> 在获取 Advisor 的时候通过 BeanDefinition(不能使用 FactoryBean 定义的 bean)

由于之前是日志定义和 Spring bean 定义是在一个对象里面。日志框架使用者和 Spring 框架其实中间缺少一个代理者，就是把日志框架使用者的定义的日志摘要定义的日志名称及切面表达式获取到然后日志框架内部通过 Spring 的扩展来创建 Advisor。

把解决问题的思路理清楚了，解决问题就比较简单了。通过上面我们的跟踪源码我们首先把对 Spring bean 增强的 BeanPostProcessor 这个接口排除，上面获取 Advisor 的方式是通过 Spring Bean 的定义也就是 BeanDefinion 来的。那么我们的修改点就应该围绕它来，下面就是整个解决这个问题的思路：

1、定义一个 POGO 对象用于日志框架者的定义日志打印
2、实现 Spring 框架对于 BeanDefinion 的增强接口也就是BeanFactoryPostProcessor，把 POGO 转换成 Advisor 对象

步骤二它的主要逻辑就是获取到 PGOG 定义的日志名称以及日志需要增强的切面表达式重新生成 Advisor，然后覆盖定义的 POGO 定义的 BeanDefinion。

4、解决问题

下面就是解决问题需要涉及到的类。

4.1 DigestLoggerConfig.java

定义的 POGO 用户只需要通过它来定义日志名称以及切面表达式就可以了

@Data
public class DigestLoggerConfig implements InitializingBean {

	private String loggerName;
	private String aspectjExpression;

	public DigestLoggerConfig() {
	}

	public DigestLoggerConfig(String loggerName, String aspectjExpression) {
		this.loggerName = loggerName;
		this.aspectjExpression = aspectjExpression;
	}

	public String getLoggerName() {
		return loggerName;
	}

	public String getAspectjExpression() {
		return aspectjExpression;
	}

	@Override
	public String toString() {
		return "DigestLoggerConfig{" +
				"loggerName='" + loggerName + '\'' +
				", aspectjExpression='" + aspectjExpression + '\'' +
				'}';
	}

	@Override
	public void afterPropertiesSet() throws Exception {
		Assert.hasText(this.loggerName, "loggerName must not be empty");
		Assert.hasText(this.aspectjExpression, "aspectjExpression must not be empty");
	}
}

4.2 DigestLogBeanPostProcess.java

利用 Spring 框架的扩展 BeanFactoryPostProcessor 对 BeanDefinion 进行增强。把日志框架使用者定义的 POGO 对象转换成通知类，实现对目标对象的增强。

public class DigestLogBeanPostProcess implements BeanFactoryPostProcessor {

	@Override
	public void postProcessBeanFactory(ConfigurableListableBeanFactory beanFactory) throws BeansException {
		if(!(beanFactory instanceof BeanDefinitionRegistry)) {
			return;
		}
		String[] beanNames = beanFactory.getBeanNamesForType(DigestLoggerConfig.class);
		if(beanNames == null || beanNames.length == 0) {
			return;
		}
		for (String beanName : beanNames) {
			DigestLoggerConfig config = beanFactory.getBean(beanName, DigestLoggerConfig.class);
			if(!StringUtils.hasLength(config.getLoggerName())){
				return;
			}
			if(!StringUtils.hasLength(config.getAspectjExpression())){
				return;
			}
			BeanDefinition advisorBeanDefinition = createAdvisor(config);
			BeanDefinitionRegistry beanDefinitionRegistry = BeanDefinitionRegistry.class.cast(beanFactory);
			beanDefinitionRegistry.registerBeanDefinition(beanName, advisorBeanDefinition);
		}
	}

	private BeanDefinition createAdvisor(DigestLoggerConfig config) {
		RootBeanDefinition beanDefinition = new RootBeanDefinition(DefaultBeanFactoryPointcutAdvisor.class);
		beanDefinition.getPropertyValues().add("advice", createAdvice(config.getLoggerName()));
		beanDefinition.getPropertyValues().add("pointcut", createPointcut(config.getAspectjExpression()));
		return beanDefinition;
	}

	private BeanDefinition createPointcut(String expression) {
		RootBeanDefinition beanDefinition = new RootBeanDefinition(AspectJExpressionPointcut.class);
		beanDefinition.setScope(BeanDefinition.SCOPE_PROTOTYPE);
		beanDefinition.setSynthetic(true);
		beanDefinition.getPropertyValues().add("expression", expression);
		return beanDefinition;
	}

	private BeanDefinition createAdvice(String loggerName){
		RootBeanDefinition beanDefinition = new RootBeanDefinition(BasicDigestLogInterceptor.class);
		beanDefinition.getConstructorArgumentValues().addGenericArgumentValue(loggerName);
		return beanDefinition;
	}

}

4.3 DigestLoggerConfiguration.java

日志增强的配置类主要是配合下面定义的注解方便框架使用者的使用。

@Configuration
@Role(BeanDefinition.ROLE_INFRASTRUCTURE)
public class DigestLoggerConfiguration {

	@Bean
	@Role(BeanDefinition.ROLE_INFRASTRUCTURE)
	public DigestLogBeanPostProcess digestLogBeanPostProcess() {
		return new DigestLogBeanPostProcess();
	}

}

4.4 EnableDigestLogger.java

借鉴于 Spring 框架的 EnableXXX注解，就是使用者添加该类型注解就具备了某种能力。使用EnableDigestLogger注解就有了打印摘要日志的能力。并且在这个注解上面标注了 @Configuration，使用者要使用该注解的时候也可以不添加 @Configuration 注解。

@Target(ElementType.TYPE)
@Retention(RetentionPolicy.RUNTIME)
@Import(DigestLoggerConfiguration.class)
@Configuration
@Documented
public @interface EnableDigestLogger {
}

5、结果

下面就是框架使用者需要的配置了：

EnableDigestLogger.java

@EnableDigestLogger
public class DigestLogConfig {
	@Bean
	public DigestLoggerConfig serviceDigestLoggerConfig(){
		DigestLoggerConfig digestLoggerConfig = new DigestLoggerConfig();
		digestLoggerConfig.setLoggerName("SERVICE-DIGEST-LOGGER");
		digestLoggerConfig.setAspectjExpression("within(com.ushareit.fintech.query.service.impl.*)");
		return digestLoggerConfig;
	}
}

通过测试能够正常打印摘要日志，并且日志框架使用者只需要关心日志名称以及切面表达式就好了。

carl-zhao 博客专家

发布了184 篇原创文章 · 获赞 231 · 访问量 71万+

他的留言板关注