アプリケーション間でRequestIdを送りあってみる

# やりたいこと
サービスが複数またがってている場合、運用時にサービス間を跨いだログを見たくなる時があるので、その方法をかく。
順番は
1. Spring BootでRequestIdを生成して、ログファイルに出しておく
2. 他アプリケーション(今回はGin)に対して、リクエストを投げる
3. Gin側でRequestIdを受け取る

ソース
[Spring Boot](https://github.com/ririkku/spring-log-demo)
[Gin](https://github.com/ririkku/go-sandbox/tree/master/gin-nginx-sample)

# 環境
- Java
- Spring Boot
- Go
- Gin

# Spring Boot側にRequestIdの設定を入れる

## ログファイルにRequestIdが表示されるようにする

MDCを使用して、リクエスト毎にUUIDを生成して、ログに仕込めるようにしておく

```SampleFilter.java
import org.slf4j.MDC;
import org.springframework.web.filter.OncePerRequestFilter;

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.UUID;

public class SampleFilter extends OncePerRequestFilter {

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

        String requestIdKey = "X-REQUEST-ID";
        String uuid = UUID.randomUUID().toString();

        // どこからでもリクエストIDが取得できるように設定しておく
        request.setAttribute(requestIdKey, uuid);

        try {
            // ログに出力できるように設定
            MDC.put(requestIdKey, uuid);
            filterChain.doFilter(request, response);

        } finally {
            MDC.remove(requestIdKey);
        }
    }
}
```

## Filterを使えるようにBeanに登録する

`/api`配下にフィルターがかかるように設定する

```SampleConfiguration.java
import org.springframework.boot.web.servlet.FilterRegistrationBean;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;

@Configuration
public class SampleConfiguration {

    @Bean
    public FilterRegistrationBean<SampleFilter> hogeFilter() {
        FilterRegistrationBean<SampleFilter> bean = new FilterRegistrationBean<>();
        bean.setFilter(new SampleFilter());
        bean.addUrlPatterns("/api/*");
        bean.setOrder(Integer.MIN_VALUE);
        return bean;
    }
}
```

## Logbackの設定

`SampleFilter.java`で定義した`X-REQUEST-ID`を`<pattern>`にも設定する

```logback-spring.xml
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/defaults.xml" />
    <include resource="org/springframework/boot/logging/logback/console-appender.xml" />
    <include resource="org/springframework/boot/logging/logback/file-appender.xml" />

    <springProperty name="loggingFilePath" source="logging.file.path" />

    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <file>${loggingFilePath}/spring.log</file>
        <encoder>
            <pattern>[%-5level] [%X{X-REQUEST-ID}] [%d{yyyy-MM-dd HH:mm:ss.SSS}] [%logger{36}] - %msg%n</pattern>
        </encoder>
    </appender>

    <root level="INFO">
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="FILE" />
    </root>
</configuration>
```
今回はINFO以上のレベルしか出さないようにする

```application.properties
logging.file.path=logs/
logging.level.org.springframework=INFO
```

### リクエストを投げてログを確認

`http://localhost:8080/api/`にGETのエンドポイントを作っておく

```SampleController.java
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
@RequestMapping("api")
public class SampleController {

    private static final Logger logger = LoggerFactory.getLogger(SampleController.class);

    @GetMapping
    public String get() {
        logger.info("info!");
        return "get";
    }
}
```
### リクエストの結果のログファイル

```spring.log
[INFO ] [2389c607-f5ed-4789-95a3-efd78be1e8d9] [2020-XX-XX 23:26:25.536] [c.e.log.logdemo.SampleController] - info!
```
`2389c607-f5ed-4789-95a3-efd78be1e8d9`が生成したUUID
ちゃんと出てるっぽいね

# RestTemplateで他サービスにリクエストする時にRequestIdを付与する

RestTemplateを使えるようにBeanに登録しておく
(特にここで定義する必要はなかったですが楽だったので)

```LogDemoApplication.java
@SpringBootApplication
public class LogDemoApplication {

	public static void main(String[] args) {
		SpringApplication.run(LogDemoApplication.class, args);
	}

	@Bean
	public RestTemplate setRestTemplate(){
		return new RestTemplate();
	}
}
```

他アプリケーションに投げるためのエンドポイントを用意しておく

```SampleController.java
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.http.HttpEntity;
import org.springframework.http.HttpHeaders;
import org.springframework.http.HttpMethod;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;
import org.springframework.web.client.RestTemplate;
import org.springframework.web.context.request.RequestAttributes;
import org.springframework.web.context.request.RequestContextHolder;

@RestController
@RequestMapping("api")
public class SampleController {

    private static final Logger logger = LoggerFactory.getLogger(SampleController.class);

    // 追記
    RestTemplate restTemplate;

    // 追記
    public SampleController(RestTemplate restTemplate) {
        this.restTemplate = restTemplate;
    }

    @GetMapping
    public String get() {
        logger.info("info!");
        return "get";
    }

    // 追記
    @GetMapping("to-other-app")
    public String toOtherApp() {

        String requestId = (String) RequestContextHolder
                .getRequestAttributes()
                .getAttribute("X-REQUEST-ID", RequestAttributes.SCOPE_REQUEST);

        logger.info("他のアプリケーションにリクエスト投げます！");

        HttpHeaders headers = new HttpHeaders();
        headers.set("X-REQUEST-ID", requestId);
        HttpEntity<String> entity = new HttpEntity<>("headers", headers);
        ResponseEntity<OtherAppResponse> response = restTemplate.exchange("http://localhost/api", HttpMethod.GET, entity, OtherAppResponse.class);

        return response.getBody().getValue();
    }
}
```

これでSpring Boot側の設定は完了です！

# Gin側のアプリケーションを作成する

[別で書いた](https://qiita.com/ririkku/items/2ad76f6867c7b4078fc7)の記事のものを流用します

`docker-compose up -d`を叩くだけなので、簡単
`http://localhost:80/api`にアクセスすると、 `{"key": "value"}`が返ってくるだけのAPIがあります

# お互いのログを確認

Spring Bootは`http://localhost:8080/`
Giは`http://localhost:80/`
で起動します

### Spring Boot側でリクエスト
`http://localhost:8080/api/to-other-app`にアクセス

```spring.log
[INFO ] [549ef61a-44c9-4fe4-9c0f-3d923976d32f] [2020-XX-XX 00:19:00.274] [c.e.log.logdemo.SampleController] - 他のアプリケーションにリクエスト投げます！
```
ログが見えました
リクエストIDは `549ef61a-44c9-4fe4-9c0f-3d923976d32f`

### Gin側のログファイルを確認

```
[GIN-debug] [WARNING] Creating an Engine instance with the Logger and Recovery middleware already attached.

[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:	export GIN_MODE=release
 - using code:	gin.SetMode(gin.ReleaseMode)

[GIN-debug] GET    /api                      --> main.main.func1 (4 handlers)
[GIN-debug] Listening and serving HTTP on :3000
[GIN] 2020/XX/XX - 15:16:44 | 200 |       1.005ms |      172.19.0.3 | GET      "/api"
{"time":"2020-XX-XXT15:19:00.3482677Z","level":"-","prefix":"-","file":"main.go","line":"30","message":"RequestId=549ef61a-44c9-4fe4-9c0f-3d923976d32f"}
```

送られてきたリクエストIDは`549ef61a-44c9-4fe4-9c0f-3d923976d32f`
どうやら一致したようですね(日付はぼかしてます)

# まとめ
さらっとやりましたが、Spring BootでリクエストIDをどこでも使えるようにするだとか、Ginでアプリケーション作るだとかに時間がかかりました。Spring Boot側の`RequestContextHolder`とか、「これでええんかな...」感はありますが、他にやり方が浮かばなかったので、もし知っていたら教えていただけるととても嬉しいです。Gin側でSpring Bootに返すのはHeader設定するだけで簡単っぽいので割愛しました。なんでGinなのか、ギョームではSpring Boot + NodeJSで実現してますが、最近Goに興味が湧いたので(Go楽しい)。
分かり辛いところ、もっと効率のいいやり方、アドバイスあればぜひコメントください