Help us understand the problem. What is going on with this article?

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

More than 1 year has passed since last update.

はじめに

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

検証には以前、コチラのシリーズで作成したリポジトリを使用します。

pom.xmlにDependencyを追加

AOPを使用するにあたって、spring-boot-starter-aopを追加します。

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

LoggingAdviceを追加

実際にaopを使用してメソッドのin-outをlogに出力する処理を追加します。

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

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

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という戻り値が出力されているはずです。

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

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

出力されました!

Why not register and get more from Qiita?
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away
Comments
No comments
Sign up for free and join this conversation.
If you already have a Qiita account
Why do not you register as a user and use Qiita more conveniently?
You need to log in to use this function. Qiita can be used more conveniently after logging in.
You seem to be reading articles frequently this month. Qiita can be used more conveniently after logging in.
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away
ユーザーは見つかりませんでした