各种切入点表达式范围意外触发多个通知调用

Question

背景

使用方面记录项目，以便所有方法、类和标有 @Log 注释的构造函数都将信息写入日志文件。

问题

方法似乎被递归调用了一层深度，但代码没有显示任何此类递归关系。

实际

记录的结果：

2018-09-25 12:17:29,155 |↷|   EmailNotificationServiceBean#createPayload([SECURE])
2018-09-25 12:17:29,155 |↷|     EmailNotificationServiceBean#createPayload([{service.notification.smtp.authentication.password=password, mail.smtp.port=25, service.notification.smtp.authentication.username=dev@localhost, mail.mime.allowutf8=true, mail.smtp.auth=false, mail.smtp.starttls.enable=false, mail.smtp.timeout=10000, mail.smtp.host=localhost}])
2018-09-25 12:17:29,193 |↷|       EmailPayloadImpl#<init>([{service.notification.smtp.authentication.password=password, mail.smtp.port=25, service.notification.smtp.authentication.username=dev@localhost, mail.mime.allowutf8=true, mail.smtp.auth=false, mail.smtp.starttls.enable=false, mail.smtp.timeout=10000, mail.smtp.host=localhost}])
2018-09-25 12:17:29,193 |↷|         EmailPayloadImpl#validate([SECURE])
2018-09-25 12:17:29,194 |↷|           EmailPayloadImpl#validate([{service.notification.smtp.authentication.password=password, mail.smtp.port=25, service.notification.smtp.authentication.username=dev@localhost, mail.mime.allowutf8=true, mail.smtp.auth=false, mail.smtp.starttls.enable=false, mail.smtp.timeout=10000, mail.smtp.host=localhost}, SMTP connection and credentials])
2018-09-25 12:17:29,195 |↷|         EmailPayloadImpl#setMailServerSettings([SECURE])
2018-09-25 12:17:29,196 |↷|           EmailPayloadImpl#setMailServerSettings([{service.notification.smtp.authentication.password=password, mail.smtp.port=25, service.notification.smtp.authentication.username=dev@localhost, mail.mime.allowutf8=true, mail.smtp.auth=false, mail.smtp.starttls.enable=false, mail.smtp.timeout=10000, mail.smtp.host=localhost}])

预期

预期的记录结果：

2018-09-25 12:17:29,155 |↷|   EmailNotificationServiceBean#createPayload([SECURE])
2018-09-25 12:17:29,193 |↷|     EmailPayloadImpl#<init>([SECURE])
2018-09-25 12:17:29,193 |↷|       EmailPayloadImpl#validate([SECURE])
2018-09-25 12:17:29,195 |↷|       EmailPayloadImpl#setMailServerSettings([SECURE])

代码

日志方面：

@Aspect
public class LogAspect {
    @Pointcut("execution(public @Log( secure = true ) *.new(..))")
    public void loggedSecureConstructor() { }

    @Pointcut("execution(@Log( secure = true ) * *.*(..))")
    public void loggedSecureMethod() { }

    @Pointcut("execution(public @Log( secure = false ) *.new(..))")
    public void loggedConstructor() { }

    @Pointcut("execution(@Log( secure = false ) * *.*(..))")
    public void loggedMethod() { }

    @Pointcut("execution(* (@Log *) .*(..))")
    public void loggedClass() { }

    @Around("loggedSecureMethod() || loggedSecureConstructor()")
    public Object logSecure(final ProceedingJoinPoint joinPoint) throws Throwable {
        return log(joinPoint, true);
    }

    @Around("loggedMethod() || loggedConstructor() || loggedClass()")
    public Object log(final ProceedingJoinPoint joinPoint) throws Throwable {
        return log(joinPoint, false);
    }

    private Object log(final ProceedingJoinPoint joinPoint, boolean secure) throws Throwable {
        final Signature signature = joinPoint.getSignature();
        final Logger log = getLogger(signature);

        final String className = getSimpleClassName(signature);
        final String memberName = signature.getName();
        final Object[] args = joinPoint.getArgs();
        final CharSequence indent = getIndentation();
        final String params = secure ? "[SECURE]" : Arrays.deepToString(args);

        log.trace("\u21B7| {}{}#{}({})", indent, className, memberName, params);

        try {
            increaseIndent();

            return joinPoint.proceed(args);
        } catch (final Throwable t) {
            final SourceLocation source = joinPoint.getSourceLocation();
            log.warn("\u2717| {}[EXCEPTION {}] {}", indent, source, t.getMessage());
            throw t;
        } finally {
            decreaseIndent();
            log.trace("\u21B6| {}{}#{}", indent, className, memberName);
        }
    }

Log接口定义：

@Retention(RetentionPolicy.RUNTIME)
@Target({ElementType.METHOD, ElementType.TYPE, ElementType.CONSTRUCTOR})
public @interface Log {
    boolean secure() default false;
}

反编译后的服务bean：

@Log
public class EmailNotificationServiceBean
implements EmailNotificationService {

    @Log(secure = true)
    @Override
    public EmailPayload createPayload(Map<String, Object> settings) throws NotificationServiceException {
        Map<String, Object> map = settings;
        JoinPoint joinPoint = Factory.makeJP((JoinPoint.StaticPart)ajc$tjp_2, (Object)this, (Object)this, map);
        Object[] arrobject = new Object[]{this, map, joinPoint};
        return (EmailPayload)LogAspect.aspectOf().logSecure(new EmailNotificationServiceBean$AjcClosure7(arrobject).linkClosureAndJoinPoint(69648));
    }

负载实现：

@Log
public class EmailPayloadImpl extends AbstractPayload implements EmailPayload {

    @Log(secure = true)
    public EmailPayloadImpl(final Map<String, Object> settings)
                    throws NotificationServiceException {
        validate(settings, "SMTP connection and credentials");
        setMailServerSettings(settings);
    }

    @Log(secure = true)
    private void validate(final Map<String, Object> map, final String message)
                    throws NotificationServiceException {
        if (map == null || map.isEmpty()) {
            throwException(message);
        }
    }

    @Log(secure = true)
    private void setMailServerSettings(final Map<String, Object> settings) {
        this.mailServerSettings = settings;
    }

问题

导致的原因：

要忽略的secure = true构造函数注解属性；和
要调用和记录两次 validate 和 setMailServerSettings 方法（一次安全，一次不安全）？

我怀疑这些问题是相关的。

Answer 1

基本上，您的示例有两个问题导致安全注释的重复和 "ignoring"。

首先你在 EmailPayloadImpl 中有一个 @Log class 级别注释和一个名为 loggedClass 的切入点 @Pointcut("execution(* (@Log *) .*(..))") class 方法包括构造函数。因此，这意味着 EmailPayloadImpl 上的任何方法调用都将以不安全的日志结束，因为 secure 属性的默认值是 Log 注释中的 false。

第二个问题是构造函数的切入点不正确，这就是 secure = true 被忽略的原因。在为构造函数创建切入点时，您使用的是不正确的可见性关键字。所以切入点

@Pointcut("execution(public @Log( secure = true ) *.new(..))")
public void loggedSecureConstructor() { }

应该改为

@Pointcut("execution(@Log( secure = true ) *.new(..))")
public void loggedSecureConstructor() { }

唯一的区别是删除了 public 可见性关键字。 loggedConstructor().

也应该这样做

So as you constructor pointcuts were incorrect the @Log annotation on the constructor was ignored as there was no pointcut which should have used it. And the @Log on the class was just applying log for all of the class methods including the constructor.

为了您的示例，您需要修复切入点并删除 class 级别注释。

查看您对示例的修复

让我们修复 LogAspect

中的切入点

@Aspect
public class LogAspect {
@Pointcut("execution(@Log( secure = true ) *.new(..))")
public void loggedSecureConstructor() { }

@Pointcut("execution(@Log( secure = true ) * *.*(..))")
public void loggedSecureMethod() { }

@Pointcut("execution(@Log( secure = false ) *.new(..))")
public void loggedConstructor() { }

@Pointcut("execution(@Log( secure = false ) * *.*(..))")
public void loggedMethod() { }

@Pointcut("execution(* (@Log *) .*(..))")
public void loggedClass() { }

@Around("loggedSecureMethod() || loggedSecureConstructor()")
public Object logSecure(final ProceedingJoinPoint joinPoint) throws Throwable {
    return log(joinPoint, true);
}

@Around("loggedMethod() || loggedConstructor() || loggedClass()")
public Object log(final ProceedingJoinPoint joinPoint) throws Throwable {
    return log(joinPoint, false);
}

private Object log(final ProceedingJoinPoint joinPoint, boolean secure) throws Throwable {
    final Signature signature = joinPoint.getSignature();
    final Logger log = getLogger(signature);

    final String className = getSimpleClassName(signature);
    final String memberName = signature.getName();
    final Object[] args = joinPoint.getArgs();
    final CharSequence indent = getIndentation();
    final String params = secure ? "[SECURE]" : Arrays.deepToString(args);

    log.trace("\u21B7| {}{}#{}({})", indent, className, memberName, params);

    try {
        increaseIndent();

        return joinPoint.proceed(args);
    } catch (final Throwable t) {
        final SourceLocation source = joinPoint.getSourceLocation();
        log.warn("\u2717| {}[EXCEPTION {}] {}", indent, source, t.getMessage());
        throw t;
    } finally {
        decreaseIndent();
        log.trace("\u21B6| {}{}#{}", indent, className, memberName);
    }
}

删除 class 级别 @Log 注释

public class EmailPayloadImpl extends AbstractPayload implements EmailPayload {

@Log(secure = true)
public EmailPayloadImpl(final Map<String, Object> settings)
                throws NotificationServiceException {
    validate(settings, "SMTP connection and credentials");
    setMailServerSettings(settings);
}

@Log(secure = true)
private void validate(final Map<String, Object> map, final String message)
                throws NotificationServiceException {
    if (map == null || map.isEmpty()) {
        throwException(message);
    }
}

@Log(secure = true)
private void setMailServerSettings(final Map<String, Object> settings) {
    this.mailServerSettings = settings;
}

Answer 2

解决方案：

要修复重复问题需要调整 loggedClass() 切入点定义：

@Pointcut("execution(* (@Log *) .*(..)) && !@annotation(Log)")
public void loggedClass() { }

另请在附加信息部分找到link到概念验证。

解释：

与连接点（由 @Pointcut 注释定义）相关的问题，它们的模式相互交叉 - 这就是日志中重复的原因。

在我们的案例中，所有 @Pointcut 的名称都足够描述性，例如：

loggedClass() 涵盖 class 中由 @Log.
loggedSecureMethod()涵盖了@Log(secure = true)注释的所有方法。其他的和这个差不多，就不解释了。

因此，如果 EmailPayloadImpl 被注释为 @Log 并且 EmailPayloadImpl.validate() 被注释为 @Log(secure = true) - 我们将有 2 个活动连接点：一个 secure 和一个 non-secure。这将导致添加 2 个日志条目。

假设我们想在注释中引入优先级，即 方法级注释应该覆盖 class 级注释 - 最简单的方法就是避免交叉连接点模式。

因此我们需要 3 个方法组：

用 @Log(secure = true) 注释的方法 = loggedSecureMethod()
用 @Log 注释的方法 = loggedMethod()

方法没有 @Log 注释，但在 class 中用 @Log 注释，即：

@Pointcut("execution(* (@Log *) .*(..)) && !@annotation(Log)")
public void loggedClass() { }

附加信息：

如果还需要在 class 级别上处理 @Log(secure = true) - 当然需要添加类似于 loggedClass() 的额外连接点。
在 GitHub

Proof of concept >>

各种切入点表达式范围意外触发多个通知调用

Various pointcut expression scopes trigger multiple advice calls unexpectedly

java

aop

annotations

aspectj

pointcut

背景

问题

实际

预期

代码

问题

解决方案：

解释：

附加信息：