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

かんがるーさんの日記

最近自分が興味をもったものを調べた時の手順等を書いています。今は Spring Boot をいじっています。

Spring Boot で書籍の貸出状況確認・貸出申請する Web アプリケーションを作る ( 番外編 )( AspectJ でログを出力する )

概要

Spring Boot で作成した Webアプリケーションで AspectJ ( Spring AOP ) でログを出力する方法を調べたので、そのメモ書きです。

やりたいと思ったのは、以下の3点です。

  • Controller クラスのクラスに画面名を、メソッドに処理名をアノテーションで指定したら、その文字列をログに出力する。
  • Controller クラスの @RequestMapping アノテーションが付加されたメソッドが呼び出された時に request, response のデータをログに出力する。
  • クラスのメソッドが呼び出された時に引数と戻り値をログに出力する。

参照したサイト・書籍

  1. Aspect Oriented Programming with Spring
    http://docs.spring.io/spring/docs/current/spring-framework-reference/html/aop.html

  2. How can I get HttpServletRequest and HttpServletResponse object in Spring AOP
    http://stackoverflow.com/questions/30027912/how-can-i-get-httpservletrequest-and-httpservletresponse-object-in-spring-aop

  3. Spring AOP: @annotation(annotation)
    http://stackoverflow.com/questions/21588684/spring-aop-annotationannotation

  4. generic Enumeration to Iterable converter [closed]
    http://stackoverflow.com/questions/8197797/generic-enumeration-to-iterable-converter

  5. Java8 の Stream 取得方法あれこれ
    http://etc9.hatenablog.com/entry/2015/05/07/195629

  6. AOP @Around: return BAD_REQUEST response
    http://stackoverflow.com/questions/31075594/aop-around-return-bad-request-response

  7. Log4j and AOP, how to get actual class name
    http://stackoverflow.com/questions/11505735/log4j-and-aop-how-to-get-actual-class-name

目次

  1. Spring Boot + AspectJ でログを出力するために必要なこと
  2. feature/aspectj-memo ブランチの作成
  3. Controller クラスのクラスに画面名を、メソッドに処理名をアノテーションで指定したら、その文字列をログに出力する
    1. 実装仕様
    2. アノテーションとログを出力する仕組みを実装する
    3. 動作確認
  4. Controller クラスの @RequestMapping アノテーションが付加されたメソッドが呼び出された時に request, response のデータをログに出力する
    1. 実装仕様
    2. request, response のデータをログに出力する仕組みを実装する
    3. 動作確認
  5. クラスのメソッドが呼び出された時に引数と戻り値をログに出力する
    1. クラスのメソッドが呼び出された時に引数と戻り値をログに出力する仕組みを実装する
    2. 動作確認
  6. Push、Pull Request、マージ

手順

Spring Boot + AspectJ でログを出力するために必要なこと

build.gradle に spring-boot-starter-data-jpa を指定すれば Spring AOP も有効になります。spring-boot-starter-aop を指定する必要はありません。今回はこの前提で書きます。

dependencies {

    ..........

    compile("org.springframework.boot:spring-boot-starter-data-jpa")

    ..........
}

feature/aspectj-memo ブランチの作成

  1. feature/aspectj-memo ブランチを作成します。

Controller クラスのクラスに画面名を、メソッドに処理名をアノテーションで指定したら、その文字列をログに出力する

実装仕様

  • @LoggingControllerName, @LogginEventName アノテーションを用意します。Controller クラスで以下のように指定する想定です。
@Controller
@RequestMapping("/confirmresult")
@LoggingControllerName("貸出申請結果確認画面")
public class ConfirmresultController {

    ..........

    @RequestMapping
    @LoggingEventName("初期表示処理")
    public String index(@Validated ConfirmresultParamForm confirmresultParamForm
            , BindingResult bindingResult
            , ConfirmresultForm confirmresultForm
            , BindingResult bindingResultOfConfirmresultForm
            , HttpServletResponse response) {

        ..........

    }

    @RequestMapping(value = "/filedownloadByResponse", method = RequestMethod.POST)
    @LoggingEventName("CSVダウンロード ( HttpServletResponse ) ボタンクリック時の処理")
    public void filedownloadByResponse(ConfirmresultForm confirmresultForm
            , BindingResult bindingResult
            , HttpServletResponse response) throws IOException {

        ..........

    }

    ..........

}
  • ログには以下のフォーマットで出力します。
2016-02-27 20:39:15.003  INFO 4960 --- [xxxxxxxxxxxxxxx] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx  : ***** begin *****   ControllerName = 貸出申請結果確認画面, EventName = 初期表示処理
2016-02-27 20:39:15.003  INFO 4960 --- [xxxxxxxxxxxxxxx] xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx  : ***** end   *****   ControllerName = 貸出申請結果確認画面, EventName = 初期表示処理

アノテーションとログを出力する仕組みを実装する

  1. src/main/java/ksbysample/webapp/lending の下に aspect.logging パッケージを作成します。

  2. src/main/java/ksbysample/webapp/lending/aspect/logging の下に LoggingControllerName.java を作成します。作成後、リンク先の内容 に変更します。

  3. src/main/java/ksbysample/webapp/lending/aspect/logging の下に LoggingEventName.java を作成します。作成後、リンク先の内容 に変更します。

  4. src/main/java/ksbysample/webapp/lending/aspect/logging の下に ControllerAndEventNameLogger.java を作成します。作成後、リンク先の内容 に変更します。

動作確認

動作確認します。

最初に ksbysample/webapp/lending/web/confirmresult/ConfirmresultController.java に以下のように @LoggingControllerName, @LoggingEventName アノテーションを付加します。

@Controller
@RequestMapping("/confirmresult")
@LoggingControllerName("貸出申請結果確認画面")
public class ConfirmresultController {

    ..........

    @RequestMapping
    @LoggingEventName("初期表示処理")
    public String index(@Validated ConfirmresultParamForm confirmresultParamForm
            , BindingResult bindingResult
            , ConfirmresultForm confirmresultForm
            , BindingResult bindingResultOfConfirmresultForm
            , HttpServletResponse response) {

        ..........
    }

    ..........

}

Tomcat を起動し、http://localhost:8080/confirmresult?lendingAppId=105 にアクセスします。以下のように ControllerName と EventName がログに出力することが確認できます。

2016-02-28 09:25:00.379  INFO 7080 --- [nio-8080-exec-1] k.w.l.a.l.ControllerAndEventNameLogger   : ***** begin *****  ControllerName = 貸出申請結果確認画面, EventName = 初期表示処理
..........
2016-02-28 09:25:02.446  INFO 7080 --- [nio-8080-exec-1] k.w.l.a.l.ControllerAndEventNameLogger   : ***** end   *****  ControllerName = 貸出申請結果確認画面, EventName = 初期表示処理

今度は ksbysample/webapp/lending/web/confirmresult/ConfirmresultController.java から @LoggingControllerName を取り除き、 @LoggingEventName アノテーションのみ付加した状態にします。

@Controller
@RequestMapping("/confirmresult")
public class ConfirmresultController {

    ..........

    @RequestMapping
    @LoggingEventName("初期表示処理")
    public String index(@Validated ConfirmresultParamForm confirmresultParamForm
            , BindingResult bindingResult
            , ConfirmresultForm confirmresultForm
            , BindingResult bindingResultOfConfirmresultForm
            , HttpServletResponse response) {

        ..........
    }

    ..........

}

再度 http://localhost:8080/confirmresult?lendingAppId=105 にアクセスします。今度は EventName だけがログに出力されることが確認できます。

2016-02-28 09:27:19.926  INFO 7080 --- [nio-8080-exec-1] k.w.l.a.l.ControllerAndEventNameLogger   : ***** begin *****  EventName = 初期表示処理
..........
2016-02-28 09:27:20.061  INFO 7080 --- [nio-8080-exec-1] k.w.l.a.l.ControllerAndEventNameLogger   : ***** end   *****  EventName = 初期表示処理

ksbysample/webapp/lending/web/confirmresult/ConfirmresultController.java に @LoggingControllerName を再度付加した後、Tomcat を停止し一旦ここで commit します。

Controller クラスの @RequestMapping アノテーションが付加されたメソッドが呼び出された時に request, response のデータをログに出力する

実装仕様

Controller クラスの @RequestMapping アノテーションが付加されたメソッドが呼び出された時に、Seasar2 の RequestDumpFilter が出力するようなログ ( Seasar2 - RequestDumpFilter ) を出力してみます。

request, response のデータをログに出力する仕組みを実装する

  1. src/main/java/ksbysample/webapp/lending/aspect/logging の下に RequestAndResponseLogger.java を作成します。作成後、リンク先の内容 に変更します。

動作確認

動作確認します。

Tomcat を起動し、http://localhost:8080/confirmresult?lendingAppId=105 にアクセスします。以下のようにログが出力されることが確認できます。

2016-02-28 20:48:10.393  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.ControllerAndEventNameLogger   : ***** begin *****  ControllerName = 貸出申請結果確認画面, EventName = 初期表示処理
2016-02-28 20:48:10.393  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][info  ] REQUEST_URI = /confirmresult, SERVLET_PATH = /confirmresult
2016-02-28 20:48:10.393  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][info  ] CHARACTER_ENCODING = UTF-8, CONTENT_LENGTH = -1, CONTENT_TYPE = null, LOCALE = ja_JP, SCHEME = http
2016-02-28 20:48:10.393  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][info  ] REMOTE_ADDR = 127.0.0.1, REMOTE_HOST = 127.0.0.1, SERVER_NAME = localhost, SERVER_PORT = 8080
2016-02-28 20:48:10.393  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][info  ] CONTEXT_PATH = , REQUEST_METHOD = GET, QUERY_STRING = lendingAppId=105, PATH_INFO = null, REMOTE_USER = tanaka.taro@sample.com
2016-02-28 20:48:10.393  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][header] accept = text/html, application/xhtml+xml, */*
2016-02-28 20:48:10.393  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][header] accept-language = ja-JP,en;q=0.5
2016-02-28 20:48:10.393  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][header] user-agent = Mozilla/5.0 (Windows NT 6.1; WOW64; Trident/7.0; rv:11.0) like Gecko
2016-02-28 20:48:10.393  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][header] accept-encoding = gzip, deflate
2016-02-28 20:48:10.394  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][header] host = localhost:8080
2016-02-28 20:48:10.394  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][header] dnt = 1
2016-02-28 20:48:10.394  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][header] connection = Keep-Alive
2016-02-28 20:48:10.394  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][header] cache-control = no-cache
2016-02-28 20:48:10.394  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][cookie] name = SESSION, value = b264c91f-4b0d-4a2f-8462-b4bdd4b58de2, domain = null, path = null, maxage = -1, secure = false, httponly = false
2016-02-28 20:48:10.394  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [req][param ] lendingAppId = 105
..........
2016-02-28 20:48:10.441  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [res][info  ] RESPONSE_STATUS = 200, CHARACTER_ENCODING = UTF-8, CONTENT_TYPE = null, LOCALE = ja_JP
2016-02-28 20:48:10.441  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [res][header] X-Content-Type-Options = nosniff
2016-02-28 20:48:10.441  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [res][header] X-XSS-Protection = 1; mode=block
2016-02-28 20:48:10.441  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [res][header] Cache-Control = no-cache, no-store, max-age=0, must-revalidate
2016-02-28 20:48:10.442  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [res][header] Pragma = no-cache
2016-02-28 20:48:10.442  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [res][header] Expires = 0
2016-02-28 20:48:10.442  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.RequestAndResponseLogger       : [res][header] X-Frame-Options = DENY
2016-02-28 20:48:10.442  INFO 456 --- [nio-8080-exec-1] k.w.l.a.l.ControllerAndEventNameLogger   : ***** end   *****  ControllerName = 貸出申請結果確認画面, EventName = 初期表示処理

Tomcat を停止し一旦ここで commit します。

クラスのメソッドが呼び出された時に引数と戻り値のデータをログに出力する

クラスのメソッドが呼び出された時に引数と戻り値をログに出力する仕組みを実装する

  1. ksbysample/webapp/lending/aspect/logging の下に MethodLogger.java を作成します。作成後、リンク先の内容 に変更します。

動作確認

動作確認します。

Tomcat を起動し、http://localhost:8080/confirmresult?lendingAppId=105 にアクセスします。以下のようにログが出力されることが確認できます。

2016-03-01 00:52:16.047  INFO 10020 --- [nio-8080-exec-1] k.w.l.a.l.ControllerAndEventNameLogger   : ***** begin *****  ControllerName = 貸出申請結果確認画面, EventName = 初期表示処理
2016-03-01 00:52:16.048  INFO 10020 --- [nio-8080-exec-1] k.w.lending.aspect.logging.MethodLogger  : call : ksbysample.webapp.lending.web.confirmresult.ConfirmresultController#index({ConfirmresultParamForm(lendingAppId=105),org.springframework.validation.BeanPropertyBindingResult: 0 errors,ConfirmresultForm(lendingApp=null, lendingUserId=null, lendingUserName=null, approvalUserName=null, approvedBookFormList=null),org.springframework.validation.BeanPropertyBindingResult: 0 errors,org.springframework.security.web.context.HttpSessionSecurityContextRepository$SaveToSessionResponseWrapper@7d6deb3f})
..........
2016-03-01 00:52:16.101  INFO 10020 --- [nio-8080-exec-1] k.w.lending.aspect.logging.MethodLogger  : ret = confirmresult/confirmresult : ksbysample.webapp.lending.web.confirmresult.ConfirmresultController#index
2016-03-01 00:52:16.101  INFO 10020 --- [nio-8080-exec-1] k.w.l.a.l.ControllerAndEventNameLogger   : ***** end   *****  ControllerName = 貸出申請結果確認画面, EventName = 初期表示処理

Tomcat を停止し一旦ここで commit します。

Push、Pull Request、マージ

  1. GitHub へ Push、feature/aspectj-memo -> 1.0.x へ Pull Request、1.0.x でマージ、feature/aspectj-memo ブランチを削除、をします。

ソースコード

LoggingControllerName.java

package ksbysample.webapp.lending.aspect.logging;

import java.lang.annotation.Documented;
import java.lang.annotation.Retention;
import java.lang.annotation.Target;

import static java.lang.annotation.ElementType.TYPE;
import static java.lang.annotation.RetentionPolicy.RUNTIME;

@Target({TYPE})
@Retention(RUNTIME)
@Documented
public @interface LoggingControllerName {

    String value();

}

LoggingEventName.java

package ksbysample.webapp.lending.aspect.logging;

import java.lang.annotation.Documented;
import java.lang.annotation.Retention;
import java.lang.annotation.Target;

import static java.lang.annotation.ElementType.METHOD;
import static java.lang.annotation.RetentionPolicy.RUNTIME;

@Target({METHOD})
@Retention(RUNTIME)
@Documented
public @interface LoggingEventName {

    String value();

}

ControllerAndEventNameLogger.java

package ksbysample.webapp.lending.aspect.logging;

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;

@Aspect
@Component
public class ControllerAndEventNameLogger {

    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    @Around(value = "execution(* ksbysample.webapp.lending.web..*.*(..)) && @annotation(loggingEventName)"
            , argNames = "pjp, loggingEventName")
    public Object logginControllerAndEventName(ProceedingJoinPoint pjp, LoggingEventName loggingEventName)
            throws Throwable {
        StringBuilder logBegin = new StringBuilder("***** begin *****  ");
        StringBuilder logEnd = new StringBuilder("***** end   *****  ");

        LoggingControllerName loggingGamenName = pjp.getTarget().getClass().getAnnotation(LoggingControllerName.class);
        if (loggingGamenName != null) {
            appendControllerName(logBegin, loggingGamenName.value());
            appendControllerName(logEnd, loggingGamenName.value());
        }
        appendEventName(logBegin, loggingEventName.value());
        appendEventName(logEnd, loggingEventName.value());

        logger.info(logBegin.toString());
        Object ret = pjp.proceed();
        logger.info(logEnd.toString());

        return ret;
    }

    private void appendControllerName(StringBuilder sb, String loggingGamenName) {
        sb.append("ControllerName = ");
        sb.append(loggingGamenName);
        sb.append(", ");
    }

    private void appendEventName(StringBuilder sb, String loggingEventName) {
        sb.append("EventName = ");
        sb.append(loggingEventName);
    }

}
  • logginControllerAndEventName メソッドには @Around アノテーションを付加して、条件にマッチするメソッドの処理前後に処理を追加できるようにします。
  • @Around アノテーションの value 属性に指定した文字列は、execution(* ksbysample.webapp.lending.web..*.*(..)) は ksbysample.webapp.lending.web パッケージの下 ( サブパッケージを含む ) の全てのクラス、メソッドを対象にすることを意味しており、@annotation(loggingEventName) は @LoggingEventName アノテーションが付加されたメソッドだけを対象にすることを意味しています。@annotation の括弧の中に指定する文字列はアノテーションのクラス名ではなく logginControllerAndEventName メソッドに渡す引数名である点が注意です。

RequestAndResponseLogger.java

package ksbysample.webapp.lending.aspect.logging;

import com.google.common.collect.Iterators;
import org.apache.commons.lang3.StringUtils;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
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 javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.util.Arrays;
import java.util.Map;
import java.util.stream.StreamSupport;

@Aspect
@Component
public class RequestAndResponseLogger {

    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    private static final String LOG_REQUEST_INFO = "[req][info  ] ";
    private static final String LOG_REQUEST_HEADER = "[req][header] ";
    private static final String LOG_REQUEST_COOKIE = "[req][cookie] ";
    private static final String LOG_REQUEST_PARAMETER = "[req][param ] ";

    private static final String LOG_RESPONSE_INFO = "[res][info  ] ";
    private static final String LOG_RESPONSE_HEADER = "[res][header] ";

    @Around(value = "execution(* ksbysample.webapp.lending.web..*.*(..)) && @annotation(org.springframework.web.bind.annotation.RequestMapping)")
    public Object logginRequestAndResponse(ProceedingJoinPoint pjp)
            throws Throwable {
        HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest();
        loggingRequest(request);
        Object ret = pjp.proceed();
        HttpServletResponse response = ((ServletRequestAttributes) RequestContextHolder.getRequestAttributes()).getResponse();
        loggingResponse(response);

        return ret;
    }

    private void loggingRequest(HttpServletRequest request) {
        loggingRequestInfo(request);
        loggingRequestHeaders(request);
        loggingRequestCookies(request);
        loggingRequestParameters(request);
    }

    private void loggingResponse(HttpServletResponse response) {
        loggingResponseInfo(response);
        loggingResponseHeaders(response);
    }

    private void loggingRequestInfo(HttpServletRequest request) {
        StringBuilder sb = new StringBuilder();
        append(sb, "REQUEST_URI", request.getRequestURI());
        append(sb, ", SERVLET_PATH", request.getServletPath());
        logging(LOG_REQUEST_INFO, null, sb.toString());

        sb = new StringBuilder();
        append(sb, "CHARACTER_ENCODING", request.getCharacterEncoding());
        append(sb, ", CONTENT_LENGTH", String.valueOf(request.getContentLength()));
        append(sb, ", CONTENT_TYPE", request.getContentType());
        append(sb, ", LOCALE", String.valueOf(request.getLocale()));
        append(sb, ", SCHEME", request.getScheme());
        logging(LOG_REQUEST_INFO, null, sb.toString());

        sb = new StringBuilder();
        append(sb, "REMOTE_ADDR", request.getRemoteAddr());
        append(sb, ", REMOTE_HOST", request.getRemoteHost());
        append(sb, ", SERVER_NAME", request.getServerName());
        append(sb, ", SERVER_PORT", String.valueOf(request.getServerPort()));
        logging(LOG_REQUEST_INFO, null, sb.toString());

        sb = new StringBuilder();
        append(sb, "CONTEXT_PATH", request.getContextPath());
        append(sb, ", REQUEST_METHOD", request.getMethod());
        append(sb, ", QUERY_STRING", request.getQueryString());
        append(sb, ", PATH_INFO", request.getPathInfo());
        append(sb, ", REMOTE_USER", request.getRemoteUser());
        logging(LOG_REQUEST_INFO, null, sb.toString());
    }

    private void loggingRequestHeaders(HttpServletRequest request) {
        Iterable<String> headerNameList = () -> Iterators.forEnumeration(request.getHeaderNames());
        StreamSupport.stream(headerNameList.spliterator(), false)
                .filter(headerName -> !StringUtils.equals(headerName, "cookie"))
                .forEach(headerName -> {
                    Iterable<String> headerList = () -> Iterators.forEnumeration(request.getHeaders(headerName));
                    headerList.forEach(header -> logging(LOG_REQUEST_HEADER, headerName, header));
                });
    }

    private void loggingRequestCookies(HttpServletRequest request) {
        if (request.getCookies() != null) {
            Arrays.asList(request.getCookies()).forEach(cookie -> {
                StringBuilder sb = new StringBuilder();
                sb.append("name = ");
                sb.append(cookie.getName());
                sb.append(", value = ");
                sb.append(cookie.getValue());
                sb.append(", domain = ");
                sb.append(cookie.getDomain());
                sb.append(", path = ");
                sb.append(cookie.getPath());
                sb.append(", maxage = ");
                sb.append(cookie.getMaxAge());
                sb.append(", secure = ");
                sb.append(cookie.getSecure());
                sb.append(", httponly = ");
                sb.append(cookie.isHttpOnly());
                logging(LOG_REQUEST_COOKIE, null, sb.toString());
            });
        }
    }

    private void loggingRequestParameters(HttpServletRequest request) {
        Map<String, String[]> parameterMap = request.getParameterMap();
        parameterMap.forEach((key, values) -> {
            Arrays.asList(values).forEach(value -> logging(LOG_REQUEST_PARAMETER, key, value));
        });
    }

    private void loggingResponseInfo(HttpServletResponse response) {
        StringBuilder sb = new StringBuilder();
        append(sb, "RESPONSE_STATUS", String.valueOf(response.getStatus()));
        append(sb, ", CHARACTER_ENCODING", response.getCharacterEncoding());
        append(sb, ", CONTENT_TYPE", response.getContentType());
        append(sb, ", LOCALE", String.valueOf(response.getLocale()));
        logging(LOG_RESPONSE_INFO, null, sb.toString());
    }

    private void loggingResponseHeaders(HttpServletResponse response) {
        response.getHeaderNames().forEach(headerName -> {
            response.getHeaders(headerName).forEach(header -> logging(LOG_RESPONSE_HEADER, headerName, header));
        });
    }

    private void logging(String title, String name, String value) {
        StringBuilder sb = new StringBuilder(title);
        if (name != null) {
            sb.append(name);
            sb.append(" = ");
        }
        sb.append(value);
        logger.info(sb.toString());
    }

    private void append(StringBuilder sb, String name, String value) {
        sb.append(name);
        sb.append(" = ");
        sb.append(value);
    }

}
  • logginRequestAndResponse メソッドに付加する @Around アノテーションの value 属性の中で @annotation を記述しますが、今回は @RequestMapping アノテーションが付加されているメソッドを対象にしたいので、パッケージも全て記述する org.springframework.web.bind.annotation.RequestMapping の形式で指定します。

MethodLogger.java

package ksbysample.webapp.lending.aspect.logging;

import org.apache.commons.lang3.builder.ToStringBuilder;
import org.apache.commons.lang3.builder.ToStringStyle;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;

@Aspect
@Component
public class MethodLogger {

    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    @Pointcut("execution(* ksbysample.webapp.lending.web..*.*(..)) && @within(org.springframework.stereotype.Controller)")
    private void pointcutControllerMethod() {
    }

    @Pointcut("execution(* ksbysample.webapp.lending.service..*.*(..)) && @within(org.springframework.stereotype.Service)")
    private void pointcutServiceMethod() {
    }

    @Around(value = "pointcutControllerMethod() || pointcutServiceMethod()")
    public Object logginMethod(ProceedingJoinPoint pjp)
            throws Throwable {
        String className = pjp.getSignature().getDeclaringTypeName();
        String methodName = pjp.getSignature().getName();

        logginBeginMethod(className, methodName, pjp.getArgs());
        Object ret = pjp.proceed();
        logginEndMethod(className, methodName, ret);

        return ret;
    }

    private void logginBeginMethod(String className, String methodName, Object[] args) {
        StringBuilder sb = new StringBuilder();
        sb.append("call : ");
        sb.append(className);
        sb.append("#");
        sb.append(methodName);
        sb.append("(");
        sb.append(ToStringBuilder.reflectionToString(args, ToStringStyle.SIMPLE_STYLE));
        sb.append(")");
        logger.info(sb.toString());
    }

    private void logginEndMethod(String className, String methodName, Object ret) {
        StringBuilder sb = new StringBuilder();
        sb.append("ret = ");
        sb.append(ret);
        sb.append(" : ");
        sb.append(className);
        sb.append("#");
        sb.append(methodName);
        logger.info(sb.toString());
    }

}
  • execution(...) で指定したパッケージ配下の @within(...) で指定したアノテーションが付加されているクラスのみ対象にします。

履歴

2016/03/01
初版発行。
2016/03/06
* cookie がない場合に RequestAndResponseLogger が原因で NullPointerException が発生する問題を修正しました