Spring AOP和AspectJ加载时编织：将为私有方法调用两次Around建议

Question

我将使用Spring AOP和AspectJ加载时编织来度量代码中特定的私有/受保护/公共方法的执行时间。

为此，我编写了以下注解，其中一个注解将对应该测量执行时间的方法进行注解：

package at.scan.spring.aop.measuring;

import org.aspectj.lang.ProceedingJoinPoint;

import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;

/**
 * Annotation for pointcut associated with the advice {@link MeasuringAspect#aroundAdvice(ProceedingJoinPoint)}.
 * @author ilyesve
 * @since 02.12.2015
 */
@Target(value = ElementType.METHOD)
@Retention(value = RetentionPolicy.RUNTIME)
public @interface Measured {

}

我还写了以下几个方面：

package at.scan.spring.aop.measuring;

import org.apache.commons.lang3.builder.ReflectionToStringBuilder;
import org.apache.commons.lang3.builder.ToStringStyle;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

/**
 * An aspect which contains an advice to measure execution of methods that are annotated with {@link Measured} if it
 * is enabled.
 * After the execution of the annotated method the captured data over its execution will be forwarded to the
 * configured {@link MeasuringReporter}.
 * @author ilyesve
 * @since 02.12.2015
 */
@Aspect
public class MeasuringAspect {

    /** LOGGER. */
    private static final Logger LOGGER = LoggerFactory.getLogger(MeasuringAspect.class.getPackage().getName());

    /** Determines whether the Around advice is enabled. Default is disabled. */
    private boolean enabled = false;

    /** The {@link MeasuringReporter} to report the captured measuring data. */
    private MeasuringReporter reporter;

    /**
     * The Around advice which will be executed on calling of methods annotated with {@link Measured}.
     * @param pjp the join point
     * @throws Throwable on failure
     * @return result of proceeding of the join point
     */
    @Around("@annotation(Measured)")
    public Object aroundAdvice(ProceedingJoinPoint pjp) throws Throwable {
        Object result = null;

        if (enabled && reporter != null) {
            LOGGER.debug("Starting measuring of method '{}.{}()'...",
                    pjp.getSignature().getDeclaringTypeName(),
                    pjp.getSignature().getName());

            MeasuringDataDto measuringData = new MeasuringDataDto(pjp.getSignature(), pjp.getArgs());

            measuringData.setStartTs(System.currentTimeMillis());
            try {
                measuringData.setResult(pjp.proceed());
            } catch (Throwable t) {
                measuringData.setThrowable(t);
            }
            measuringData.setEndTs(System.currentTimeMillis());

            try {
                reporter.report(measuringData);
            } catch (Throwable t) {
                LOGGER.error("Unable to report captured measuring data because of an error. MeasuringData [{}]",
                        ReflectionToStringBuilder.toString(measuringData, ToStringStyle.DEFAULT_STYLE, true, true),
                        t);
            }

            if (measuringData.getThrowable() != null) {
                throw measuringData.getThrowable();
            }

            result = measuringData.getResult();
        } else {
            result = pjp.proceed();
        }

        return result;
    }

    /**
     * @param theEnabled if {@code true} the contained advice will be enabled, otherwise disabled
     */
    public final void setEnabled(final boolean theEnabled) {
        enabled = theEnabled;
        if (enabled && reporter != null) {
            LOGGER.info("Methods will be measured. Reporter [{}]", reporter.getClass().getCanonicalName());
        }
    }

    /**
     * @param theReporter the {@link MeasuringReporter} to be used to report the captured measuring data about
     *                    execution of an method annotated with {@link Measured}
     */
    public final void setReporter(final MeasuringReporter theReporter) {
        reporter = theReporter;
        if (enabled && reporter != null) {
            LOGGER.info("Methods will be measured. Reporter [{}]", reporter.getClass().getCanonicalName());
        }
    }
}

我的Spring配置如下：

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xmlns:context="http://www.springframework.org/schema/context"
       xmlns:aop="http://www.springframework.org/schema/aop"
       xsi:schemaLocation="http://www.springframework.org/schema/beans
       http://www.springframework.org/schema/beans/spring-beans.xsd
       http://www.springframework.org/schema/context
       http://www.springframework.org/schema/context/spring-context.xsd
       http://www.springframework.org/schema/aop
       http://www.springframework.org/schema/aop/spring-aop.xsd"
       default-autowire="byName">

    <context:load-time-weaver aspectj-weaving="autodetect" />

    <bean id="measuringAspect" class="at.scan.spring.aop.measuring.MeasuringAspect"
          factory-method="aspectOf">
        <property name="enabled" value="${measuring.enabled}" />
        <property name="reporter" ref="measuringReporterService" />
    </bean>
</beans>

我还在项目的src/main/resources/meta-inf目录中放置了以下aop.xml:

<!DOCTYPE aspectj PUBLIC "-//AspectJ//DTD//EN" "http://www.eclipse.org/aspectj/dtd/aspectj.dtd">
<aspectj>
    <weaver>
        <include within="at.scan..*" />
    </weaver>
    <aspects>
        <aspect name="at.scan.spring.aop.measuring.MeasuringAspect" />
    </aspects>
</aspectj>

此外，我还向POM添加了以下Spring AOP和/或AspectJ特定的依赖项：

null

对于带注释的public和protected方法，一切工作都很好，但是对于带注释的private方法，我方面的around建议将被调用两次，我不知道为什么。

Answer 1

您的切入点表达式匹配连接点的主题具有@measure注释的所有连接点。这包括方法执行和方法调用类型的连接点。您可能会看到在私有方法上执行两次建议，这仅仅是因为您的私有方法是从建议类本地调用的。如果您有从advised code到@measure其他可见性的注释方法的方法调用，您将看到这些方法上的双重Advision执行，而不仅仅是私有方法。解决方案是更改切入点表达式，将联接点限制为method-execution或method-call。在您的例子中,我猜测是方法执行本身,因此您的切入点表达式将变成这样：

@Around("execution(@Measured * *(..))")

由于您没有在建议中的任何地方绑定注释，因此甚至不需要@annotation(measure)部分。

在项目中设置新方面时，最好在aop.xml中启用-showweaveinfo和-verbose来检查编织过程。

<weaver options="-showWeaveInfo -verbose">
...
</weaver>

这将在标准错误上公开类似于以下内容的日志消息（也请注意行号）：

[AppClassLoader@62b103dd] weaveinfo Join point 'method-call(void at.scan.spring.aop.measuring.MeasuredClass.test3())' in Type 'at.scan.spring.aop.measuring.MeasuredClass' (MeasuredClass.java:18) advised by around advice from 'at.scan.spring.aop.measuring.MeasuringAspect' (MeasuringAspect.java)
[AppClassLoader@62b103dd] weaveinfo Join point 'method-execution(void at.scan.spring.aop.measuring.MeasuredClass.test3())' in Type 'at.scan.spring.aop.measuring.MeasuredClass' (MeasuredClass.java:27) advised by around advice from 'at.scan.spring.aop.measuring.MeasuringAspect' (MeasuringAspect.java)