为什么 AOP Logging 在我的项目中不起作用

Question

我现在在设置 AOP 日志记录方面浪费了很多时间。 我不知道为什么 AOP 在我的项目中不起作用。 我想我已经完成了所有我能做的设置。 如果你们有解决方案，请告诉我。 谢谢。

• application.java

@EnableAspectJAutoProxy
@SpringBootApplication
@ComponentScan(basePackages = "com.demo.apiservice")
@MapperScan("com.demo.apiservice.mapper")
public class ApiServiceApplication extends SpringBootServletInitializer {

    @Override
    protected SpringApplicationBuilder configure(SpringApplicationBuilder builder) {
      return builder.sources(ApiServiceApplication.class);
    }

    public static void main(String[] args) {
      SpringApplication.run(ApiServiceApplication.class, args);
    }

    @Bean
    public ModelMapper modelMapper() {
       return new CustmizedModelMapper();
    }

    @Bean
    public AopLoggingConfig loggingAspect(){
       return new AopLoggingConfig();
    }
}

• build.gradle

    configurations {
            all {
               exclude group: 'org.springframework.boot', module: 'spring-boot-starter-logging'
            }
    }
  
    dependencies {
            //implementation 'org.springframework.boot:spring-boot-starter-security:2.5.5'
            implementation 'org.springframework.boot:spring-boot-starter-web:2.5.5'
            implementation 'org.springframework.boot:spring-boot-starter-log4j2:2.5.5'
            implementation 'org.springframework.boot:spring-boot-starter-mail:2.5.5'
            implementation 'org.springframework.boot:spring-boot-starter-aop:2.5.5'
        implementation 'org.mybatis.spring.boot:mybatis-spring-boot-starter:2.1.3'
        testImplementation 'org.mybatis.spring.boot:mybatis-spring-boot-starter-test:2.1.3'
            implementation 'org.springframework.boot:spring-boot-starter-data-rest:2.5.5'
        implementation 'org.springframework.boot:spring-boot-starter-thymeleaf'
            implementation 'org.projectlombok:lombok:1.18.8'
            implementation 'org.modelmapper:modelmapper:2.3.8'
            implementation 'org.springframework.boot:spring-boot-starter-data-jpa:2.5.5'
            implementation 'org.springframework.boot:spring-boot-starter-jdbc:2.5.5'
            implementation 'com.h2database:h2:1.4.200'
            implementation 'org.springframework.boot:spring-boot-configuration-processor:2.5.5'
            implementation 'org.springframework.security:spring-security-core:5.4.2'
            implementation 'com.fasterxml.jackson.core:jackson-core:2.12.3'
            implementation 'com.fasterxml.jackson.dataformat:jackson-dataformat-xml:2.12.3'
            implementation 'com.fasterxml.jackson.core:jackson-databind:2.12.3'
            implementation 'org.apache.httpcomponents:httpclient:4.5.13'
            implementation 'com.nimbusds:nimbus-jose-jwt:9.7'
            implementation 'io.springfox:springfox-swagger2:3.0.0'
            implementation 'io.springfox:springfox-swagger-ui:2.9.2'
            implementation 'joda-time:joda-time:2.10.10'
            implementation 'io.jsonwebtoken:jjwt-api:0.11.1'
            implementation 'javax.inject:javax.inject:1'
            implementation 'com.googlecode.json-simple:json-simple:1.1'
            implementation 'de.mkammerer:argon2-jvm:2.7'
            implementation 'org.bouncycastle:bcprov-jdk15on:1.68'
            implementation 'org.apache.maven.plugins:maven-surefire-plugin:2.22.0'
            implementation 'javax.validation:validation-api:2.0.1.Final'
            implementation 'org.postgresql:postgresql:42.1.4'
            implementation 'org.hibernate:hibernate-gradle-plugin:5.6.1.Final'
            implementation 'com.jayway.jsonpath:json-path:2.6.0'
            compileOnly 'org.projectlombok:lombok:1.18.8'
        testCompileOnly 'org.projectlombok:lombok:1.18.8'
            runtimeOnly 'org.springframework.boot:spring-boot-devtools:2.5.5'
        annotationProcessor 'org.projectlombok:lombok:1.18.8'
        testAnnotationProcessor 'org.projectlombok:lombok:1.18.8'
            testImplementation 'org.springframework.boot:spring-boot-starter-test:2.5.5'
            testImplementation 'org.springframework.security:spring-security-test:5.5.2'
    }
  

• AopLoggingComponent.java

    package com.demo.apiservice.config;
  
    import org.aspectj.lang.ProceedingJoinPoint;
    import org.aspectj.lang.annotation.Around;
    import org.aspectj.lang.annotation.Aspect;
    import org.aspectj.lang.annotation.Pointcut;
    import org.slf4j.Logger;
    import org.slf4j.LoggerFactory;
    import org.springframework.stereotype.Component;
  
    @Component
    @Aspect
    public class AopLoggingConfig {
  
        Logger logger =  LoggerFactory.getLogger(AopLoggingConfig.class);
  
        static String name = "";
  
        static String type = "";
  
        /**
            *   AspectJ is applied only to a specific class/method in package.
            */
        @Around("execution(* com.demo.apiservice.customer.*Controller.*(..))")
        public Object logPrint(ProceedingJoinPoint joinPoint) throws Throwable {
            type = joinPoint.getSignature().getDeclaringTypeName();
  
            if (type.indexOf("Controller")  -1) {
                name = "Controller  \t:  ";
            }
            else if (type.indexOf("Service")  -1) {
                name = "ServiceImpl  \t:  ";
            }
            else if (type.indexOf("DAO")  -1) {
                name = "DAO  \t\t:  ";
            }
            logger.debug(name + type + ".@@@@@@@@@@@@@@@@@@@@@@@@@ " + joinPoint.getSignature().getName() + "()");
            return joinPoint.proceed();
        }
    }
  

• controller.java

    package com.demo.apiservice.customer;
  
    import org.springframework.beans.factory.annotation.Autowired;
    import org.springframework.beans.factory.annotation.Value;
    import org.springframework.http.HttpStatus;
    import org.springframework.http.ResponseEntity;
    import org.springframework.web.bind.annotation.GetMapping;
    import org.springframework.web.bind.annotation.PathVariable;
    import org.springframework.web.bind.annotation.PostMapping;
    import org.springframework.web.bind.annotation.PutMapping;
    import org.springframework.web.bind.annotation.RequestBody;
    import org.springframework.web.bind.annotation.RequestHeader;
    import org.springframework.web.bind.annotation.RequestMapping;
    import org.springframework.web.bind.annotation.ResponseBody;
    import org.springframework.web.bind.annotation.RestController;
  
    import com.demo.apiservice.constant.Constants;
    import com.demo.apiservice.customer.service.CustomerService;
    import com.demo.apiservice.customer.service.impl.CustomerServiceImpl;
    import com.demo.apiservice.request.CustomerRequest;
    import com.demo.apiservice.request.LoginRequest;
    import com.demo.apiservice.response.GetCustomerResponse;
    import com.demo.apiservice.response.SuccessResponse;
    import com.demo.apiservice.utils.ResponseHandler;
  
    import io.swagger.annotations.Api;
    import io.swagger.annotations.ApiOperation;
    import io.swagger.annotations.ApiParam;
    import io.swagger.annotations.ApiResponse;
    import io.swagger.annotations.ApiResponses;
    import lombok.extern.slf4j.Slf4j;
  
    import java.util.List;
  
    import javax.validation.Valid;
  
    @Slf4j
    @RestController
    @Api(tags = "Customers APIs")
    @RequestMapping("/apiservice/v1/customers")
    public class CustomerController {
  
            @Autowired
            private CustomerService customerService;
  
            @GetMapping
            @ApiOperation(value = "List of Customers API")
            @ApiResponses(value = {
                      @ApiResponse(code = 400, message = Constants.BAD_REQUEST),
                      @ApiResponse(code = 403, message = Constants.ACCESS_DENIED)})
            public ResponseEntity<Object retrieveAll() {
               log.info("Start of CustomerController::retrieveAll method");
               return customerService.retrieveAll();
            }
    }
  

• application.yml

    logging:
      level:
            org:
             springframework.web: DEBUG
             hibernat: DEBUG
            com:
             atoz_develop:
               mybatissample:
                    repository: TRACE
  
    mybatis:
      mapper-locations: classpath:/mappers/*.xml
      type-aliases-package: com.demo.apiservice.entity
      configuration:
            map-underscore-to-camel-case: 'true'
  
    debug: 'true'
  
    spring:
      datasource:
            driver-class-name: org.postgresql.Driver
            username: postgres
            url: jdbc:postgresql://localhost:5432/postgres
            platform: postgres
            password: postgres
      jpa:
            generate-ddl: 'false'
            properties:
             hibernate:
               dialect: org.hibernate.dialect.PostgreSQL10Dialect
               format_sql: 'true'
            hibernate:
             ddl-auto: update
            show-sql: 'true'
  

• 堆栈跟踪日志

    2021-11-17 16:05:19.992 DEBUG 23300 --- [nio-8080-exec-8] o.s.w.s.DispatcherServlet                      : GET /apiservice/v1/customers, parameters={}        2021-11-17 16:05:19.992 DEBUG 23300 --- [nio-8080-exec-8] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.demo.apiservice.customer.CustomerController#retrieveAll()
    2021-11-17 16:05:19.993  INFO 23300 --- [nio-8080-exec-8] c.l.a.c.CustomerController                        : Start of CustomerController::retrieveAll method
    2021-11-17 16:05:19.993  INFO 23300 --- [nio-8080-exec-8] c.l.a.c.s.i.CustomerServiceImpl               : Inside of the CustomerServiceImpl :: retrieveAll method
    2021-11-17 16:05:19.996  INFO 23300 --- [nio-8080-exec-8] c.l.a.c.s.i.CustomerServiceImpl               : End of the CustomerServiceImpl :: retrieveAll method
    2021-11-17 16:05:19.996 DEBUG 23300 --- [nio-8080-exec-8] o.s.w.s.m.m.a.HttpEntityMethodProcessor  : Using application/xhtml+xml, given [text/html, application/xhtml+xml, image/avif, image/webp, image/apng, application/xml;q=0.9, application/signed-exchange;v=b3;q=0.9, */*;q=0.8] and supported [application/json, application/*+json, application/json, application/*+json, application/xml;charset=UTF-8, text/xml;charset=UTF-8, application/*+xml;charset=UTF-8, application/xml;charset=UTF-8, text/xml;charset=UTF-8, application/*+xml;charset=UTF-8]
    2021-11-17 16:05:19.996 DEBUG 23300 --- [nio-8080-exec-8] o.s.w.s.m.m.a.HttpEntityMethodProcessor  : Writing [{data=[Customer(email=test1@test.com, password=null, customerId=null, storeName=eos, firstname=test1 (truncated)...]
    2021-11-17 16:05:19.998 DEBUG 23300 --- [nio-8080-exec-8] o.s.w.s.DispatcherServlet                      : Completed 200 OK
  

Answer 1

以下应该有效：

package com.demo.apiservice.config;

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

@Component
@Aspect
public class AopLoggingConfig {

    Logger logger =  LoggerFactory.getLogger(AopLoggingConfig.class);

    static String name = "";

    static String type = "";

    @Pointcut("within(@org.springframework.web.bind.annotation.RestController *)")
    public void controllerClassMethods() {}

    @Around("controllerClassMethods()")
    public Object logPrint(ProceedingJoinPoint joinPoint) throws Throwable {
        type = joinPoint.getSignature().getDeclaringTypeName();

        if (type.indexOf("Controller")  -1) {
            name = "Controller  \t:  ";
        }
        else if (type.indexOf("Service")  -1) {
            name = "ServiceImpl  \t:  ";
        }
        else if (type.indexOf("DAO")  -1) {
            name = "DAO  \t\t:  ";
        }
        logger.debug(name + type + ".@@@@@@@@@@@@@@@@@@@@@@@@@ " + joinPoint.getSignature().getName() + "()");
        return joinPoint.proceed();
    }
}

这将匹配带有@RestController注解的所有类中的所有方法。

Answer 2

你的方面被触发了。我添加了一个显式的控制器方法调用以检查：

  public static void main(String[] args) {
    ConfigurableApplicationContext context = SpringApplication.run(ApiServiceApplication.class, args);
    context.getBean(CustomerController.class).retrieveAll();
  }

然后我修正了您代码中的一些错别字，就像我之前评论中提到的那样。

可能您的问题是您根本没有看到日志输出，因为您忘记了应用程序包com.demo.apiservice的日志配置：

logging:
  level:
    org:
      springframework.web: DEBUG
      hibernate: DEBUG
    com:
      atoz_develop:
        mybatissample:
          repository: TRACE
      demo.apiservice: DEBUG

顺便说一句，我还将您的拼写错误 hibernat 更正为 hibernate，但这与手头的问题无关。

然后我在日志中看到了这个：

[  restartedMain] o.s.b.w.e.t.TomcatWebServer              : Tomcat started on port(s): 8080 (http) with context path ''
[  restartedMain] c.d.a.ApiServiceApplication              : Started ApiServiceApplication in 5.101 seconds (JVM running for 6.117)
[  restartedMain] c.d.a.c.AopLoggingConfig                 : Controller     :  com.demo.apiservice.customer.CustomerController.@@@@@@@@@@@@@@@@@@@@@@@@@ retrieveAll()
[  restartedMain] c.d.a.c.AopLoggingConfig                 : Controller     :  com.demo.apiservice.customer.CustomerController.@@@@@@@@@@@@@@@@@@@@@@@@@ retrieveAll()
[  restartedMain] c.d.a.c.CustomerController               : Start of CustomerController::retrieveAll method

你看到问题了吗？您会得到重复的日志记录，因为组件扫描会拾取一次切面，并在应用程序配置中将其作为 bean 再实例化一次。所以你需要从ApiServiceApplication中删除这部分：

  @Bean
  public AopLoggingConfig loggingAspect() {
    return new AopLoggingConfig();
  }

现在重复的日志记录消失了。

接下来，也许您想稍微简化一下您的方面并简单地记录joinPoint 或joinPoint.getSignature()。您还需要创建name 和type 局部变量，因为静态字段不是线程安全的。相反，您可能希望在方面中使用静态记录器。

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

  @Around("execution(* com.demo.apiservice.customer.*Controller.*(..))")
  public Object logPrint(ProceedingJoinPoint joinPoint) throws Throwable {
    String type = joinPoint.getSignature().getDeclaringTypeName();
    String name = "";

    if (type.contains("Controller")) {
      name = "Controller  \t:  ";
    }
    else if (type.contains("Service")) {
      name = "ServiceImpl  \t:  ";
    }
    else if (type.contains("DAO")) {
      name = "DAO  \t\t:  ";
    }

    logger.debug(name + joinPoint.getSignature());
    return joinPoint.proceed();
  }
}

日志行变为：

Controller      :  ResponseEntity com.demo.apiservice.customer.CustomerController.retrieveAll()

但实际上，包名和类名都表明我们正在处理一个控制器、DAO 或服务。那么，为什么首先要打扰if-else 的东西呢？为什么把一件简单的事情搞复杂，把事情搞得更慢？此外，如果你只想记录一些东西而不影响控制流、方法参数或返回值，一个简单的@Before 通知就可以了，不需要昂贵的@Around。

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

  @Before("execution(* com.demo.apiservice.customer.*Controller.*(..))")
  public void logPrint(JoinPoint joinPoint) {
    logger.debug(joinPoint.getSignature().toString());
  }
}

日志行变为：

ResponseEntity com.demo.apiservice.customer.CustomerController.retrieveAll()

这还不够吗？

甚至更简单：

    logger.debug(joinPoint.toString());

日志：

execution(ResponseEntity com.demo.apiservice.customer.CustomerController.retrieveAll())

保持简单！