RestTemplateの通信ログの残し方

## はじめに
マイクロサービスなどで特にそうだと思いますが、他のアプリとの通信ログは残すべきとされています。

しかし、良い感じの実装をフレームワークが提供してくれているとは限らないので、みなさんググるなりご自身で考えたりしていると思います。

実際、私もSpringで実現する方法についてまずググりました。

その結果を総合して（弊社のプロダクトには）こうしたほうが良いと思ったやり方が他の方の参考にもなると思ったためQiitaに残しておきます。

## 要件
- resttemplateを使った通信内容をリクエスト・レスポンスともにログに出力する
    - ローカル含む開発環境ではpayloadもログに出したい
    - しかし、本番ではパフォーマンスやメモリ消費量の問題があるためpayloadは出力したくない
        - 秘匿が必要な情報が含まれている可能性もありフォーマット毎に正しく秘匿する制御はそれなりに大変なので、その工数が避けないならいっそ全部出さないほうがいい（はず）
- headerには秘匿が必要な情報が含まれている可能性があるため、一部のheaderは出力時に秘匿したい。
    - 主には`Authorization`を想定しているが、それ以外にも多々あるはず。
    - 全部秘匿してしまうと中身が識別できなくなるため、前後数文字ずつオリジナルの文字列を残したいので設定可能とする。

## サンプルコードと解説
### サンプルアプリ
- [resttemplate-logging-java-sample](https://github.com/kogayushi/resttemplate-logging-java-sample)

### 前置き
- 掲載するコードは前述のサンプルアプリからの抜粋です。
- 実装が楽になるので、lombokを使っています。
- getter/setterやfull constructorをlombokに生成させているので脳内補完してください

### `ClientHttpRequestInterceptor`を実装して、ログを出力する

```java
package resttemplatelogging.javaexample;

import static java.util.stream.Collectors.toList;
import static java.util.stream.Collectors.toMap;

import lombok.RequiredArgsConstructor;
import lombok.extern.slf4j.Slf4j;
import org.springframework.http.HttpHeaders;
import org.springframework.http.HttpRequest;
import org.springframework.http.HttpStatus;
import org.springframework.http.client.ClientHttpRequestExecution;
import org.springframework.http.client.ClientHttpRequestInterceptor;
import org.springframework.http.client.ClientHttpResponse;
import org.springframework.stereotype.Component;
import org.springframework.util.StreamUtils;

import java.io.BufferedReader;
import java.io.ByteArrayInputStream;
import java.io.IOException;
import java.io.InputStream;
import java.io.InputStreamReader;
import java.nio.charset.StandardCharsets;
import java.util.List;
import java.util.Map;

@Component
@RequiredArgsConstructor
@Slf4j
public class RestTemplateLoggingInterceptor implements ClientHttpRequestInterceptor {

    private final RestTemplateProperties restTemplateProperties;

    public ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution) throws IOException {
        this.logRequest(request, body);
        ClientHttpResponse response = execution.execute(request, body);
        if (restTemplateProperties.shouldIncludePayload()) { // 設定でpayloadを出力するとなっていた場合のみ出力する
            BufferingClientHttpResponseWrapper wrappedResponse = new BufferingClientHttpResponseWrapper(response);
            this.logResponse(wrappedResponse);
            return wrappedResponse;
        }
        this.logResponse(response);
        return response;
    }

    private void logRequest(HttpRequest request, byte[] body) {
        Map<String, List<String>> maskedHeader = maskedHeaders(request.getHeaders()); // header情報の一部を秘匿する
        String responseBody = buildRequestBody(body);
        log.info("[API:Request] Request=[{}:{}], Headers=[{}], Body=[{}]",
                 request.getMethod(),
                 request.getURI(),
                 maskedHeader,
                 responseBody);
    }

    private String buildRequestBody(byte[] body) {
        return restTemplateProperties.shouldIncludePayload() ? new String(body, StandardCharsets.UTF_8) : "omitted request body";
    }

    // BufferingClientHttpResponseWrapperが渡された場合、payloadを出力すると判断する。この分岐をオーバーロードで表現している。
    private void logResponse(BufferingClientHttpResponseWrapper response) throws IOException {
        String responseBody = this.buildResponseBody(response); // responseのpayloadを取得する
        logResponse(response, responseBody);
    }

    private String buildResponseBody(ClientHttpResponse response) throws IOException {
        StringBuilder inputStringBuilder = new StringBuilder();

        // 入力ストリームを開くのでtry with resource文で確実にcloseする
        try (BufferedReader bufferedReader = new BufferedReader(new InputStreamReader(response.getBody(), StandardCharsets.UTF_8))) {
            String line = bufferedReader.readLine();
            while (line != null) {
                inputStringBuilder.append(line);
                line = bufferedReader.readLine();
                if (line != null) {
                    inputStringBuilder.append('\n');
                }
            }
        } catch (Exception ex) {
            String msg = "Something went wrong during reading response body";
            log.error(msg, ex);
            throw ex;
        }
        return inputStringBuilder.toString();
    }

    // ClientHttpResponseが渡された場合、payloadを出力しないと判断する。この分岐をオーバーロードで表現している。
    private void logResponse(ClientHttpResponse response) throws IOException {
        String responseBody = "omitted response body"; // payloadを出力しないので代替テキストをハードコード
        logResponse(response, responseBody);
    }

    private void logResponse(ClientHttpResponse response, String responseBody) throws IOException {
        Map<String, List<String>> maskedHeader = maskedHeaders(response.getHeaders()); // headerを秘匿する
        log.info("[API:Response] Status=[{}:{}], Headers=[{}], Body=[{}]",
                 response.getStatusCode().value(),
                 response.getStatusText(),
                 maskedHeader,
                 responseBody);
    }

    private Map<String, List<String>> maskedHeaders(HttpHeaders headers) {
        return headers.entrySet()
                      .stream()
                      .collect(toMap(Map.Entry::getKey, it -> maskedIfNeed(it.getKey(), it.getValue()) /* 指定されたheaderのみ秘匿する */));
    }

    private List<String> maskedIfNeed(String headerName, List<String> headers) {
        // 秘匿が必要かどうか判断する
        if (shouldMask(headerName)) {
            // 何文字オリジナルの文字列を残すかを取得する
            int lengthRetained = restTemplateProperties.lengthRetainingOf(headerName);
            return headers.stream()
                          .map(header -> masked(header, lengthRetained)) // オリジナルの文字列を一部残しつつ、秘匿する
                          .collect(toList());
        }
        // 秘匿が不要ならオリジナルをそのまま返す
        return headers;
    }

    private boolean shouldMask(String headerName) {
        // 秘匿対象と設定されたheaderかどうかチェックする
        return restTemplateProperties.getMaskingKeywords()
                                     .stream()
                                     .anyMatch(headerNeededToBeMasked -> headerNeededToBeMasked.isSameWith(headerName));
    }

    private String masked(String header, int lengthRetained) {
        String maskedString = "<<***masked***>>"; // 秘匿する際の代替テキスト。秘匿されたとわかる表現になっていれば何でも良い。
        int lengthEnoughToBeMasked = lengthRetained * 2 + 1;
        if (header.length() > lengthEnoughToBeMasked) { // 秘匿時に残す文字数がオリジナルの文字数を超えるとオリジナルの文字列がそのまま出力されてしまうので、そうなっていないかチェックする
            return String.format("%s%s%s",
                                 header.substring(0, lengthRetained),
                                 maskedString,
                                 header.substring(header.length() - lengthRetained));
        }
        // 秘匿時に残す文字数がオリジナルの文字数を超えていた場合は、秘匿用の代替テキストをそのまま帰す
        return maskedString;
    }

    // org.springframework.http.client.BufferingClientHttpResponseWrapperをコピー
    private static class BufferingClientHttpResponseWrapper implements ClientHttpResponse {
        private byte[] body;
        private final ClientHttpResponse response;


        public HttpStatus getStatusCode() throws IOException {
            return this.response.getStatusCode();
        }

        public int getRawStatusCode() throws IOException {
            return this.response.getRawStatusCode();
        }

        public String getStatusText() throws IOException {
            return this.response.getStatusText();
        }

        public HttpHeaders getHeaders() {
            return this.response.getHeaders();
        }

        public InputStream getBody() throws IOException {
            if (this.body == null) {
                this.body = StreamUtils.copyToByteArray(this.response.getBody());
            }

            return new ByteArrayInputStream(this.body);
        }

        public void close() {
            this.response.close();
        }

        public BufferingClientHttpResponseWrapper(ClientHttpResponse response) {
            this.response = response;
        }
    }
}
```

### 設定を取得するための`ConfigurationProperties`なクラスを用意する
- だたの設定保持用のクラスではありますが、使いやすくするためにヘルパーメソッドを生やしています。
  - OOP的な発想です。

```java
package resttemplatelogging.javaexample;

import lombok.Data;
import org.springframework.boot.context.properties.ConfigurationProperties;
import org.springframework.stereotype.Component;
import org.springframework.validation.annotation.Validated;

import javax.validation.constraints.Min;
import javax.validation.constraints.NotNull;
import java.util.Collections;
import java.util.List;

@Data
@Validated // 正しく設定されていない場合はアプリを起動させたくないので、`@Validated`を付与する
@Component
@ConfigurationProperties(prefix = "resttemplate.logging")
public class RestTemplateProperties {

    private boolean shouldIncludePayload = false; // requestとresponseのpayloadのログ出力有無を設定可能にする。

    private List<MaskingHeader> maskingHeaders = Collections.emptyList();

    // lombokが生やすboolean用のgetterは可読性が悪いので自分で定義する
    public boolean shouldIncludePayload() {
        return this.shouldIncludePayload;
    }

    // 設定用のクラスかもしれないが、クライアントコードから使いやすくなるようにヘルパーメソッドを生やす。
    public int lengthRetainingOf(String keyword) {
        return this.maskingHeaders.stream()
                                  .filter(it -> it.isSameWith(keyword))
                                  .mapToInt(it -> it.lengthRetainingOriginalString)
                                  .findFirst().orElse(0);
    }

    @Data
    public static class MaskingHeader {

        @NotNull
        private String name; // 秘匿対象とするheader名

        @NotNull
        @Min(0)
        private Integer lengthRetainingOriginalString = 0;

        // 設定用のクラスかもしれないが、クライアントコードから使いやすくなるようにヘルパーメソッドを生やす。
        public boolean isSameWith(String headerName) {
            return this.name.equalsIgnoreCase(headerName);
        }
    }
}
```

### yamlに設定を記述する

#### application.yml
```yml
spring:
  profiles:
    active: local # profile指定なしの場合、local profileで起動する。このサンプルとは無関係な設定。

resttemplate:
  logging:
    should-include-payload: false # 特定環境以外ではrequest/responseのpayloadを出力したくないのでデフォルトでfalseにしておく
```

### application-local.yml
```yml
resttemplate:
  logging:
    should-include-payload: true # request/responseのpayloadを出力する
    masking-headers: # この設定はrequest/responseで共通
      - name: set-cookie # デモのため、set-cookieを秘匿する。
        length-retaining-original-string: 2 # 秘匿時に前後2文字はオリジナルの文字列をを残す
```

### `RestTemplateCustomizer`を実装してDIコンテナに登録されたRestTemplate全てに`RestTemplateLoggingInterceptor`を登録する
- 簡単なので特に解説なしです

```java
package resttemplatelogging.javaexample;

import lombok.RequiredArgsConstructor;
import org.springframework.boot.web.client.RestTemplateCustomizer;
import org.springframework.stereotype.Component;
import org.springframework.web.client.RestTemplate;

@RequiredArgsConstructor
@Component
public class CustomRestTemplateCustomizer implements RestTemplateCustomizer {
    private final RestTemplateLoggingInterceptor restTemplateLoggingInterceptor;

    @Override
    public void customize(RestTemplate restTemplate) {
        restTemplate.getInterceptors().add(restTemplateLoggingInterceptor);
    }
}
```


## 参考にしたブログ・サイトなど
- [RestTemplateでリクエストやレスポンスの中身をログに出す](https://qiita.com/shotana/items/14972c681e5fc315deec)
- [RestTemplateのリクエスト・レスポンスをログ出力する](https://qiita.com/seijikohara/items/b322d7de3130440f9455)
- [Configure a RestTemplate with RestTemplateBuilder](https://www.baeldung.com/spring-rest-template-builder#configuration-using-aresttemplatecustomizer)