はじめに

静的ページ（JavaScriptやCSS等）は除いて、Spring Bootでリクエストを受けたものについて、以下をログに出力したい。

  • 処理開始時刻、処理終了時刻、処理時間
  • URL
  • すべてのリクエストパラメータ
  • レスポンスステータス

また、一つ一つのリクエストを一意に特定しやすくするため、ログインユーザ名とUUIDを組み合わせた文字列を、ログの先頭に識別子として必ず付与する。

検証version

  • Spring Boot 1.3.5
  • Selenium WebDriver 2.53.0

ソース

LoggingFilter.java

import java.io.IOException;
import java.util.Arrays;
import java.util.Map;
import java.util.Map.Entry;
import java.util.UUID;

import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

import org.springframework.stereotype.Component;

import lombok.extern.slf4j.Slf4j;

@Component
@Slf4j
public class LoggingFilter implements Filter {

    @Override
    public void init(FilterConfig filterConfig) throws ServletException {
    }

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        HttpServletRequest httpReq = ((HttpServletRequest)request);
        String uri = httpReq.getRequestURI();
        if (isStatic(uri)) {
            chain.doFilter(request, response);
            return;
        }

        long start = System.currentTimeMillis();
        UUID uuid = UUID.randomUUID();
        String userName = httpReq.getRemoteUser();
        String requestIdentifier = "[" + userName + "]" + "[" + uuid + "]";

        log.info(String.format("%s start", requestIdentifier));
        log.info(String.format("%s URI: %s", requestIdentifier, uri));

        Map<String, String[]> params = httpReq.getParameterMap();
        for (Entry<String, String[]> param : params.entrySet()) {
            log.info(String.format("%s PARAM_KEY: %s, PARAM_VALUE: %s"
                    , requestIdentifier
                    , param.getKey()
                    , Arrays.toString(param.getValue())));
        }

        chain.doFilter(request, response);

        int status = ((HttpServletResponse)response).getStatus();

        log.info(String.format("%s end in %d millisec. STATUS %d", requestIdentifier, System.currentTimeMillis() - start, status));
    }

    private boolean isStatic(String uri) {
        return uri.contains("/js/")
        || uri.contains("/css/")
        || uri.contains("/fonts/");
    }

    @Override
    public void destroy() {
    }
}

ソースコード解説

ログ項目の取得方法

処理開始時刻、処理終了時刻、処理時間は通常のJavaコードである。

URL、リクエストパラメータ、レスポンスステータスは、SpringのモジュールではなくJavaServletでおなじみのHttpServletRequest、HttpServletResponseを利用して取得する。

Loggerオブジェクト

Loggerオブジェクトを取得するためには、通常 private static final Logger log = LoggerFactory.getLogger(Sample.class); のようなコードを書く必要があるが、Lombokを使用しているため、 @Slf4j でクラスをアノテートすることで、logという名前の Loggerオブジェクトが使えるようなる。

Filter実装クラスのSpring Bootへの登録方法

@Component をFilter実装クラスにつけるだけで、Spring BootがFilterとして扱ってくれる。

今回はFilterはただ一つLoggingFilterのみを登録すればよかったのでこの方法を採っているが、Filter実装クラスを複数登録し、さらにFilterの実行順序を制御するのであれば、FilterRegistrationBeanを使用する必要があるだろう。

FilterRegistrationBeanの使用方法はこちらを参考：Spring Boot で複数の Filter を定義する