1. mijinco0612

    Posted

    mijinco0612
Changes in title
+spring-boot AOPでメソッドのinとoutをlogに出力する
Changes in tags
Changes in body
Source | HTML | Preview
@@ -0,0 +1,141 @@
+## はじめに
+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";
+ }
+
+}
+
+```
+
+##実際に検証してみる
+
+Postmanを使用して以下のようなリクエストを送信してみました
+```
+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
+```
+出力されました!