Статьи

Использование Spring AOP для отслеживания вызова

Октябрь 22, 2017

Как часто ты пишешь что-то подобное?

public void foo(){
   logger.debug("entering foo");
   ....
   logger.debug("leaving foo");
}

Если ваш ответ «достаточно часто», то вам следует рассмотреть следующую информацию. Любой, кто использует Spring Framework DebugInterceptor (или любой другой перехватчик по вашему выбору), может легко интегрировать ведение журнала трассировки в свое приложение, лишь с небольшими изменениями в своих контекстных контекстах Spring. В этом посте я опишу, как отследить ваш код с помощью Spring AOP

Идея, лежащая в основе предлагаемого решения, заключается в том, чтобы обернуть bean-компонент, вызовы которого вы собираетесь отследить, с прокси-сервером, имеющим SimpleTraceInterceptor или DebugInterceptor в свойстве interceptorNames . Упомянутые перехватчики являются реализациями общего совета, который запишет все детали вызовов в некоторый регистратор (способ выбора нашего регистратора обсуждается позже). Эти перехватчики предоставляются основной библиотекой Spring вместе с CustomizableTraceInterceptor , PerformanceMonitorInterceptor и некоторыми другими . Я думаю, пример — лучший способ показать, как это работает.

Рассмотрим эту простую программу: два bean-компонента, один контекстный контекст Spring и один класс точки входа, который просто вызывает метод первого bean-компонента (поэтому он опущен на этой странице).

Bean1 :

package com.blogspot.mikler.java;

import org.apache.log4j.Logger;

public class Bean1 {

    Logger logger = Logger.getLogger(Bean1.class);

    Bean2 bean2;

    public void entryPoint(){
        bean2.importantMethod();
        bean2.doSomethingQuick("a job");
        logger.info("All jobs done");
    }

    public void setBean2(Bean2 bean2) {
        this.bean2 = bean2;
    }

}

 Bean2:

package com.blogspot.mikler.java;

import org.apache.log4j.Logger;

import java.text.MessageFormat;

public class Bean2 {
    Logger logger = Logger.getLogger(Bean2.class);

    public void importantMethod(){
        logger.info("Doing job for 3 seconds");
        try {
            Thread.sleep(3000);
        } catch (InterruptedException e) {
            throw new RuntimeException(e);
        }
    }

    public void doSomethingQuick(String param1) {
        logger.info(MessageFormat.format("doing something quick with param = {0}",param1));
    }
}

Весенний контекст:

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xmlns:aop="http://www.springframework.org/schema/aop"
       xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans.xsd">

    <bean id="simpleTraceInterceptor" class="org.springframework.aop.interceptor.SimpleTraceInterceptor">
        <property name="useDynamicLogger" value="true"/>
    </bean>
    <bean id="debugInterceptor" class="org.springframework.aop.interceptor.DebugInterceptor">
        <property name="useDynamicLogger" value="true"/>
    </bean>

    <bean id="bean1" class="org.springframework.aop.framework.ProxyFactoryBean">
        <property name="target">
            <bean class="com.blogspot.mikler.java.Bean1">
                <property name="bean2" ref="bean2"/>
            </bean>
        </property>
        <property name="interceptorNames" value="simpleTraceInterceptor"/>
    </bean>

    <bean id="bean2" class="org.springframework.aop.framework.ProxyFactoryBean">
        <property name="target">
            <bean class="com.blogspot.mikler.java.Bean2"/>
        </property>
        <property name="interceptorNames" value="simpleTraceInterceptor"/>
    </bean>

</beans>

Запустив этот код, мы получим следующий вывод:

23:13:04,348 TRACE [com.blogspot.mikler.java.Bean1] - Entering method 'entryPoint' of class [com.blogspot.mikler.java.Bean1]
23:13:04,349 TRACE [com.blogspot.mikler.java.Bean2] - Entering method 'importantMethod' of class [com.blogspot.mikler.java.Bean2]
23:13:04,349 INFO [com.blogspot.mikler.java.Bean2] - Doing job for 3 seconds
23:13:07,349 TRACE [com.blogspot.mikler.java.Bean2] - Exiting method 'importantMethod' of class [com.blogspot.mikler.java.Bean2]
23:13:07,350 TRACE [com.blogspot.mikler.java.Bean2] - Entering method 'doSomethingQuick' of class [com.blogspot.mikler.java.Bean2]
23:13:07,351 INFO [com.blogspot.mikler.java.Bean2] - doing something quick with param = a job
23:13:07,351 TRACE [com.blogspot.mikler.java.Bean2] - Exiting method 'doSomethingQuick' of class [com.blogspot.mikler.java.Bean2]
23:13:07,351 INFO [com.blogspot.mikler.java.Bean1] - All jobs done
23:13:07,351 TRACE [com.blogspot.mikler.java.Bean1] - Exiting method 'entryPoint' of class [com.blogspot.mikler.java.Bean1]

Я надеюсь, что исходный код рассказывает историю.

Несколько моментов, которые следует подчеркнуть:

  • Нужно решить использовать Dynamic Logger или нет (см. Использование свойства DynamicLogger в DebugInterceptor). Если используется динамический регистратор, то сообщения журнала вызовов будут записываться в регистратор соответствующего класса компонента (log4j.logger.com.blogspot.mikler.java. * Регистраторы в нашем случае). В противном случае будет использоваться логгер соответствующего Interceptor, по одному для всех bean-компонентов.
  • Убедитесь, что вы включили уровень трассировки для выбранного регистратора. Потому что в целях оптимизации перехватчики не выполняют никакой работы, экономя ваше рабочее время, если этот уровень регистрации для регистратора, который они ищут, не включен.

 Инструкции о том, как проверить исходный код этой статьи, вы можете найти в оригинальном посте .

Первоначально опубликовано на miklerjava.blogspot.com

35
Share: