Spring Boot でリクエストヘッダーを取得しMDCでログを落とす

MDCで落とすログのフォーマット
リクエストヘッダーの取得
動作確認

MDCで落とすログのフォーマット

MCDで落とすログのフォーマットはlogback.xmlで指定します。

logback.xml

<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{HH:mm:ss} [%thread] %-5level %logger{36} Request-Id:%X{RequestId} message:%msg%n</pattern>
        </encoder>
    </appender>

        <root>
        <level value="INFO" />
        <appender-ref ref="STDOUT" />
        </root>
</configuration>

<pattern>%d{HH:mm:ss} [%thread] %-5level %logger{36} Request-Id:%X{RequestId} message:%msg%n</pattern>

</encoder>

</appender>

<root>

<appender-ref ref="STDOUT" />

</root>

</configuration>

%X{RequestId} にMDCでputした値が、%msg にSlf4jで出力したログ文字列がマッピングされます。

ほかにも%d{HH:mm:ss} でログの出力時間、[%thread] でログを出力したスレッド名、%-5level でログレベルなどが出力されます。

リクエストヘッダーの取得

RESTAPIのコントローラクラスとして以下のクラスを作成。

Controller.java

import lombok.extern.slf4j.Slf4j;
import org.springframework.http.HttpStatus;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.*;

@RestController
@RequestMapping()
@Slf4j
public class Controller {

    @RequestMapping(method = RequestMethod.GET, path = "/{string}")
    public ResponseEntity<String> get(@PathVariable(value = "string") String string) {
        log.warn("my string = " + string);
        return new ResponseEntity<>("get", HttpStatus.OK);
    }

    @RequestMapping(method = RequestMethod.POST, path = "/")
    public ResponseEntity<String> add(@RequestBody String string) {
        log.warn("my string = " + string);
        return new ResponseEntity<>("post", HttpStatus.CREATED);
    }
}

import lombok.extern.slf4j.Slf4j;

import org.springframework.http.HttpStatus;

import org.springframework.http.ResponseEntity;

import org.springframework.web.bind.annotation.*;

@RestController

@RequestMapping()

@Slf4j

public class Controller {

@RequestMapping(method = RequestMethod.GET, path = "/{string}")

public ResponseEntity<String> get(@PathVariable(value = "string") String string) {

log.warn("my string = " + string);

return new ResponseEntity<>("get", HttpStatus.OK);

}

@RequestMapping(method = RequestMethod.POST, path = "/")

public ResponseEntity<String> add(@RequestBody String string) {

log.warn("my string = " + string);

return new ResponseEntity<>("post", HttpStatus.CREATED);

}

上の方のGETメソッドのエンドポイントではパスパラメータで受け取った値を、下のPOSTメソッドではリクエストボディをログに落としている。

ログでリクエストヘッダーのパラメータを落とすためにControllerが呼ばれる前に経由する、interceptorを以下で定義します。

RequestInterceptor.java

import org.slf4j.MDC;
import org.springframework.lang.Nullable;
import org.springframework.stereotype.Component;
import org.springframework.web.servlet.handler.HandlerInterceptorAdapter;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

@Component
public class RequestInterceptor extends HandlerInterceptorAdapter {
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {

        String requestId = request.getHeader("Request-Id");

        MDC.clear();
        MDC.put("RequestId", requestId);
        return true;
    }
    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler,
                                @Nullable Exception ex) throws Exception {
        MDC.clear();
    }

}

import org.slf4j.MDC;

import org.springframework.lang.Nullable;

import org.springframework.stereotype.Component;

import org.springframework.web.servlet.handler.HandlerInterceptorAdapter;

import javax.servlet.http.HttpServletRequest;

import javax.servlet.http.HttpServletResponse;

@Component

public class RequestInterceptor extends HandlerInterceptorAdapter {

@Override

public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {

String requestId = request.getHeader("Request-Id");

MDC.clear();

MDC.put("RequestId", requestId);

return true;

}

@Override

public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler,

@Nullable Exception ex) throws Exception {

MDC.clear();

}

MDC.put(“RequestId”, requestId); でlogback.xmlで指定した%X{RequestId} のところに値がマッピングされます。

interceptorを経由するようにWebMVCの設定を追加します。

WebMvcConfig.java

あimport org.springframework.beans.factory.annotation.Autowired;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;

@Configuration
public class WebMvcConfig implements WebMvcConfigurer {

    @Autowired
    RequestInterceptor requestInterceptor;

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(requestInterceptor);
    }
}

あimport org.springframework.beans.factory.annotation.Autowired;

import org.springframework.context.annotation.Configuration;

import org.springframework.web.servlet.config.annotation.InterceptorRegistry;

import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;

@Configuration

public class WebMvcConfig implements WebMvcConfigurer {

@Autowired

RequestInterceptor requestInterceptor;

@Override

public void addInterceptors(InterceptorRegistry registry) {

registry.addInterceptor(requestInterceptor);

}

動作確認

POSTのエンドポイントにリクエスト

$ curl -X POST -H "Content-Type: application/json" -d '{"test":"test"}' localhost:8080 -H "Request-Id: hoge"
post

1 2	$ curl -X POST -H "Content-Type: application/json" -d '{"test":"test"}' localhost:8080 -H "Request-Id: hoge" post

出力されたログ

15:46:12 [http-nio-8080-exec-1] WARN  c.e.s.Controller Request-Id:hoge message:my string = {"test":"test"}

1	15:46:12 [http-nio-8080-exec-1] WARN c.e.s.Controller Request-Id:hoge message:my string = {"test":"test"}

GETのエンドポイントにリクエスト

$ curl http://localhost:8080/fuga -H "Request-Id: hoge"
get

1 2	$ curl http://localhost:8080/fuga -H "Request-Id: hoge" get

出力されたログ

15:46:41 [http-nio-8080-exec-2] WARN  c.e.s.Controller Request-Id:hoge message:my string = fuga

1	15:46:41 [http-nio-8080-exec-2] WARN c.e.s.Controller Request-Id:hoge message:my string = fuga