1. 概要

このチュートリアルでは、効率的なRestTemplate要求/応答ロギングを実装する方法を学習します。 これは、2台のサーバー間の交換をデバッグする場合に特に便利です。

残念ながら、Spring Bootは、単純なJSON応答本文を検査またはログに記録する簡単な方法を提供していません。

HTTPヘッダー、または最も興味深い部分であるHTTPボディのいずれかをログに記録するためのいくつかの方法を検討します。

:Spring RestTemplate は非推奨になり、WebClientに置き換えられます。 WebClient を使用した同様の記事は、 Logging Spring WebClientCallsにあります。

2. RestTemplateを使用した基本的なロギング

application.propertiesファイルでRestTemplateロガーの構成を開始しましょう。

logging.level.org.springframework.web.client.RestTemplate=DEBUG

その結果、リクエストURL、メソッド、本文、レスポンスステータスなどの基本情報のみを表示できます。

o.s.w.c.RestTemplate - HTTP POST http://localhost:8082/spring-rest/persons
o.s.w.c.RestTemplate - Accept=[text/plain, application/json, application/*+json, */*]
o.s.w.c.RestTemplate - Writing [my request body] with org.springframework.http.converter.StringHttpMessageConverter
o.s.w.c.RestTemplate - Response 200 OK

ただし、応答本文はここに記録されません。これは、最も興味深い部分であるため、残念です。

これを解決するために、ApacheHttpClientまたはSpringインターセプターのいずれかを選択します。

3. ApacheHttpClientを使用したヘッダー/ボディのロギング

まず、RestTemplateApacheHttpClient実装を使用させる必要があります。

Maven依存関係が必要です。

<dependency>
    <groupId>org.apache.httpcomponents</groupId>
    <artifactId>httpclient</artifactId>
    <version>4.5.12</version>
</dependency>

RestTemplate インスタンスを作成するとき、 ApacheHttpClientを使用していることを通知する必要があります。

RestTemplate restTemplate = new RestTemplate();
restTemplate.setRequestFactory(new HttpComponentsClientHttpRequestFactory());

次に、application.propertiesファイルでクライアントロガーを構成しましょう。

logging.level.org.apache.http=DEBUG
logging.level.httpclient.wire=DEBUG

これで、要求/応答ヘッダーと本文の両方を確認できます。

    o.a.http.headers - http-outgoing-0 >> POST /spring-rest/persons HTTP/1.1
    o.a.http.headers - http-outgoing-0 >> Accept: text/plain, application/json, application/*+json, */*
// ... more request headers
    o.a.http.headers - http-outgoing-0 >> User-Agent: Apache-HttpClient/4.5.9 (Java/1.8.0_171)
    o.a.http.headers - http-outgoing-0 >> Accept-Encoding: gzip,deflate
org.apache.http.wire - http-outgoing-0 >> "POST /spring-rest/persons HTTP/1.1[\r][\n]"
org.apache.http.wire - http-outgoing-0 >> "Accept: text/plain, application/json, application/*+json, */*[\r][\n]"
org.apache.http.wire - http-outgoing-0 >> "Content-Type: text/plain;charset=ISO-8859-1[\r][\n]"
// ... more request headers
org.apache.http.wire - http-outgoing-0 >> "[\r][\n]"
org.apache.http.wire - http-outgoing-0 >> "my request body"
org.apache.http.wire - http-outgoing-0 << "HTTP/1.1 200 [\r][\n]"
org.apache.http.wire - http-outgoing-0 << "Content-Type: application/json[\r][\n]"
// ... more response headers
org.apache.http.wire - http-outgoing-0 << "Connection: keep-alive[\r][\n]"
org.apache.http.wire - http-outgoing-0 << "[\r][\n]"
org.apache.http.wire - http-outgoing-0 << "21[\r][\n]"
org.apache.http.wire - http-outgoing-0 << "["Lucie","Jackie","Danesh","Tao"][\r][\n]"

ただし、これらのログは冗長であり、デバッグには便利ではありません

これを解決する方法については、次の章で説明します。

4. RestTemplateインターセプターを使用したロギングボディ

別の解決策として、RestTemplateインターセプターを構成できます。

4.1. ロギングインターセプターの実装

まず、新しいLoggingInterceptorを作成して、ログをカスタマイズしましょう。 このインターセプターは、要求の本文を単純なバイト配列としてログに記録します。 ただし、応答については、ボディストリーム全体を読み取る必要があります。

public class LoggingInterceptor implements ClientHttpRequestInterceptor {

    static Logger LOGGER = LoggerFactory.getLogger(LoggingInterceptor.class);

    @Override
    public ClientHttpResponse intercept(
      HttpRequest req, byte[] reqBody, ClientHttpRequestExecution ex) throws IOException {
        LOGGER.debug("Request body: {}", new String(reqBody, StandardCharsets.UTF_8));
        ClientHttpResponse response = ex.execute(req, reqBody);
        InputStreamReader isr = new InputStreamReader(
          response.getBody(), StandardCharsets.UTF_8);
        String body = new BufferedReader(isr).lines()
            .collect(Collectors.joining("\n"));
        LOGGER.debug("Response body: {}", body);
        return response;
    }
}

次の章で説明するように、このインターセプターは応答コンテンツ自体に影響を与えることに注意してください。

4.2. RestTemplateでインターセプターを使用する

ここで、ストリーミングの問題に対処する必要があります。インターセプターが応答ストリームを消費すると、クライアントアプリケーションには空の応答本文が表示されます。

これを回避するには、BufferingClientHttpRequestFactoryを使用する必要があります。これはストリームコンテンツをメモリにバッファリングします。 このようにして、2回読み取ることができます。1回目はインターセプターで、2回目はクライアントアプリケーションで読み取ります。

ClientHttpRequestFactory factory = 
        new BufferingClientHttpRequestFactory(new SimpleClientHttpRequestFactory());
        RestTemplate restTemplate = new RestTemplate(factory);

ただし、このファクトリを使用すると、パフォーマンス上の欠点が発生します。これについては次のサブセクションで説明します。

次に、ロギングインターセプターを RestTemplate インスタンスに追加できます。既存のインターセプターがある場合は、その後に追加します。

List<ClientHttpRequestInterceptor> interceptors = restTemplate.getInterceptors();
if (CollectionUtils.isEmpty(interceptors)) {
    interceptors = new ArrayList<>();
}
interceptors.add(new LoggingInterceptor());
restTemplate.setInterceptors(interceptors);

その結果、必要な情報のみがログに表示されます。

c.b.r.l.LoggingInterceptor - Request body: my request body
c.b.r.l.LoggingInterceptor - Response body: ["Lucie","Jackie","Danesh","Tao"]

4.3. RestTemplateインターセプターの欠点

前述のように、 BufferingClientHttpRequestFactory を使用すると、ストリーミングのメリットが失われるという重大な欠点があります。 結果として、 ボディデータ全体をメモリにロードすると、アプリケーションがパフォーマンスの問題にさらされる可能性があります。 さらに悪いことに、OutOfMemoryErrorにつながる可能性があります

これを防ぐための1つの可能なオプションは、データボリュームがスケールアップしたときにこれらの冗長ログがオフになると想定することです。これは通常、本番環境で発生します。 たとえば、ロガーでDEBUGレベルが有効になっている場合にのみバッファリングされたRestTemplateインスタンスを使用できます

RestTemplate restTemplate = null;
if (LOGGER.isDebugEnabled()) {
    ClientHttpRequestFactory factory 
    = new BufferingClientHttpRequestFactory(new SimpleClientHttpRequestFactory());
    restTemplate = new RestTemplate(factory);
} else {
    restTemplate = new RestTemplate();
}

同様に、 DEBUGロギングが有効になっている場合にのみインターセプターが応答を読み取るようにします

if (LOGGER.isDebugEnabled()) {
    InputStreamReader isr = new InputStreamReader(response.getBody(), StandardCharsets.UTF_8);
    String body = new BufferedReader(isr)
        .lines()
        .collect(Collectors.joining("\n"));
    LOGGER.debug("Response body: {}", body);
}

5. 結論

RestTemplate の要求/応答ログは、Spring Bootにすぐに含まれていないため、簡単なことではありません。

幸い、 Apache HttpClientロガーを使用して、交換されたデータの詳細なトレースを取得できることがわかりました。

または、カスタムインターセプターを実装して、より人間が読める形式のログを取得することもできます。 ただし、これにより、大量のデータのパフォーマンスが低下する可能性があります。

いつものように、この記事のソースコードは、GitHubtestフォルダーにあるから入手できます。 この例では、同じプロジェクトで定義されたRESTエンドポイントのライブテストでRestTemplateを使用しています。