読者です 読者をやめる 読者になる 読者になる

Spring BootでSpring AOPのAdviceを試す

Spring AOPでAdvice試してみたメモです。

今さらながらSpring BootでSpringAOPのAdviceを試してみました。

maven

pom.xmlにはspring-boot-starter-aopを追加しました。

pom.xml

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

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
        </dependency>
    </dependencies>

Advice

Adviceはjoin pointで実行する処理です。
join pointはAdviceを割り込みさせるタイミングで、springだとメソッド実行時がjoin pointになります。
springでは下記Adviceが用意されています。

Advice 実行タイミング
Before join pointの前に実行
After join point後に実行
AfterReturning join pointの正常終了後に実行
AfterThrowing join pointで例外発生時に実行
Around join pointの前後に実行

Aspectの実行対象クラス

下記のServiceクラスを用意。
それぞれのメソッドが呼ばれる毎にAdviceが実行されるように、Aspectを実装します。

SampleService.java

@Service
public class SampleService {
    public int getRandomValue(int seed) {
        Random random = new Random(seed);
        return random.nextInt();
    }

    public int getLength(String str) {
        return str.length();
    }
}

Aspect

Aspectの実装クラスです。
それぞれのAdviceでログを標準出力に出力してみます。

MethodCallLoggingAspect.java

@Aspect
@Component
public class MethodCallLoggingAspect {
    @Before("execution(* *..*Service.*(..))")
    public void beforeLog(JoinPoint jp) {
        System.out.println("[Before]====================================");
        System.out.println("[Before]args:" + Arrays.toString(jp.getArgs()));
        System.out.println("[Before]signature:" + jp.getSignature());
    }

    @AfterReturning(value = "execution(* *..*Service.*(..))", returning = "randomValue")
    public void afterReturningLog(JoinPoint jp, int randomValue) {
        System.out.println("[AfterReturn]====================================");
        System.out.println("[AfterReturn]args:" + Arrays.toString(jp.getArgs()));
        System.out.println("[AfterReturn]signature:" + jp.getSignature());
        System.out.println("[AfterReturn]return:" + randomValue);
    }

    @AfterThrowing(value = "execution(* *..*Service.*(..))", throwing = "e")
    public void afterThrowingLog(JoinPoint jp, NullPointerException e) {
        System.out.println("[AfterThrowing]====================================");
        System.out.println("[AfterThrowing]args:" + Arrays.toString(jp.getArgs()));
        System.out.println("[AfterThrowing]signature:" + jp.getSignature());
    }

    @After("execution(* *..*Service.*(..))")
    public void afterLog(JoinPoint jp) {
        System.out.println("[After]====================================");
        System.out.println("[After]args:" + Arrays.toString(jp.getArgs()));
        System.out.println("[After]signature:" + jp.getSignature());
    }

    @Around("execution(* *..*Service.getRandomValue*(..))")
    public Object aroundLog(ProceedingJoinPoint jp) {
        System.out.println("[Around]====================================");
        Object result = null;
        try {
            // 対象メソッド実行
            result = jp.proceed();
            System.out.println("[Around]args:" + Arrays.toString(jp.getArgs()));
            System.out.println("[Around]signature:" + jp.getSignature());
            System.out.println("[Around]return:" + result);
        } catch (Throwable throwable) {
            throwable.printStackTrace();
        }
        return result;
    }
}
@Before

execution()で実行対象を指定できます(Pointcut)。ワイルドカードも使用可能。
ここではSampleServiceのメソッドを対象とするようにしています。

引数のJoinPointクラスを利用し、getArgs()で対象メソッドの引数を取得し、
getSignature()で対象メソッドのシグネチャを取得してます。

    @Before("execution(* *..*Service.*(..))")
    public void beforeLog(JoinPoint jp) {
        System.out.println("[Before]====================================");
        System.out.println("[Before]args:" + Arrays.toString(jp.getArgs()));
        System.out.println("[Before]signature:" + jp.getSignature());
    }
@AfterReturning

returningで戻り値を参照できます。指定した変数名で参照できるようになります。
ここでは、"randomValue"という変数名で参照してます。

引数のJoinPointクラスを利用し、getArgs()で対象メソッドの引数を取得し、
getSignature()で対象メソッドのシグネチャを取得してます。

    @AfterReturning(value = "execution(* *..*Service.*(..))", returning = "randomValue")
    public void afterReturningLog(JoinPoint jp, int randomValue) {
        System.out.println("[AfterReturn]====================================");
        System.out.println("[AfterReturn]args:" + Arrays.toString(jp.getArgs()));
        System.out.println("[AfterReturn]signature:" + jp.getSignature());
        System.out.println("[AfterReturn]return:" + randomValue);
    }
@AfterThrowing

引数のJoinPointクラスを利用し、getArgs()で対象メソッドの引数を取得し、
getSignature()で対象メソッドのシグネチャを取得してます。

    @AfterThrowing(value = "execution(* *..*Service.*(..))", throwing = "e")
    public void afterThrowingLog(JoinPoint jp, NullPointerException e) {
        System.out.println("[AfterThrowing]====================================");
        System.out.println("[AfterThrowing]args:" + Arrays.toString(jp.getArgs()));
        System.out.println("[AfterThrowing]signature:" + jp.getSignature());
    }
@After

引数のJoinPointクラスを利用し、getArgs()で対象メソッドの引数を取得し、
getSignature()で対象メソッドのシグネチャを取得してます。

    @After("execution(* *..*Service.*(..))")
    public void afterLog(JoinPoint jp) {
        System.out.println("[After]====================================");
        System.out.println("[After]args:" + Arrays.toString(jp.getArgs()));
        System.out.println("[After]signature:" + jp.getSignature());
    }
@Around

@AroundではProceedingJoinPointになります。
引数のProceedingJoinPointクラスを利用し、proceed()でメソッド実行と処理結果を取得し、
getArgs()で対象メソッドの引数を取得し、
getSignature()で対象メソッドのシグネチャを取得してます。

execution()でgetRandomValue()メソッドだけを対象にしています。

    @Around("execution(* *..*Service.getRandomValue*(..))")
    public Object aroundLog(ProceedingJoinPoint jp) {
        System.out.println("[Around]====================================");
        Object result = null;
        try {
            // 対象メソッド実行
            result = jp.proceed();
            System.out.println("[Around]args:" + Arrays.toString(jp.getArgs()));
            System.out.println("[Around]signature:" + jp.getSignature());
            System.out.println("[Around]return:" + result);
        } catch (Throwable throwable) {
            throwable.printStackTrace();
        }
        return result;
    }

実行(エラーなし)

getRandomValue()メソッドを実行してみます。

SpringAopApplication.java

@SpringBootApplication
public class SpringAopApplication implements CommandLineRunner {
    @Autowired
    private SampleService sampleService;

    @Override
    public void run(String... args) throws Exception {
        sampleService.getRandomValue(100);
    }

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


結果

[Around]====================================
[Before]====================================
[Before]args:[100]
[Before]signature:int spring.aop.com.example.service.SampleService.getRandomValue(int)
[Around]args:[100]
[Around]signature:int spring.aop.com.example.service.SampleService.getRandomValue(int)
[Around]return:-1193959466
[After]====================================
[After]args:[100]
[After]signature:int spring.aop.com.example.service.SampleService.getRandomValue(int)
[AfterReturn]====================================
[AfterReturn]args:[100]
[AfterReturn]signature:int spring.aop.com.example.service.SampleService.getRandomValue(int)
[AfterReturn]return:-1193959466


実行された順番を見てみると下記のようになっていることが分かります。
①@Aroundのjp.proceed()前
②@Before
③@Aroundのjp.proceed()後
④@After
⑤@AfterReturn

実行(エラーあり)

次はわざとエラーを発生させるために、
getLength()メソッドを引数nullで実行してみます。

@AfterThrowingを試したいので、@Aroundは対象外にしています。
@Aroundも対象にしていると、@Aroundで例外がキャッチされ、@AfterThrowingが実行されません。

@Around("execution(* *..*Service.getRandomValue*(..))")

SpringAopApplication.java

@SpringBootApplication
public class SpringAopApplication implements CommandLineRunner {
    @Autowired
    private SampleService sampleService;

    @Override
    public void run(String... args) throws Exception {
        sampleService.getLength(null);
    }

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


結果

[Before]====================================
[Before]args:[null]
[Before]signature:int spring.aop.com.example.service.SampleService.getLength(String)
[After]====================================
[After]args:[null]
[After]signature:int spring.aop.com.example.service.SampleService.getLength(String)
[AfterThrowing]====================================
[AfterThrowing]args:[null]
[AfterThrowing]signature:int spring.aop.com.example.service.SampleService.getLength(String)
2016-12-26 20:51:42.520  INFO 6464 --- [           main] utoConfigurationReportLoggingInitializer : 

Error starting ApplicationContext. To display the auto-configuration report re-run your application with 'debug' enabled.
2016-12-26 20:51:42.533 ERROR 6464 --- [           main] o.s.boot.SpringApplication               : Application startup failed

java.lang.IllegalStateException: Failed to execute CommandLineRunner
	at org.springframework.boot.SpringApplication.callRunner(SpringApplication.java:803) [spring-boot-1.4.2.RELEASE.jar:1.4.2.RELEASE]
	at org.springframework.boot.SpringApplication.callRunners(SpringApplication.java:784) [spring-boot-1.4.2.RELEASE.jar:1.4.2.RELEASE]
	at org.springframework.boot.SpringApplication.afterRefresh(SpringApplication.java:771) [spring-boot-1.4.2.RELEASE.jar:1.4.2.RELEASE]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:316) [spring-boot-1.4.2.RELEASE.jar:1.4.2.RELEASE]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1186) [spring-boot-1.4.2.RELEASE.jar:1.4.2.RELEASE]
	at org.springframework.boot.SpringApplication.run(SpringApplication.java:1175) [spring-boot-1.4.2.RELEASE.jar:1.4.2.RELEASE]
	at spring.aop.com.example.SpringAopApplication.main(SpringAopApplication.java:21) [classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_102]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_102]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_102]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_102]
	at com.intellij.rt.execution.application.AppMain.main(AppMain.java:147) [idea_rt.jar:na]
	:
	:
	:


実行された順番を見てみると下記のようになっていることが分かります。
①@Before
②@After
③@AfterThrowing


試したのはこのくらいです。

ソースは一応あげときました。
github.com


終わり。