SpringBoot2でリクエスト情報をログに出力する方法【Filter】

リクエストログを出力しよう

サーバーのログ解析をする場合、どんなリクエストが飛んできた際のログなのか？という情報が重要になってきます。

自前でインターセプターなどを使って実装しても良いのですが、SpringBootを使っていれば簡単に実現が可能です。

手順

CommonsRequestLoggingFilterをBean登録

やり方は簡単です。

まずは@Configurationがついているコンフィグクラスにて、以下のように@Bean定義を行いましょう。

XRequestIdFilterConfig

package tech.blogenist.service.account.api.infrastructure.filter.x_request_id;

import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.filter.CommonsRequestLoggingFilter;

@Configuration
public class XRequestIdFilterConfig
{
...
    @Bean
    public CommonsRequestLoggingFilter requestLoggingFilter()
    {
        CommonsRequestLoggingFilter filter = new CommonsRequestLoggingFilter();
        filter.setIncludeClientInfo( true );
        filter.setIncludeQueryString( true );
        filter.setIncludeHeaders( true );
        filter.setIncludePayload( true );
        return filter;
    }
...
}

次に、application.ymlにて、以下の設定を追加しましょう。

CommonsRequestLoggingFilterでは、DEBUGレベルで出力しているので、出力対象にする必要があります。

application.yml

logging:
  level:
    org:
      springframework:
        web:
          filter:
            CommonsRequestLoggingFilter: DEBUG

確認

GETの場合

では、実際にGETリクエストを投げてみましょう。

リクエスト

curl  -v -X GET   \
  -H 'Content-Type: application/json' \
  -H 'hoge: fuga' \
  'http://localhost:8080/v1/accounts/10001/?query=blogenist'

サーバーログ

{
   "timestamp":"2019-05-05T00:00:56.006+09:00",
   "level":"DEBUG",
   "thread":"http-nio-8080-exec-5",
   "mdc":{"x-request-id":"4169a153-e26c-4275-a4d4-8391d5183e66"},
   "logger":"org.springframework.web.filter.CommonsRequestLoggingFilter",
   "message":"Before request [
    uri=/v1/accounts/10001/?query=blogenist;client=0:0:0:0:0:0:0:1;headers=[
      host:\"localhost:8080\",
      user-agent:\"curl/7.64.0\",
      accept:\"*/*\",
      hoge:\"fuga\",
      Content-Type:\"application/json;charset=UTF-8\"
    ]
  ]"
}{
   "timestamp":"2019-05-05T00:00:56.020+09:00",
   "level":"DEBUG",
   "thread":"http-nio-8080-exec-5",
   "mdc":{"x-request-id":"4169a153-e26c-4275-a4d4-8391d5183e66"},
   "logger":"org.springframework.web.filter.CommonsRequestLoggingFilter",
   "message":"After request [
    uri=/v1/accounts/10001/?query=blogenist;client=0:0:0:0:0:0:0:1;headers=[
      host:\"localhost:8080\",
      user-agent:\"curl/7.64.0\",
      accept:\"*/*\",
      hoge:\"fuga\",
      Content-Type:\"application/json;charset=UTF-8\"
    ]
  ]"
}

POSTの場合

次に、POSTリクエストを投げてみましょう。

リクエスト

curl  -v -X POST   \
  -H 'Content-Type: application/json' \
  -H 'hoge: fuga' \
  -d '{"fizz": "bazz"}' \
  'http://localhost:8080/v1/accounts/'

サーバーログ

{
   "timestamp":"2019-05-04T23:48:17.008+09:00",
   "level":"DEBUG",
   "thread":"http-nio-8080-exec-7",
   "mdc":{"x-request-id":"9d1bb6cb-0a2b-45f9-957c-d5e1c027b160"},
   "logger":"org.springframework.web.filter.CommonsRequestLoggingFilter",
   "message":"Before request [
      uri=/v1/accounts/;client=0:0:0:0:0:0:0:1;headers=[
        host:\"localhost:8080\",
        user-agent:\"curl/7.64.0\",
        accept:\"*/*\", hoge:\"fuga\",
        content-length:\"16\",
        Content-Type:\"application/json;
        charset=UTF-8\"
     ]
   ]"
}
{
   "timestamp":"2019-05-04T23:48:17.010+09:00",
   "level":"DEBUG",
   "thread":"http-nio-8080-exec-7",
   "mdc":{"x-request-id":"9d1bb6cb-0a2b-45f9-957c-d5e1c027b160"},
   "logger":"org.springframework.web.filter.CommonsRequestLoggingFilter",
   "message":"After request [
    uri=/v1/accounts/;client=0:0:0:0:0:0:0:1;headers=[
      host:\"localhost:8080\",
        user-agent:\"curl/7.64.0\",
        accept:\"*/*\", hoge:\"fuga\",
        content-length:\"16\",
        Content-Type:\"application/json;
        charset=UTF-8\"
      ];payload={
        \"fizz\":\"bazz\"
      }
    ]"
}

正常にリクエスト内容が出力されていますね♪

ちなみに、Payload(リクエストボディ)はBefore RequestではなくAfter Requestのみ出力されるので気をつけてください。

終わりに

以上のように、簡単にリクエスト情報をログに出力する事が出来ました。

運用が始まってからでは遅いので、初期開発時に忘れないように設定しておきましょう。