Рубрики
Без рубрики

Ведение журнала производительности пружины

Краткое и практическое руководство по мониторингу производительности с помощью Spring AOP

Автор оригинала: Loredana Crusoveanu.

1. Обзор

В этом уроке мы рассмотрим несколько основных опций, которые предлагает Spring Framework для мониторинга производительности.

2. PerformanceMonitorInterceptor

Простое решение для получения базовой функциональности мониторинга времени выполнения наших методов мы можем использовать класс PerformanceMonitorInterceptor из Spring AOP (Аспектно-ориентированное программирование).

Spring AOP позволяет определять сквозные проблемы в приложениях, то есть код, который перехватывает выполнение одного или нескольких методов, чтобы добавить дополнительную функциональность.

Класс PerformanceMonitorInterceptor является перехватчиком, который может быть связан с любым пользовательским методом, выполняемым одновременно. Этот класс использует экземпляр секундомера для определения времени начала и окончания выполнения метода.

Давайте создадим простой Person класс и Person Service класс с двумя методами, которые мы будем отслеживать:

public class Person {
    private String lastName;
    private String firstName;
    private LocalDate dateOfBirth;

    // standard constructors, getters, setters
}
public class PersonService {
    
    public String getFullName(Person person){
        return person.getLastName()+" "+person.getFirstName();
    }
    
    public int getAge(Person person){
        Period p = Period.between(person.getDateOfBirth(), LocalDate.now());
        return p.getYears();
    }
}

Для того, чтобы использовать перехватчик Spring monitoring, нам нужно определить точечный разрез и советник:

@Configuration
@EnableAspectJAutoProxy
@Aspect
public class AopConfiguration {
    
    @Pointcut(
      "execution(public String com.baeldung.performancemonitor.PersonService.getFullName(..))"
    )
    public void monitor() { }
    
    @Bean
    public PerformanceMonitorInterceptor performanceMonitorInterceptor() {
        return new PerformanceMonitorInterceptor(true);
    }

    @Bean
    public Advisor performanceMonitorAdvisor() {
        AspectJExpressionPointcut pointcut = new AspectJExpressionPointcut();
        pointcut.setExpression("com.baeldung.performancemonitor.AopConfiguration.monitor()");
        return new DefaultPointcutAdvisor(pointcut, performanceMonitorInterceptor());
    }
    
    @Bean
    public Person person(){
        return new Person("John","Smith", LocalDate.of(1980, Month.JANUARY, 12));
    }
 
    @Bean
    public PersonService personService(){
        return new PersonService();
    }
}

Pointcut содержит выражение, которое идентифицирует методы, которые мы хотим перехватить — в нашем случае метод getFullName() класса PersonService .

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

Наконец, аннотация @EnableAspectJAutoProxy включает поддержку AspectJ для наших бобов. Проще говоря, AspectJ-это библиотека, созданная для облегчения использования Spring AOP с помощью удобных аннотаций, таких как @Pointcut .

После создания конфигурации нам нужно установить уровень журнала класса перехватчика на TRACE , так как это уровень , на котором он регистрирует сообщения.

Например, используя Jog4j, мы можем добиться этого с помощью файла log4j.properties :

log4j.logger.org.springframework.aop.interceptor.PerformanceMonitorInterceptor=TRACE, stdout

Для каждого выполнения метода getAge() мы увидим сообщение TRACE в журнале консоли:

2017-01-08 19:19:25 TRACE 
  PersonService:66 - StopWatch 
  'com.baeldung.performancemonitor.PersonService.getFullName': 
  running time (millis) = 10

3. Пользовательский Перехватчик Мониторинга Производительности

Если мы хотим больше контроля над тем, как выполняется мониторинг производительности , мы можем реализовать наш собственный пользовательский перехватчик.

Для этого давайте расширим класс AbstractMonitoringInterceptor и переопределим метод invokeUnderTrace () , чтобы регистрировать начало, конец и продолжительность метода, а также предупреждение, если выполнение метода длится более 10 мс:

public class MyPerformanceMonitorInterceptor extends AbstractMonitoringInterceptor {
    
    public MyPerformanceMonitorInterceptor() {
    }

    public MyPerformanceMonitorInterceptor(boolean useDynamicLogger) {
            setUseDynamicLogger(useDynamicLogger);
    }

    @Override
    protected Object invokeUnderTrace(MethodInvocation invocation, Log log) 
      throws Throwable {
        String name = createInvocationTraceName(invocation);
        long start = System.currentTimeMillis();
        log.info("Method " + name + " execution started at:" + new Date());
        try {
            return invocation.proceed();
        }
        finally {
            long end = System.currentTimeMillis();
            long time = end - start;
            log.info("Method "+name+" execution lasted:"+time+" ms");
            log.info("Method "+name+" execution ended at:"+new Date());
            
            if (time > 10){
                log.warn("Method execution longer than 10 ms!");
            }            
        }
    }
}

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

Давайте определим точечный разрез для getAge() метода Personal Service и свяжем его с созданным нами перехватчиком:

@Pointcut("execution(public int com.baeldung.performancemonitor.PersonService.getAge(..))")
public void myMonitor() { }
    
@Bean
public MyPerformanceMonitorInterceptor myPerformanceMonitorInterceptor() {
    return new MyPerformanceMonitorInterceptor(true);
}
    
@Bean
public Advisor myPerformanceMonitorAdvisor() {
    AspectJExpressionPointcut pointcut = new AspectJExpressionPointcut();
    pointcut.setExpression("com.baeldung.performancemonitor.AopConfiguration.myMonitor()");
    return new DefaultPointcutAdvisor(pointcut, myPerformanceMonitorInterceptor());
}

Давайте установим уровень журнала на INFO для пользовательского перехватчика:

log4j.logger.com.baeldung.performancemonitor.MyPerformanceMonitorInterceptor=INFO, stdout

Выполнение метода g etAge() привело к следующему результату:

2017-01-08 19:19:25 INFO PersonService:26 - 
  Method com.baeldung.performancemonitor.PersonService.getAge 
  execution started at:Sun Jan 08 19:19:25 EET 2017
2017-01-08 19:19:25 INFO PersonService:33 - 
  Method com.baeldung.performancemonitor.PersonService.getAge execution lasted:50 ms
2017-01-08 19:19:25 INFO PersonService:34 - 
  Method com.baeldung.performancemonitor.PersonService.getAge 
  execution ended at:Sun Jan 08 19:19:25 EET 2017
2017-01-08 19:19:25 WARN PersonService:37 - 
  Method execution longer than 10 ms!

4. Заключение

В этом кратком руководстве мы представили простой мониторинг производительности весной.

Как всегда, полный исходный код этой статьи можно найти на Github .