Go to Qiita Advent Calendar Top
LoginSignup
1
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

@masatomix(Masatomi KINO)in株式会社プライム・ブレインズ

AWS CDK で Infrastructure as Code する: Fluent Bit 番外編。SpringBootのログ機構つづき。

Posted at

今回は前回の「SpringBootのログ機構」の続きです。
前回の最後に、続きでこんなことをやりたいと書きました。

  • アプリチームが投げる例外について、フレームワークチームがExceptionHandlerを使って、適切なHTTPのResponse Statusに載せ替えて返す
    • アプリチームは 業務例外を投げさえすればOK。FW側が例外を判定して所定のステータスのエラーを返却することができます
    • ログ出力もFWにお任せすることで、業務例外はWARNなどのログ記録だけをしてもらい、システム例外はCloudWatch Alarmに検知してもらう、などが可能です
  • アプリでは自由にログ出力できるようにしつつ、Request/Responseのログは常にFWが別の場所へ出力してあげる
    • (通常アプリもFWも同じLogger機構を使うと思いますが、アプリチームが無邪気にエラーログを出しちゃって監視から電話がくる、なんて事を避けるための考慮が必要、ってこと)
    • logTypeとか、ログの種類を判別するプロパティを追加したり
    • requestId というリクエストごとにユニークな値を全ログに出力したり
    • Request/Response のパラメタをログに出力したり、できます
    • (さらには上記のRequest/Responseのようにネストされたデータの場合はMDCじゃない別の機構を用いる)
  • それらの処理を実現するための SpringのInterceptor機能、Servlet Filter機能

順々にやっていこうと思います。

前提

  • いままでの記事をひととおり見ている方

今回のソース

$ git clone --branch fluentbit04  https://github.com/masatomix/spring-boot-sample-tomcat.git
$

よりダウンロードできます。前提の環境、セットアップ手順なども、いままでの記事と同じなので割愛します。

アプリチームが投げる例外について、フレームワークチームがExceptionHandlerを使って、適切なHTTPのResponse Statusに載せ替えて返す

まず一つ目。ログ出力の観点も含めて中身をちゃんと書くとこんな感じ。

  • アプリチームは 業務例外を投げるだけにしたい。そしてFW側がその例外を判定して、所定のHTTPステータスのエラーを呼び元に返却する。
  • アプリチームが業務例外を投げると自動でWARNログが出る、アプリのコード内でシステム例外が発生すると自動でERRORログが出る(で、監視が検知する)
    • ログ出力もFWにお任せすることで、業務例外はWARNなどのログ記録をしてもらい、システム例外はCloudWatch Alarmとかで検知してもらう、などとしたい

これらを実現する機構として、SpringBootにはREST API向けの共通レスポンス処理、エラー発生時の共通処理を行うためのAnnotation、「RestControllerAdvice/ExceptionHandler」があります。
具体的なコード(nu.mine.kino.advice.GlobalExceptionHandler)はこちら。

package nu.mine.kino.advice;

import org.slf4j.MDC;
import org.springframework.http.HttpStatus;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.ExceptionHandler;
import org.springframework.web.bind.annotation.RestControllerAdvice;

import lombok.extern.slf4j.Slf4j;
import nu.mine.kino.exceptions.ClientException;
import nu.mine.kino.exceptions.ServerException;
import nu.mine.kino.interceptor.MDCKey;

/**
 * アプリたち独自の例外を、HTTP Status付きのResposeへ載せ替えるHandler
 */
@RestControllerAdvice
@Slf4j
public class GlobalExceptionHandler {

    @ExceptionHandler(ClientException.class)
    public ResponseEntity<ErrorResponse> handleClientException(ClientException exception) {
        var body = new ErrorResponse("BAD_REQUEST", exception.getMessage());
        try {
            MDC.put(MDCKey.APP_TYPE.key(), "FW");
            log.warn(exception.getMessage(), exception);
            return ResponseEntity.status(HttpStatus.BAD_REQUEST).body(body);
        } finally {
            MDC.remove(MDCKey.APP_TYPE.key());
        }
    }

    @ExceptionHandler(ServerException.class)
    public ResponseEntity<ErrorResponse> handleServerException(ServerException exception) {
        var body = new ErrorResponse("SERVICE_UNAVAILABLE", exception.getMessage());
        try {
            MDC.put(MDCKey.APP_TYPE.key(), "FW");
            log.error(exception.getMessage(), exception);
            return ResponseEntity.status(HttpStatus.SERVICE_UNAVAILABLE).body(body);
        } finally {
            MDC.remove(MDCKey.APP_TYPE.key());
        }
    }

    // Lombok の @Value (Immutableな@Data)みたいなもん
    record ErrorResponse(String code, String message) {
    }
}

こんなふうにアプリたち(=Controllerとか)が所定の例外、上記だとClientException,ServerExceptionを投げたとき、所定の型 ErrorResponseのJSON にして返却する、などを例外クラスごとに記述できたりします1。

アプリが例外をスローすると、適切な型で返却される

アプリ達は業務ロジックでエラーが発生したときは業務例外をスローして終わりとできれば楽ですが ExceptionHandlerをつかうと実現できます。実際、

package nu.mine.kino.web;

import lombok.extern.slf4j.Slf4j;
.. 長いので省略

@RestController
@Slf4j
public class EchoController {

    @RequestMapping(value = "/clientException", method = RequestMethod.GET)
    public String clientExcetpion() throws ClientException {
        throw new ClientException("クライアント起因の例外が発生しました");
    }

    @RequestMapping(value = "/serverException", method = RequestMethod.GET)
    public String serverExcetpion() {
        throw new ServerException("サーバ起因の例外が発生しました");
    }
}

とするだけで、あとはFW(ExceptionHandlerのこと)が前回の記事のように

$ curl "http://localhost:8080/clientException" -i
HTTP/1.1 400
X-Request-Id: 6791e888-7a8c-4997-9924-67c3676eb51c
vary: accept-encoding
Content-Type: application/json
Transfer-Encoding: chunked
Date: Mon, 15 Sep 2025 13:36:38 GMT
Connection: close

{"code":"BAD_REQUEST","message":"クライアント起因の例外が発生しました"}
$

とステータスコードが400番で、レスポンスBodyにJSONデータを返却してくれます。ServerException の場合も、その例外に対応した処理が動くってことですね。

続いてMDCを使ったログ出力をまとめたいですが、そのまえにMDCのTIPSを。

MDCのKeyをenumに定義しておく

何度も出てくるMDCのキー値について、次のようなenumを定義しておきました。

package nu.mine.kino.interceptor;

public enum MDCKey {
    REQUEST_ID("requestId"),
    METHOD("method"),
    URI("uri"),
    DURATION("duration"),
    STATUS("status"),
    APP_TYPE("appType"),
    LOG_TYPE("logType");

    private final String key;

    MDCKey(String key) {
        this.key = key;
    }

    public String key() {
        return key;
    }
}

こうすることで、毎回キー値を打鍵しないでコード補完が効いてくれるのと、MDCをリセットするときに

for (MDCKey key : MDCKey.values()) {
    MDC.remove(key.key());
}

などと一度にremoveすることが可能です2。

適切なログの出力

ということでログ出力。FW(ExceptionHandler)がLoggerでログ出力していますが、その際MDCでMDC.put(MDCKey.APP_TYPE.key(), "FW"); とやって、appTypeプロパティ(FWが出しているログだよ、のフラグ)を設定しています。

また、業務例外(ClientException)時の処理は、呼び元起因のエラーなのでWARNなログを出力。実際、

$ curl "http://localhost:8080/clientException" -i
HTTP/1.1 400
X-Request-Id: f10660f8-e922-44fd-9306-eabf8b41eea0
...
Connection: close

{"code":"BAD_REQUEST","message":"クライアント起因の例外が発生しました"}
$

業務例外は下記のように WARNログがでていますね。

{
    "@timestamp": "2025-09-15T13:36:38.082494351Z",
    "@version": "1",
    "message": "クライアント起因の例外が発生しました",
    "logger_name": "nu.mine.kino.advice.GlobalExceptionHandler",
    "thread_name": "http-nio-8080-exec-1",
    "level": "WARN",   ← WARN！
    "level_value": 30000,
    "stack_trace": "略",
    "requestId": "6791e888-7a8c-4997-9924-67c3676eb51c",
    "appType": "FW"  ← こっちも出てる!
}

あとは基盤の Fluent Bitによって「これは検知しないただのログ」として処理 すればよさそうです。

一方システム例外(ServerException)時の処理は、呼び元起因のエラーではないので、なんらか障害かも？ということでERRORログを出力。実際、

$ curl "http://localhost:8080/serverException" -i
HTTP/1.1 503
X-Request-Id: 022ebc20-cacc-4cf5-84e4-a3b676075b91
...
Connection: close

{"code":"SERVICE_UNAVAILABLE","message":"サーバ起因の例外が発生しました"}
$

システム例外は下記の通りERRORログが出力されました。

{
 "@timestamp": "2025-09-17T15:32:11.275673406+09:00",
 "@version": "1",
 "message": "サーバ起因の例外が発生しました",
 "logger_name": "nu.mine.kino.advice.GlobalExceptionHandler",
 "thread_name": "http-nio-8080-exec-1",
 "level": "ERROR",   ← ERROR！
 "level_value": 40000,
 "stack_trace": "略",
 "requestId": "85beea65-e86b-480a-96c9-efaa2e1fe947",
 "appType": "FW"  ← 出てる!
}

こちらも、この先は Fluent Bitが「これは検知したいログ」としてrewrite_tagすればよさそうです。

参考:Fluent Bit編2。設定ファイルを読んでみる#rewrite_tag の処理

ログが出力されたあとの基盤の動きをまとめると、Fluent Bit では

  • "appType": "FW"かつ"level": "ERROR" なログは error-$container_idとかにrewrite_tagする
  • "appType": "FW"かつ"level": "WARN" なログは特になにもしない(ほかのログとおなじところにながれる)

とかをやらせれば良さそうです。実際は、この辺はログの設計次第ですが。

アプリでは自由にログ出力できるようにしつつ、Request/Responseのログは常にFWが別の場所へ出力してあげる。

さて次です。

アプリチームが意識しなくても、全てのリクエストに対して「Request/Responseログ」が別の場所にログ出力される、を実現したい件。

これについては、Springには全てのリクエストへ共通処理を追加など、リクエストをインターセプトするための仕組みとして「Interceptor」という機構が存在します。

nu.mine.kino.interceptor.MDCLoggingInterceptor をみてみるとこんな感じに、

  • preHandle: アプリチームの業務ロジックを呼び出す前、に動かしたい処理を書く箇所
  • afterCompletion:アプリチームの業務ロジック終了後、に動かしたい処理を書く箇所

みたいな仕組みになっています。

package nu.mine.kino.interceptor;

@Component
@Slf4j
public class MDCLoggingInterceptor implements HandlerInterceptor {

    @Override
    public boolean preHandle(HttpServletRequest request,
            HttpServletResponse response,
            Object handler) {
            ... リクエスト前にやりたい処理を書く(省略)
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request,
            HttpServletResponse response,
            Object handler,
            Exception ex) {
        try {        
            リクエスト後にやりたい処理を書く(省略)
        } finally {
            後始末処理を書く
        }
    }
}

省略の部分、もうすこし見てみましょう。

まずpreHandle。

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

        String requestId = UUID.randomUUID().toString(); // リクエストIDを生成
        long startTime = System.currentTimeMillis(); // リクエスト開始時間を記録
        requestIdThreadLocal.set(requestId);
        startTimeThreadLocal.set(startTime);

        // 全てのリクエストに出力したいプロパティはココで設定する。
        MDC.put(MDCKey.REQUEST_ID.key(), requestId);

        // レスポンスヘッダにも付けると呼び元でも追跡できる
        response.setHeader("X-Request-Id", requestId);
        return true;
    }

こちらはアプリチームの業務処理前に呼ばれる箇所なので、主に

  • リクエスト全体を通して使う「リクエストID」を払い出して、スレッドローカルな値に保存する
  • 「リクエスト開始日時」を記録し、スレッドローカルな値に保存する
  • リクエストIDはこのスレッドの全てのログに出力するつもりで、MDCに値を設定する
  • ついでにresponse.setHeader でリクエストIDを呼び元へのレスポンスヘッダにもセットしました

などをやっています。

続いて、afterCompletion。

    public void afterCompletion(HttpServletRequest request,
            HttpServletResponse response,
            Object handler,
            Exception ex) {

        try {
            // スレッドから値を取り出す
            String requestId = requestIdThreadLocal.get();
            long startTime = startTimeThreadLocal.get();
            
            String method = request.getMethod();
            String requestURI = request.getRequestURI();
            int status = response.getStatus();
            String statusStr = String.valueOf(status);

            // 開始時刻を取り出して処理時間を計算
            Long endTime = System.currentTimeMillis();
            long duration = endTime - startTime;
        
            String durationStr = String.valueOf(duration);

            // FWの出しているログだよ、ということを明示するフラグ
            MDC.put(MDCKey.APP_TYPE.key(), "FW");
            // Request/Responseを記録しているログだよ、ということを明示するフラグ
            MDC.put(MDCKey.LOG_TYPE.key(), "request_response");

            MDC.put(MDCKey.METHOD.key(), method);
            MDC.put(MDCKey.URI.key(), requestURI);
            MDC.put(MDCKey.DURATION.key(), durationStr);
            MDC.put(MDCKey.STATUS.key(), statusStr);
            log.info("FWログ出力");
        } finally {
            startTimeThreadLocal.remove();
            requestIdThreadLocal.remove();
            for (MDCKey key : MDCKey.values()) {
                MDC.remove(key.key());
            }
        }
    }
}

こちらは、アプリチームの業務処理が終了したあとに呼ばれる場所でしたね。ちなみにアプリが例外とかをスローした際にもちゃんと呼ばれるようになっています。

やっていることは、

  • リクエスト開始日時などをスレッドローカルの領域から取り出す
  • リクエスト開始/終了日時を使って、処理時間を算出(duration)
  • HTTP MethodやURI、レスポンスステータスとか、Request/Responseに関する情報を取得
  • 上記をもろもろMDCへ設定。上記のほかに、
    • FWが出力したことを示す "appType": "FW",
    • Request/Response用のログである事を示す"logType": "request_response" 
// FWの出しているログだよ、ということを明示するフラグ
MDC.put(MDCKey.APP_TYPE.key(), "FW");
// Request/Responseを記録しているログだよ、ということを明示するフラグ
MDC.put(MDCKey.LOG_TYPE.key(), "request_response");

などを設定。

  • 最後に log.info でログ出力
  • finallyで、スレッドローカルな値の消去、MDCの値の消去

などをおこなっています。

補足 Interceptorは登録が必要

ちなみに先ほどのInterceptorは登録が必要で nu.mine.kino.config.WebConfig というConfigurationクラスを作成し3

package nu.mine.kino.config;

import org.springframework.context.annotation.Configuration;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;

import lombok.AllArgsConstructor;
import nu.mine.kino.interceptor.MDCLoggingInterceptor;

@Configuration
@AllArgsConstructor
public class WebConfig implements WebMvcConfigurer {
    private final MDCLoggingInterceptor loggingInterceptor;

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(loggingInterceptor);
                // .addPathPatterns("/**");
    }
}

この中で該当するInterceptorクラスをレジストリに登録する必要があるようです。

実際にやってみる

SpringBootアプリを起動し、リクエストしてみます。

$ curl "http://localhost:8080/echoLogger" -i
HTTP/1.1 200
X-Request-Id: af637b24-972b-4c29-addc-47b84845fc65  ← ココ！
vary: accept-encoding
Content-Type: text/plain;charset=UTF-8
Content-Length: 16
Date: Wed, 17 Sep 2025 07:28:00 GMT

Default Message.
$

レスポンスヘッダに「X-Request-Id」とその値がセットされていますね！

ログは

[
  {
    "@timestamp": "2025-09-17T16:28:00.113429426+09:00",
    "@version": "1",
    "message": "Default Message.",
    "logger_name": "nu.mine.kino.web.EchoController",
    "thread_name": "http-nio-8080-exec-2",
    "level": "INFO",
    "level_value": 20000,
    "requestId": "af637b24-972b-4c29-addc-47b84845fc65"
  },
  {
    "@timestamp": "2025-09-17T16:28:00.116423614+09:00",
    "@version": "1",
    "message": "FWログ出力",
    "logger_name": "nu.mine.kino.interceptor.MDCLoggingInterceptor",
    "thread_name": "http-nio-8080-exec-2",
    "level": "INFO",
    "level_value": 20000,
    "logType": "request_response",
    "duration": "4",
    "method": "GET",
    "requestId": "af637b24-972b-4c29-addc-47b84845fc65",
    "appType": "FW",
    "uri": "/echoLogger",
    "status": "200"
  }
]

2行出ていますね。どちらにも requestId として先ほどのレスポンスヘッダの値と同じ値が出力されています。

ログのまず1行目は、アプリチームが普通(？)に出力したログ。

  {
    "@timestamp": "2025-09-17T16:28:00.113429426+09:00",
    "@version": "1",
    "message": "Default Message.",
    "logger_name": "nu.mine.kino.web.EchoController",
    "thread_name": "http-nio-8080-exec-2",
    "level": "INFO",
    "level_value": 20000,
    "requestId": "af637b24-972b-4c29-addc-47b84845fc65"
  }

特殊な値は特段されておらず、全ログに出力するつもりでpreHandle上でMDCにセットしたrequestIdのみ、自動で付与されていますね。

2行目はFW (Interceptorのこと) が出力したログで、

  {
    "@timestamp": "2025-09-17T16:28:00.116423614+09:00",
    "@version": "1",
    "message": "FWログ出力",
    "logger_name": "nu.mine.kino.interceptor.MDCLoggingInterceptor",
    "thread_name": "http-nio-8080-exec-2",
    "level": "INFO",
    "level_value": 20000,
    "logType": "request_response",
    "duration": "4",
    "method": "GET",
    "requestId": "af637b24-972b-4c29-addc-47b84845fc65",
    "appType": "FW",
    "uri": "/echoLogger",
    "status": "200"
  }

たしかにrequestIdはもちろん、

  • FWが出力したことを示す "appType": "FW",

  • Request/Response用のログである事を示す"logType": "request_response"

が付与されています。さらに、

"duration": "4",
"method": "GET",
"requestId": "af637b24-972b-4c29-addc-47b84845fc65",
"uri": "/echoLogger",
"status": "200"

などリクエスト・レスポンスに関する情報が付与されています。

「アプリのログ」か「FWのログ」かを見分けるフラグもあるし、普通のログ、Request/Response用のログ、などを見分けるフラグもセットできました。

イイ感じですね。

TIPS

ネストしていないけど？

Request/Responseの情報は

MDC.put(MDCKey.METHOD.key(), method);
MDC.put(MDCKey.URI.key(), requestURI);
MDC.put(MDCKey.DURATION.key(), durationStr);
MDC.put(MDCKey.STATUS.key(), statusStr);

とかやることで

"duration": "4",
"method": "GET",
"uri": "/echoLogger",
"status": "200"

とログ出力されましたが、RequestごとResponseごとでまとまった出力にしたいですよね。が、どうもMDCでは、ネスト構造のデータを出力できないようで(調べたけど分からなかった)、その場合は MDCではなく、net.logstash.logback.argument.StructuredArguments.keyValueってのを使います。

そこだけ抜粋すると、

 // MDC.put(MDCKey.METHOD.key(), method);
 // MDC.put(MDCKey.URI.key(), requestURI);
 // MDC.put(MDCKey.DURATION.key(), durationStr);
 // MDC.put(MDCKey.STATUS.key(), statusStr);
 // log.info("FWログ出力");
 // MDCはコメントアウトした
 
 Map<String, Object> requestMap = Map.of(
         MDCKey.METHOD.key(), method,
         MDCKey.URI.key(), requestURI
 //
 );
 Map<String, Object> responseMap = Map.of(
         MDCKey.DURATION.key(), durationStr,
         MDCKey.STATUS.key(), statusStr
 //
 );
 log.info("FWログ出力", keyValue("request", requestMap), keyValue("response",
         responseMap));

ってMapを作って log.info などに渡してあげればOKな模様。

出力結果は、

{
  "@timestamp": "2025-09-17T17:31:13.268688297+09:00",
  "@version": "1",
  "message": "FWログ出力",
  "logger_name": "nu.mine.kino.interceptor.MDCLoggingInterceptor",
  "thread_name": "http-nio-8080-exec-1",
  "level": "INFO",
  "level_value": 20000,
  "logType": "request_response",
  "requestId": "c19a1192-d090-4da7-ae86-26e12976f484",
  "appType": "FW",
  "request": {
    "uri": "/echoLogger",
    "method": "GET"
  },
  "response": {
    "duration": "18",
    "status": "200"
  }
}

となりました！なんだかよさげなログになりました。

preHandle、afterCompletionともrequest/responseを引数にとるので、上り電文のその他データ(リクエストパラメタ、Body、リクエストヘッダなど)はrequestから、下り電文のその他データ(レスポンスヘッダ、リクエストBodyなど)はresponse から取得してログにセットすればよさそうです。

OncePerRequestFilter の方がいいかも

ここまで書いてですが、どうも afterCompletion は、DispatcherServlet (SpringBoot のControllerみたい) まで処理が到達しなかったばあいに処理が発動しないようで、その辺を踏まえると、ググったところServletFilterで実装した方が良さそうな雰囲気。

下記にサンプルをのせておきました。下記のコードでは

  • スレッドを通して全ログに出力したいプロパティはMDCを使う(requestIdとかね)
  • それ以外のプロパティは StructuredArguments を使う
  • 万一のため、Requestを受けた時点のログも出力

と処理を整理してみました。

package nu.mine.kino.filter;

import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.Map;
import java.util.UUID;
import lombok.extern.slf4j.Slf4j;
import nu.mine.kino.interceptor.MDCKey;

import org.slf4j.MDC;
import org.springframework.stereotype.Component;
import org.springframework.web.filter.OncePerRequestFilter;

import static net.logstash.logback.argument.StructuredArguments.keyValue;

@Component
@Slf4j
public class RequestLoggingFilter extends OncePerRequestFilter {

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

        String requestId = UUID.randomUUID().toString(); // リクエストIDを生成
        long startTime = System.currentTimeMillis(); // リクエスト開始時間を記録

        // 全てのリクエストに出力したいプロパティはココで設定する。
        MDC.put(MDCKey.REQUEST_ID.key(), requestId);

        // レスポンスヘッダにも付けると呼び元でも追跡できる
        response.setHeader("X-Request-Id", requestId);

        String method = request.getMethod();
        String requestURI = request.getRequestURI();

        Map<String, Object> requestMap = Map.of(
                MDCKey.METHOD.key(), method,
                MDCKey.URI.key(), requestURI
        //
        );
        log.info("FWログ出力(Request)",
                keyValue("request", requestMap),
                keyValue(MDCKey.APP_TYPE.key(), "FW"), // FWの出しているログだよ、ということを明示するフラグ
                keyValue(MDCKey.LOG_TYPE.key(), "request_response"));// Request/Responseを記録しているログだよ、ということを明示するフラグ

        try {
            // 後続処理へ
            filterChain.doFilter(request, response);

        } finally {
            try {
                int status = response.getStatus();
                String statusStr = String.valueOf(status);

                // 開始時刻を取り出して処理時間を計算
                Long endTime = System.currentTimeMillis();
                long duration = endTime - startTime;

                String durationStr = String.valueOf(duration);

                Map<String, Object> responseMap = Map.of(
                        MDCKey.DURATION.key(), durationStr,
                        MDCKey.STATUS.key(), statusStr
                //
                );
                log.info("FWログ出力(Request/Response)",
                        keyValue("request", requestMap),
                        keyValue("response", responseMap),
                        keyValue(MDCKey.APP_TYPE.key(), "FW"), // FWの出しているログだよ、ということを明示するフラグ
                        keyValue(MDCKey.LOG_TYPE.key(), "request_response")// Request/Responseを記録しているログだよ、ということを明示するフラグ
                );
            } finally {
                // 後始末
                for (MDCKey key : MDCKey.values()) {
                    MDC.remove(key.key());
                }
            }
        }
    }
}

動かしてみると、、4

$ curl "http://localhost:8080/echoLogger" -i
HTTP/1.1 200
X-Request-Id: 08555e6f-01d6-4d17-9eeb-8f58977190ad
...

Default Message.
$

ログは

[
  {
    "@timestamp": "2025-09-18T18:16:07.67127238+09:00",
    "@version": "1",
    "message": "FWログ出力(Request)",
    "logger_name": "nu.mine.kino.filter.RequestLoggingFilter",
    "thread_name": "http-nio-8080-exec-1",
    "level": "INFO",
    "level_value": 20000,
    "requestId": "08555e6f-01d6-4d17-9eeb-8f58977190ad",
    "request": { "method": "GET", "uri": "/echoLogger" },
    "appType": "FW",
    "logType": "request_response"
  },
  {
    "@timestamp": "2025-09-18T18:16:07.763322373+09:00",
    "@version": "1",
    "message": "Default Message.",
    "logger_name": "nu.mine.kino.web.EchoController",
    "thread_name": "http-nio-8080-exec-1",
    "level": "INFO",
    "level_value": 20000,
    "requestId": "08555e6f-01d6-4d17-9eeb-8f58977190ad"
  },
  {
    "@timestamp": "2025-09-18T18:16:07.787382068+09:00",
    "@version": "1",
    "message": "FWログ出力(Request/Response)",
    "logger_name": "nu.mine.kino.filter.RequestLoggingFilter",
    "thread_name": "http-nio-8080-exec-1",
    "level": "INFO",
    "level_value": 20000,
    "requestId": "08555e6f-01d6-4d17-9eeb-8f58977190ad",
    "request": { "method": "GET", "uri": "/echoLogger" },
    "response": { "duration": "126", "status": "200" },
    "appType": "FW",
    "logType": "request_response"
  }
]

良さそうですね。

Fluent Bit側ではどうする

さてFluent Bitで上記のログたちを適切な場所に転送したいのですが、また別の記事にします。

まとめ

  • ExceptionHandlerを使うことで アプリチームは所定の例外を投げさえすれば、FWチームがHTTPステータスのセットやレスポンスBodyの作成、ログ出力などをやってくれる なんて仕組みを作れることが分かりました
  • InterceptorやServlet Filterを使うことで、アプリチームもLoggerを自由につかえるし、Request/ResponseのログはFWが別の場所へ出力してあげるなんて仕組みを作れることが分かりました
  • ちなみに、ログ出力時のMDC とStructuredArguments は、下記の使い分けがよさそうです
    • スレッドを通して全ログに出力したいプロパティはMDCを使う(requestIdとかね)
    • それ以外のプロパティは StructuredArguments を使う

次回は、途中で出てきたFluent Bitによる振り分けについて。お疲れさまでした！

関連リンク

  1. ResponseEntity<ErrorResponse>を返す事で、ErrorResponse(code,messageプロパティをもつJSON) を返すようになります。ステータスコードもResponseEntityに設定しています。 ↩

  2. 一応ですが、MDC.clear() メソッドで一律クリアも可能です。 ↩

  3. src/main/java/nu/mine/kino/より下(？)の階層におくことに注意 ↩

  4. Interceptorが動いていると、MDC.removeが動いてしまうので、WebConfig.java の処理をコメントアウトしておきましょう。 ↩

1
0
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
1
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?