为什么Aspect和Interface注解时AspectJ日志没有触发？

问题描述 投票：0回答：1

我正在寻找一种方法来记录方法。 所以我开始研究 Spring-AOP 和 AspectJ 的示例。 然而，这些似乎都没有真正起作用，或者至少在它们的片段中缺失了一些部分。

我尝试从 AspectJ 示例运行主方法。我从 Spring Initializr 创建。

@SpringBootApplication
@EnableAspectJAutoProxy
public class Demo1Application {
    public static void main(String[] args) {
        testing_a_run();
        SpringApplication.run(Demo1Application.class, args);
    }
    private static Logger logger = LoggerFactory.getLogger(Demo1Application.class);

    @LogExecutionTime
    static void testing_a_run() {
        logger.info("Handling hello request");
    }
}

或者当 Spring-Boot 运行时

package com.example.demo;

import org.springframework.stereotype.Component;

@Component
public class Service {

    @LogExecutionTime
    public void serve() throws InterruptedException {
        Thread.sleep(2000);
    }
}

随着 AspectJ Aspect-Annotation 

@Aspect
@Component
public class LoggingAspect {
    private Logger logger = LoggerFactory.getLogger(LoggingAspect.class);

    @Around("@annotation(LogExecutionTime)")
    public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
        long startTime = System.currentTimeMillis();
        Object proceed = joinPoint.proceed();
        long endTime = System.currentTimeMillis();
        logger.info(joinPoint.getSignature() + " executed in " + (endTime - startTime) + "ms");
        return proceed;
    }
    @Before("execution(* com.example.demo..*.*(..))")
    public void logBefore(JoinPoint joinPoint) {
        logger.info("Method execution started: {}", joinPoint.getSignature());
    }

    @After("execution(* com.example.demo..*.*(..))")
    public void logAfter(JoinPoint joinPoint) {
        logger.info("Method execution completed: {}", joinPoint.getSignature());
    }
}

以及注释界面

@Retention(RetentionPolicy.RUNTIME)
@Target(ElementType.METHOD)
public @interface LogExecutionTime {
}

从我见过的例子来看，这些似乎都很标准。 这就是为什么我对围绕此的日志记录似乎没有发生感到困惑。 这些注释看起来并不复杂。而且，我已经在 Python 中使用装饰器实现了这种行为。为什么这个伪包装注释没有记录到控制台？

XX:XX:XX.XXX [main] INFO com.example.demo.Demo1Application -- Handling hello request

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v3.2.5)

XXXX-XX-XXTXX:XX:XX.XXX-XX:XX  INFO 9064 --- [demo1] [           main] com.example.demo.Demo1Application        : Starting Demo1Application using Java 17.0.11 with PID 9064 (C:\Users\zmurray\git\demo1\build\classes\java\main started by zmurray in C:\Users\zmurray\git\demo1)
XXXX-XX-XXTXX:XX:XX.XXX-XX:XX  INFO 9064 --- [demo1] [           main] com.example.demo.Demo1Application        : No active profile set, falling back to 1 default profile: "default"
XXXX-XX-XXTXX:XX:XX.XXX-XX:XX  INFO 9064 --- [demo1] [           main] com.example.demo.Demo1Application        : Started Demo1Application in 1.73 seconds (process running for 2.224)
aop aspectj spring-aop spring-annotations aspect
1个回答
1
投票

应用程序的行为正如我所期望的那样。你在期待什么？

  1. 方法 

    testing_a_run()
    是静态的，不是 Spring 管理的 bean/组件类的一部分。当然，它不会被Spring AOP拦截。对于静态方法和非 Spring 管理的目标类，您需要本机 AspectJ。

  2. 您的示例应用程序从未为类 

    Service
    实例化 Spring bean - 可怕的名称，很容易与注释类 
    org.springframework.stereotype.Service
    混淆 - 从应用程序上下文中，并且从不调用其 
    serve()
    方法。根本没有运行的代码也不能被方面拦截。解决这个问题，就可以了。

package de.scrum_master.spring.q78366495;

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

@Retention(RetentionPolicy.RUNTIME)
@Target(ElementType.METHOD)
public @interface LogExecutionTime {}

package de.scrum_master.spring.q78366495;

import org.springframework.stereotype.Component;

@Component
public class Service {
  @LogExecutionTime
  public void serve() throws InterruptedException {
    Thread.sleep(2000);
  }
}

package de.scrum_master.spring.q78366495;

import lombok.extern.slf4j.Slf4j;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.context.ConfigurableApplicationContext;
import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.EnableAspectJAutoProxy;
import org.springframework.http.HttpEntity;
import org.springframework.http.HttpHeaders;
import org.springframework.http.HttpMethod;
import org.springframework.web.client.RestClientException;
import org.springframework.web.client.RestTemplate;

@SpringBootApplication
@Configuration
@Slf4j
public class Demo1Application {
  private static Logger logger = LoggerFactory.getLogger(Demo1Application.class);

  public static void main(String[] args) throws InterruptedException {
    testing_a_run();
    try (ConfigurableApplicationContext appContext = SpringApplication.run(Demo1Application.class, args)) {
      doStuff(appContext);
    }
  }

  private static void doStuff(ConfigurableApplicationContext appContext) throws InterruptedException {
    appContext.getBean(Service.class).serve();
  }

  @LogExecutionTime
  static void testing_a_run() {
    logger.info("Handling hello request");
  }
}

package de.scrum_master.spring.q78366495;

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.After;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;

@Aspect
@Component
public class LoggingAspect {
  private Logger logger = LoggerFactory.getLogger(LoggingAspect.class);

  @Around("@annotation(LogExecutionTime)")
  public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
    long startTime = System.currentTimeMillis();
    Object proceed = joinPoint.proceed();
    long endTime = System.currentTimeMillis();
    logger.info(joinPoint.getSignature() + " executed in " + (endTime - startTime) + "ms");
    return proceed;
  }

  @Before("execution(* de.scrum_master.spring.q78366495..*.*(..))")
  public void logBefore(JoinPoint joinPoint) {
    logger.info("Method execution started: {}", joinPoint.getSignature());
  }

  @After("execution(* de.scrum_master.spring.q78366495..*.*(..))")
  public void logAfter(JoinPoint joinPoint) {
    logger.info("Method execution completed: {}", joinPoint.getSignature());
  }
}

控制台日志：

17:39:58.573 [main] INFO de.scrum_master.spring.q78366495.Demo1Application - Handling hello request

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.6.4)

...
2024-04-22 17:40:04.549  INFO 6020 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2024-04-22 17:40:04.561  INFO 6020 --- [           main] d.s.spring.q78366495.Demo1Application    : Started Demo1Application in 5.808 seconds (JVM running for 6.983)
2024-04-22 17:40:04.570  INFO 6020 --- [           main] d.s.spring.q78366495.LoggingAspect       : Method execution started: void de.scrum_master.spring.q78366495.Service.serve()
2024-04-22 17:40:06.590  INFO 6020 --- [           main] d.s.spring.q78366495.LoggingAspect       : Method execution completed: void de.scrum_master.spring.q78366495.Service.serve()
2024-04-22 17:40:06.590  INFO 6020 --- [           main] d.s.spring.q78366495.LoggingAspect       : void de.scrum_master.spring.q78366495.Service.serve() executed in 2021ms
...
最新问题
© www.soinside.com 2019 - 2024. All rights reserved.