Введение в AOP в Spring Boot

В этой статье мы с помощью Spring AOP сделаем три вещи:

• Будем логировать вызовы определенного метода
• Будем логировать возвращаемое значение определенного метода при каждом вызове.
• Будем замерять и логировать время выполнения определенного аннотированного метода при каждом вызове. (Для этого метода создадим обычную Java-аннотацию, чтобы пометить метод с помощью нее).
  

Maven-dependency

Чтобы создавать аспекты, в проект Spring Boot необходимо добавить зависимость:

<dependency>
	<groupId>org.springframework.boot</groupId>
	<artifactId>spring-boot-starter-aop</artifactId>
</dependency>

Задача

Итак, допустим, у нас есть некоторый сервис:

package ru.sysout.aspectsdemo.service;

import org.springframework.stereotype.Service;

@Service
public class SomeService { 
    @LogExecutionTime
    public void someMethod() throws InterruptedException {
        Thread.sleep(1000);
    }
}

При каждом вызове метода someMethod() нам надо измерить время его выполнения. В консоль должна выводиться информация о времени.

И допустим, есть еще метод composeFullName() в компоненте:

@Component
public class FullNameComposer {

    
    public String composeFullName(String firstName, String lastName) {

        return firstName + lastName;
    }
}

Аналогично, при каждом вызове composeFullName() мы должны выводить в консоль имя метода и возвращаемое им значение.

Дополнительные условия

Обратите внимание, что методы someMethod() и composeFullName() находятся в бинах, иначе AOP не сработает. Если у нас не бины, то надо использовать библиотеку AspectJ.

Также мы пометили метод  someMethod() обычной Java-аннотацией @LogExecutionTime. Для всех методов, помеченных этой аннотацией, мы и будем логгировать время выполнения. Выглядит аннотация так:

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

}

Решить задачу можно и без аннотации, но поскольку аннотация —  это удобный способ пометить метод(ы), покажем, как работать в том  числе с ней.

Суть

С помощью выражений мы задаем те методы, для которых будет выполняться определенное действие (будь то логирование метода или измерение скорости его выполнения). Это действие называется Advice.

Выражение, с помощью которого мы выбираем интересные нам методы, а точнее, сама выборка методов — это Pointcut.

JoinPoint — это точка выполнения программы — а именно, вызов конкретного метода в конкретный момент времени, когда AOP вмешивается и выполняет наш Advice.

Вся вышеперечисленная логика собарается в коде программы в Aspect.

Aspect

Итак, начнем реализовывать логику. Для этого создадим класс LoggingAspect и пометим его аннотацией @Aspect:

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

    // Здесь будут advices и pointcuts
}

Обратите внимание, что класс должен быть Spring-бином.

PointСut

Теперь создадим условие выборки этих наших методов, для которых мы решаем нашу задачу. Тут вариантов задать условие куча, покажем несколько:

Вот так выбираются все методы класса FullNameComposer (в нашем случае там будет только один метод):

@Pointcut("within(ru.sysout.aspectsdemo.service.FullNameComposer)")
public void stringProcessingMethods() {
};

Мы создали PointCut с именем stringProcessingMethods(). Это имя мы будем использовать далее в Advice.

На самом деле необязательно выражение для выборки задавать отдельно в PointCut, можно сразу в Advice, ниже мы покажем это.

А пока что еще одно выражение для выборки этого метода:

"execution(public String ru.sysout.aspectsdemo.service.FullNameComposer.*(..))"

Здесь звездочка означает выбрать все методы класса, а точки означают, что количество и тип аргументов не важны. Звездочку можно было и вместо возвращаемого типа вставить, это значило бы, что тип не важен.

А вот еще одно выражение, на этот раз, для выборки метода someMethod():

"@annotation("@annotation(LogExecutionTime)")"

Здесь мы выбираем все методы, помеченные аннотацией @LogExecutionTime.

Advice

Наконец, перейдем к главному — зададим действия, которые выполняются при каждом вызове интересных нам методов.

Есть несколько типов advice:

• действие до вызова метода @Before
• действие после вызова метода @After (выполняется независимо от того, нормально ли завершился метод или было выброшено исключение)
• действие после вызова метода @AfterReturing (выполняется при нориальном завершении метода)
• действие после вызова метода @AfterThrowing (выполняется, если  было выброшено исключение)
• действие и до, и после @Around

Первый advice логирует вызовы composeFullName() всегда:

@After("stringProcessingMethods()")
public void logMethodCall(JoinPoint jp) {
    String methodName = jp.getSignature()
        .getName();

    logger.log(Level.INFO, "название метода: " + methodName);
}

Как видите, в аргументе JoinPoint есть полезная иформация о методе.

Создадим второй advice, который логирует возвращаемое значение в случае нормального завершения метода. У нас он всегда завершается нормально, но тем не менее:

@AfterReturning(pointcut = "execution(public String ru.sysout.aspectsdemo.service.FullNameComposer.*(..))", returning = "result")
public void logAfterReturning(JoinPoint joinPoint, Object result) {

    logger.log(Level.INFO, "возвращенное значение: " + result.toString());
}

Второй аргумент result и есть возращаемое значение.

Заметьте, что pointcut мы задали прямо в advice. Как было сказано выше, так можно делать.

Наконец, последний advice вычисляет время выполнения метода:

@Around("@annotation(LogExecutionTime)")
public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
    long start = System.currentTimeMillis();

    Object proceed = joinPoint.proceed();

    long executionTime = System.currentTimeMillis() - start;

    logger.log(Level.INFO, joinPoint.getSignature() + " выполнен за " + executionTime + "мс");
    return proceed;
}

Проверка результата

Давайте сделаем вызовы методов и запустим приложение:

@SpringBootApplication
public class AspectsDemoApplication implements CommandLineRunner {
    @Autowired
    FullNameComposer composer;
    @Autowired
    SomeService service;
    public static void main(String[] args) {
        SpringApplication.run(AspectsDemoApplication.class, args);

    }

    @Override
    public void run(String... args) throws Exception {
        composer.composeFullName("Ivan", "Petrov");
        service.someMethod();
    }
}

В результате в консоли имеем:

main] ru.sysout.aspectsdemo.LoggingAspect      : название метода: composeFullName
main] ru.sysout.aspectsdemo.LoggingAspect      : возвращенное значение: IvanPetrov
main] ru.sysout.aspectsdemo.LoggingAspect      : void ru.sysout.aspectsdemo.service.SomeService.someMethod() выполнен за 1027мс

Код примера есть на GitHub.