W życiu każdego programisty przychodzi taki moment, kiedy coś zaczyna działać zbyt wolno, zaczyna przycinać się, a ogólna wydajność zostaje ograniczona a Spring Boot Aspekty (Spring AOP) mogą stanowić istotną formę monitorowania wydajności. W takich sytuacjach naturalną reakcją jest zrozumienie problemu i próba jego poprawy. Jednak jak to zrobić skutecznie? Jednym z kluczowych narzędzi do monitorowania wydajności może być pomiar czasu wykonania poszczególnych metod. Często otrzymujemy od użytkowników informacje w stylu "strona działa wolno", ale niestety, nasza aplikacja pobiera wiele zasobów, co komplikuje identyfikację konkretnego problemu. W takich przypadkach trudno jest ustalić, który fragment kodu odpowiada za spowolnienie, szczególnie jeśli błąd nie jest powtarzalny.

Spring Boot Aspekty - Spring AOP (Aspect-Oriented Programming)

Rozważmy poniższy przykład:

Dodajemy zależności

implementation 'org.springframework.boot:spring-boot-starter-aop'

Stworzymy klasę LoggingAspect , w której będziemy definiować dwie metody.

@Aspect: Jest to adnotacja używana w aspektach w Spring AOP (Aspect-Oriented Programming). Aspekt to specjalna klasa, która definiuje rady (porady) - np. przed, po lub wokół - w celu przechwycenia i modyfikacji zachowań innych komponentów aplikacji. Adnotacja @Aspect oznacza, że dana klasa jest aspektem i zawiera punkty przecięcia oraz rady.

@Component: Jest to ogólna adnotacja Spring Framework oznaczająca, że klasa jest komponentem zarządzanym przez kontener Springa. 

@Log4j2: Jest to adnotacja pochodząca z frameworka logowania Log4j 2

@Aspect
@Component
@Log4j2
public class LoggingAspect {

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

    @Around("restControler()")
    public Object logExecutionTimeForAllRestController (ProceedingJoinPoint joinPoint) throws Throwable {
        long start = System.currentTimeMillis();
        Object proceed = joinPoint.proceed();
        long executionTime = System.currentTimeMillis() - start;
        log.info("Method " + joinPoint.getSignature() + " executed in " + executionTime + "ms");
        return proceed;
    }

}

Ten fragment kodu jest przykładem wykorzystania aspektów w Spring Boot do monitorowania wydajności metod oznaczonych adnotacją @RestController 

Co się dzieje w tym kodzie Ascpectu:

@Pointcut

To jest definicja punktu przecięcia (ang. pointcut) o nazwie restControler(). Punkty przecięcia określają, które metody lub klasy zostaną objęte aspektem. W tym przypadku punkt przecięcia jest zdefiniowany jako wszystkie metody oznaczone adnotacją @RestController.

@Around("restControler()") 

 To jest adnotacja @Around, która wskazuje, że metoda logExecutionTimeForAllRestController ma działać jako aspekt wokół metod, które pasują do punktu przecięcia restControler().

logExecutionTimeForAllRestController

Jest to deklaracja metody logExecutionTimeForAllRestController. Metoda ta zostanie wykonana jako aspekt wokół wywołań metod oznaczonych adnotacją @RestController. Przyjmuje ona jako argument obiekt ProceedingJoinPoint, który reprezentuje punkt przecięcia (czyli wywołanie metody), który został przechwycony. Może również rzucać wyjątki (throws Throwable).

long start = System.currentTimeMillis();

Ta linia kodu zapisuje aktualny czas w zmiennej start w milisekundach. Będzie to punkt początkowy pomiaru czasu wykonania metody.

Object proceed = joinPoint.proceed(); 

ta linia kodu wywołuje metodę, która została przechwycona, korzystając z joinPoint.proceed(). Metoda proceed wykonuje właściwą metodę, która została wywołana, a wynik jest zapisywany w zmiennej proceed.

long executionTime = System.currentTimeMillis() - start; 

Po zakończeniu wywołania metody obliczany jest czas wykonania, odejmując czas początkowy (start) od bieżącego czasu. Wynik jest zapisywany w zmiennej executionTime.

log.info("Method " + joinPoint.getSignature() + " executed in " + executionTime + "ms"); 

Ta linia kodu służy do zapisania informacji o czasie wykonania przechwyconej metody w logach. Wykorzystuje ona obiekt log, który prawdopodobnie jest instancją loggera, wyświetlającą informacje na konsoli lub zapisującą je do pliku. Informacja zawiera sygnaturę metody (joinPoint.getSignature()), czas wykonania oraz jednostkę (milisekundy).

return proceed;

Na koniec metoda zwraca wynik wykonania przechwyconej metody za pomocą zmiennej proceed. W ten sposób aspekt nie wpływa na wynik metody, tylko monitoruje jej wydajność i loguje czas jej wykonania.

Przykład wywołania:

2023-11-01 12:55:26,691 INFO  [http-nio-8410-exec-15] [pl.devset]: CityStatisticsDto pl.devset.CityStatisticsController.getAccumulatedStatistics(LocalDate,LocalDate,String,String,String,String,String) executed in 329ms

Customowe logowanie przy użyciu Spring Aspect

Powiedzmy, że chcemy logować tylko te metody, które zostaną oznaczone naszą adnotacją:

Stworzymy teraz nasz interfejs LogExecution:

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

Ten interfejs definiuje LogExecution, który jest naszą własną adnotacją. Jest to adnotacja oznaczona adnotacją @interface i jest definiowana zgodnie z Java Annotation API. Adnotacja ta ma dwie elementy:

@Target(ElementType.METHOD): Oznacza, że adnotację można używać tylko na poziomie metod.
@Retention(RetentionPolicy.RUNTIME): Oznacza, że adnotacja będzie dostępna w trakcie działania programu (runtime), co pozwala na przechwytywanie jej w aspekcie.

Kolejnym etapem będzie stworszenie meotdy logExecutionTime w naszej klasie LoggingAspect

@Around("@annotation(pl.devset.LogExecution)")
public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
    long start = System.currentTimeMillis();
    Object proceed = joinPoint.proceed();
    long executionTime = System.currentTimeMillis() - start;
    log.info("Method " + joinPoint.getSignature() + " executed in " + executionTime + "ms");    return proceed;
}

Adnotacja @Around wskazuje, że metoda logExecutionTime będzie działać jako aspekt wokół metod oznaczonych adnotacją @LogExecution.

Nie bede rozpisywał ciała metody poniewaz jest ona taka sama jak w metodzie logExecutionTimeForAllRestController.

Przykład zastosowania:

    @LogExecution
    public Optional<City> findByName(String name) {
        return cityRepository
                .findByName(name)
                .map(MAPPER_INSTANCE::mapToDomain);
    }

Podsumowanie

W życiu każdego programisty istnieje potrzeba monitorowania i optymalizacji wydajności aplikacji. Spring Boot Aspekty (Spring AOP) są przydatnym narzędziem do tego celu. Przy użyciu adnotacji własnej @LogExecution można precyzyjnie monitorować czas wykonania tylko tych metod, które go wymagają. To pozwala na skupienie uwagi na konkretnych fragmentach kodu i identyfikację potencjalnych źródeł problemów. Dzięki temu można efektywnie poprawić wydajność aplikacji i zwiększyć satysfakcję użytkowników.