Spring AOPでメソッドのinとoutをlogに出力する

## はじめに
Webアプリケーションの開発と保守を行う場合、リクエストとレスポンスの詳細が
logに適切に出力されていると、もしものときの調査・対応に非常に助かることが多いと思います。
今回はAOPを利用して、メソッドのin(引数等)とout(戻り値)を出力させたいと思います。

検証には以前、[コチラのシリーズ](https://qiita.com/mijinco0612/items/00d8a1a9dbf7eb8b9de8)で作成した[リポジトリ](https://github.com/mijinco0612-self-improvement/spring-auth0)を使用します。

## [pom.xmlにDependencyを追加](https://github.com/mijinco0612-self-improvement/spring-auth0/commit/9016b9f0a28e31e8921438c25d9b7268f5a8cccf)
AOPを使用するにあたって、spring-boot-starter-aopを追加します。

```xml:pom.xml
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-aop</artifactId>
        </dependency>
```

##[LoggingAdviceを追加](https://github.com/mijinco0612-self-improvement/spring-auth0/commit/b58f16870d98342c096375f6e03018f672a787ef)
実際にaopを使用してメソッドのin-outをlogに出力する処理を追加します。

```java:aspect/LoggingAdvice.java
package com.mijinco0612.springauth0.aspect;

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.AfterReturning;
import org.aspectj.lang.annotation.AfterThrowing;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;

import java.util.ArrayList;

@Aspect
@Component
public class LoggingAdvice {
    private final Logger logger;

    public LoggingAdvice() {
        this.logger = LoggerFactory.getLogger(getClass());
    }

  @Before("execution(* com.mijinco0612.springauth0.controller.api.*.*.*(..))")
  public void invokeApiControllerBefore(JoinPoint joinPoint) {
        outputLog(joinPoint);
    }


    @AfterReturning(pointcut = "execution(* com.mijinco0612.springauth0.controller.api.*.*.*(..))", returning = "returnValue")
    public void invokeControllerAfter(JoinPoint joinPoint, Object returnValue) {
        outputLog(joinPoint, returnValue);
    }

    @AfterThrowing(value = "execution(* com.mijinco0612.springauth0.controller.api.*.*.*(..))", throwing = "e")
    public void invokeControllerAfterThrowing(JoinPoint joinPoint, Throwable e) {
        outputErrorLog(joinPoint, e);
    }


    private void outputLog(JoinPoint joinPoint) {
        String logMessage = "[" + getSessionId() + "]:" + getClassName(joinPoint) + "." + getSignatureName(joinPoint) + ":START:" + getArguments(joinPoint);
        logger.info(logMessage);
    }

    private void outputLog(JoinPoint joinPoint, Object returnValue) {
        String logMessage = "[" + getSessionId() + "]:" + getClassName(joinPoint) + "." + getSignatureName(joinPoint) + ":END:" + getReturnValue(returnValue);
        logger.info(logMessage);
    }

    private void outputErrorLog(JoinPoint joinPoint, Throwable e) {
        String logMessage = "[" + getSessionId() + "]:" + getClassName(joinPoint) + "." + getSignatureName(joinPoint) + ":arguments:" + getArguments(joinPoint);
        logger.error(logMessage, e);
    }

    private String getSessionId() {
        return ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getRequest().getSession().getId();
    }

    private String getClassName(JoinPoint joinPoint) {
        return joinPoint.getTarget().getClass().toString();
    }

    private String getSignatureName(JoinPoint joinPoint) {
        return joinPoint.getSignature().getName();
    }

    private String getArguments(JoinPoint joinPoint) {
        if (joinPoint.getArgs() == null) {
            return "argument is null";
        }

        Object[] arguments = joinPoint.getArgs();
        ArrayList<String> argumentStrings = new ArrayList();

        for (Object argument : arguments) {
            if (argument != null) {
                argumentStrings.add(argument.toString());
            }
        }
        return String.join(",", argumentStrings);
    }

    private String getReturnValue(Object returnValue) {
        return (returnValue != null) ? returnValue.toString() : "return value is null";
    }

}

```

##実際に検証してみる

Posｔmanを使用して以下のようなリクエストを送信してみました
```
http://localhost:28080/api/v1/echo?echoMessage=testEchoMessage
```

リクエスト先のコントローラーはこんな感じにしています。


```java:DemoController.java
    @ResponseBody
    @GetMapping("/api/v1/echo")
    public String echoApi(@RequestParam("echoMessage") String message) {
        return "pong"+message;
    }
```
`testEchoMessage`という文字列をechoMessageというクエリパラメータに設定して`http://localhost:28080/api/v1/echo`へリクエストしました。

logには`testEchoMessage`という引数と`pongtestEchoMessage`という戻り値が出力されているはずです。

実際にログをして確認してみましょう。

```bash:spring-auth0.log
2018-07-11 13:23:05 |http-nio-28080-exec-10| [INFO] com.mijinco0612.springauth0.aspect.LoggingAdvice [CD896FA8A5798E84FBF0CDBDDE90E7FF]:class com.mijinco0612.springauth0.controller.api.v1.DemoController.echoApi:STARTtestEchoMessage
2018-07-11 13:23:05 |http-nio-28080-exec-10| [INFO] com.mijinco0612.springauth0.aspect.LoggingAdvice [CD896FA8A5798E84FBF0CDBDDE90E7FF]:class com.mijinco0612.springauth0.controller.api.v1.DemoController.echoApi:END:pongtestEchoMessage
```
出力されました！