雑多に技術メモと他色々

主に自分用な技術メモが多くなる気がする。他色々が書かれるかどうかは不明。

SpringBootでリクエスト/レスポンス情報をログに出力するFilter実装

とりあえずレスポンスペイロードやヘッダ出力もできるやつを試しに作った分をそのまま乗せる。
CommonsRequestLoggingFilterとそれを参考にして自作したレスポンス出力用フィルタをセットで使う。
(必要なログDEBUG設定箇所が2つに分かれるけど、一旦良しとしている)

コード例

Filterクラス実装

レスポンス情報をいい感じに出力するクラス君が存在しないので、まずはCommonsRequestLoggingFilterを参考に自作。

/**
 * ResponseDebugLoggingFilter.java
 *
 * These codes are licensed under CC0.
 * http://creativecommons.org/publicdomain/zero/1.0/deed.ja
 */
package com.sample.config.impl;

import org.springframework.lang.Nullable;
import org.springframework.util.Assert;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.util.ContentCachingResponseWrapper;
import org.springframework.web.util.WebUtils;

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.io.UnsupportedEncodingException;
import java.util.stream.Collectors;

public class ResponseDebugLoggingFilter extends OncePerRequestFilter {

    private static final String RESP_MSG_PREFIX = "Response info [";
    private static final String MSG_SUFFIX = "]";
    private static final int DEFAULT_MAX_PAYLOAD_LENGTH = 50;
    private static final String PAYLOAD_OMITTED_MSG = "...(omitted)";

    /**
     * ペイロード最大出力サイズ
     */
    private int maxPayloadLength = DEFAULT_MAX_PAYLOAD_LENGTH;

    /**
     * ペイロードが省略された場合、その旨を表示するか
     */
    private boolean showPayLoadOmitted = false;

    /**
     * ログ出力する最大ペイロードサイズを設定します。デフォルト値:50<br>
     *
     * @param maxPayloadLength 最大ペイロードサイズ
     */
    public void setMaxPayloadLength(int maxPayloadLength) {
        Assert.isTrue(maxPayloadLength >= 0, "'maxPayloadLength' should be larger than or equal to 0");
        this.maxPayloadLength = maxPayloadLength;
    }

    /**
     * ペイロードが省略された場合、その旨を表示するかを設定します。デフォルト値:false<br>
     * trueを設定した場合、ペイロードが最大サイズを超えた際に "...(omitted)" の12文字が末尾に追加されます。
     *
     * @param showPayLoadOmitted ペイロードが省略された旨を表示する場合、<code>true</code>
     */
    public void setShowPayLoadOmitted(boolean showPayLoadOmitted) {
        this.showPayLoadOmitted = showPayLoadOmitted;
    }

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
            throws ServletException, IOException {

        // 'ContentCachingResponseWrapper' can cache the response info.
        // If logging is required, Convert the response to 'ContentCachingResponseWrapper'.
        HttpServletResponse responseToUse = response;
        boolean shouldLog = logger.isDebugEnabled();
        if (shouldLog) {
            responseToUse = new ContentCachingResponseWrapper(response);
        }
        try {
            filterChain.doFilter(request, responseToUse);
        } finally {
            // Create and log message only when should.
            if ((responseToUse instanceof ContentCachingResponseWrapper) && shouldLog) {
                logger.debug(this.createResponseMessage(request, responseToUse, RESP_MSG_PREFIX, MSG_SUFFIX));
                // After reading stream for logging, it needs copy body to the response.
                // (Because the stream has already been loaded)
                ((ContentCachingResponseWrapper) responseToUse).copyBodyToResponse();
            }
        }
    }

    /**
     * レスポンス用の出力メッセージを生成して返却します。
     * @param request リクエスト情報
     * @param response レスポンス情報
     * @param prefix メッセージのprefix
     * @param suffix メッセージのsuffix
     * @return レスポンス用の出力メッセージ
     */
    private String createResponseMessage(HttpServletRequest request, HttpServletResponse response, String prefix, String suffix) {
        StringBuilder msg = new StringBuilder();
        msg.append(prefix);
        msg.append(request.getMethod()).append(' ');
        msg.append(request.getRequestURI());

        // Add status code.
        msg.append(", HttpStatus=").append(response.getStatus());

        // Add headers.
        var headers = response.getHeaderNames().stream()
                .distinct()
                .flatMap(name -> response.getHeaders(name).stream()
                        .map(value ->  (name + ":\"" + value  + "\""))
                ).collect(Collectors.joining(", "));
        msg.append(", resHeaders=[").append(headers).append("]");

        // Add payload.
        String payload = this.getResponsePayload(response);
        if (payload != null) {
            msg.append(", resPayload=").append(payload);
        }

        msg.append(suffix);
        return msg.toString();
    }

    @Nullable
    protected String getResponsePayload(HttpServletResponse response) {
        ContentCachingResponseWrapper wrapper =
                WebUtils.getNativeResponse(response, ContentCachingResponseWrapper.class);
        if (wrapper != null) {
            byte[] buf = wrapper.getContentAsByteArray();
            if (buf.length > 0) {
                int length = Math.min(buf.length, this.maxPayloadLength);
                try {
                    return new String(buf, 0, length, wrapper.getCharacterEncoding())
                            + (buf.length > this.maxPayloadLength && this.showPayLoadOmitted ? PAYLOAD_OMITTED_MSG : "");
                } catch (UnsupportedEncodingException ex) {
                    return "[unknown]";
                }
            }
        }
        return null;
    }
}

Configクラス実装

CommonsRequestLoggingFilterと自作Filterを順序付きで登録し、下記の順でログが出力されるようにする。

  1. リクエスト前情報(Commons)
  2. リクエスト後情報+リクエスペイロード(Commons)
  3. レスポンスの情報(自作)

package com.sample.config;

import com.sample.config.impl.ResponseDebugLoggingFilter;
import org.springframework.boot.web.servlet.FilterRegistrationBean;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.filter.CommonsRequestLoggingFilter;

@Configuration
public class RequestLogConfig {
    @Bean
    public FilterRegistrationBean responseLoggingFilter() {
        var filter = new ResponseDebugLoggingFilter();
        filter.setMaxPayloadLength(20);
        filter.setShowPayLoadOmitted(true);
        var bean = new FilterRegistrationBean<>(filter);
        bean.setOrder(1);
        return bean;
    }

    @Bean
    public FilterRegistrationBean requestLoggingFilter() {
        var filter = new CommonsRequestLoggingFilter();
        filter.setIncludeClientInfo(true);
        filter.setIncludeQueryString(true);
        filter.setIncludeHeaders(true);
        filter.setIncludePayload(true);
        filter.setMaxPayloadLength(1024);
        var bean = new FilterRegistrationBean<>(filter);
        bean.setOrder(2);
        return bean;
    }
}

ログのDEBUG設定

とりあえずapplication.yamlにDEBUG出力されるように設定した。
(設定先はどこでもいいと思う)

logging.level:
  com.sample.config.impl.ResponseDebugLoggingFilter: DEBUG
  org.springframework.web.filter.CommonsRequestLoggingFilter: DEBUG

出力例

logbackのデフォルトCONSOLEフォーマットの場合。

2022-02-18 03:15:27.150 DEBUG 18936 --- [nio-8080-exec-8] o.s.w.f.CommonsRequestLoggingFilter      : Before request [POST /test, client=127.0.0.1, headers=[host:"localhost:8080", user-agent:"curl/7.78.0", accept:"*/*", content-length:"4", Content-Type:"application/x-www-form-urlencoded;charset=UTF-8"]]
2022-02-18 03:15:27.178 DEBUG 18936 --- [nio-8080-exec-8] o.s.w.f.CommonsRequestLoggingFilter      : After request [POST /test, client=127.0.0.1, headers=[host:"localhost:8080", user-agent:"curl/7.78.0", accept:"*/*", content-length:"4", Content-Type:"application/x-www-form-urlencoded;charset=UTF-8"], payload=aaaa=]
2022-02-18 03:15:27.178 DEBUG 18936 --- [nio-8080-exec-8] c.s.c.impl.ResponseDebugLoggingFilter    : Response info [POST /test, HttpStatus=200, resHeaders=[], resPayload={"id":"aaaa=01234567...(omitted)]