Nginxのミラーリング機能で楽々パフォーマンス検証

## はじめに
サービスの内部インフラを変更した場合に、単体レベルではパフォーマンスを担保できても
実運用で問題ないかどうかは、サービス全般の負荷検証のやり直しなど、コストが相当かかります。
どうにか楽に、ユーザーの運用状況を一定期間トレースする方法ないか、ということで
nginxで現行環境のリクエストをミラーリングすれば楽できるのでは？と白羽の矢を立てました。
とはいえ、ミラーリングの負荷で現行環境に支障が出たら大変です(本当に大変です。。)
そんなわけで安心して使っていいのかを判断するべく、ミラーリングの動作を見ていこうと思います。

今回の記事はこちらの記事を参考にさせていただき、worker_connectionsの枯渇のケースを追加で検証しています。
[Nginx 1.13 の http_mirror_module を試す] (https://tagomoris.hatenablog.com/entry/2018/04/03/102831)

※本記事は「Develop fun!を体現する Works Human Intelligence Advent Calendar 2020」の12/5を担当したものです。

## 検証ポイント
- nginxのCPU負荷
- nginxのメモリ
- nginxのリクエスト数増加による遅延・失敗

## 用意するもの
<details><summary>nginx-1.13.4以降(今回は1.19.3を使用) confサンプルは折り畳んでいます</summary><div>

```
        location / {
            proxy_pass http://localhost:3000;
            mirror /mirror;
        }
        location /mirror {
            internal;
            proxy_pass http://localhost:3010$request_uri;
        }
```
</div></details>
<details><summary>サーバーA(リクエスト受け取り/レスポンス送信時にログを出す)</summary><div>

```
const express = require('express');
const app = express();
const port = 3000;

app.get('/', (req, res) => {
  console.log(new Date().toISOString()+ ':reached.');
  setTimeout(() => {
    console.log(new Date().toISOString()+ ':responsed.');
    res.send('Hello World!');
  }, 0);
})

app.listen(port, () => {
  console.log(`App listening at http://localhost:${port}`);
})
```
</div></details>
<details><summary>サーバーB(Aと同様だが、ミラー先の処理遅延を想定して、レスポンスを10秒遅延させている)</summary><div>

```
const express = require('express');
const app = express();
const port = 3010;

app.get('/', (req, res) => {
  console.log(new Date().toISOString()+ ':reached.');
  setTimeout(() => {
    console.log(new Date().toISOString()+ ':responsed.');
    res.send('Hello World!');
  }, 10000);
})

app.listen(port, () => {
  console.log(`App listening at http://localhost:${port}`);
})
```
</div></details>

## 検証
### まずは普通にミラーリング
上で用意したnginx、サーバーを起動し、localhostにアクセスすると、
サーバーAのリクエストが複製され、サーバーBにも送信されます。

サーバーAのログはリクエストを受け取ったタイミング(reached)とレスポンスを返したタイミング(responsed)にログを出力しています。タイムラグなく、すぐにレスポンスを返しています。
![サーバーAのログ](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/858001/3e2494ba-6597-712d-ef82-513c4f04a45d.png)

サーバーBのログはAとほぼ同じタイミングにリクエストを受け取っていて、10秒後にそれぞれレスポンスを返しています。下図だと7:45:01のリクエストは7:45:11にレスポンスを返しています。
![サーバーBのログ](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/858001/ed103693-1bd5-9701-5e33-7874d6f941aa.png)
これでlocalhostに投げた1つのリクエストが、無事にミラーリングできていることが分かりました。

### ミラーサーバー(サーバーB)が落ちている場合
サーバーAのリクエストは正常に処理され、レスポンスも正常に返ってきます。
nginxのログを見ると、サーバーBへのリクエストが失敗している旨が記録されています。
ミラーリング先環境が、元環境の振る舞いに影響しないのは、期待通りです。

```
2020/12/04 21:19:35 [error] 29172#34464: *6503 connect() failed (10061: No connection could be made because the target machine actively refused it) while connecting to upstream, client: 127.0.0.1, server: localhost, request: "GET / HTTP/1.1", subrequest: "/mirror", upstream: "http://[::1]:3010/", host: "localhost"
```

### 元サーバー(サーバーA)が落ちている場合
サーバーBにリクエストは届きますが、フロントにはサーバーAのエラーが返ってきます。

### ミラーリングによる負荷の確認
ここからはミラーリングを利用することによる、負荷を確認してみます。
#### nginxのCPUとメモリ
1秒当たり100リクエスト以上は投げたのですが、CPU,メモリ共に増える様子がありません。
問題ないと判断していいと思います。
![cpu_memory.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/858001/6efbe8ed-5a0d-f74b-e15f-e46a4e0add0b.png)

#### nginxのworker_connectionsの枯渇
ミラーリングによって、nginxが扱うリクエスト数は倍増します。
この影響でworker_connectionsが枯渇するかどうかを確認します。
今回の検証では`worker_connections  32`に設定した結果、

- ミラーリング無し：エラーなし  
- ミラーリング有り：以下のconnection枯渇エラーが発生しました。

```
2020/12/04 21:15:57 [alert] 29172#34464: *6501 32 worker_connections are not enough while connecting to upstream, client: 127.0.0.1, server: localhost, request: "GET / HTTP/1.1", subrequest: "/mirror", upstream: "http://127.0.0.1:3010/", host: "localhost"
```
#### 対処法
現行のworker_connections数で十分、もしくは増やす余裕があれば問題ないですが、
今回は比較的カツカツ、かつパフォーマンス遅延が読めないので念には念を入れておきたいです。
そのため、ミラーリングサーバーへのリクエストのtimeout設定をいれてみます。
関連するタイムアウト設定　`proxy_connect_timeout, proxy_read_timeout`
サーバーの処理遅延を気にしているので、今回は`proxy_read_timeout`を利用します。
※accessログのレスポンス状況は検証できなくなりますが、今回のケースではサーバー内のログで十分な情報が得られるため、一定期間でレスポンスエラーが返っても問題ない前提があります。

```
        location /mirror {
            internal;
            proxy_read_timeout 1;
            proxy_pass http://localhost:3010$request_uri;
        }
```
こちらを設定したところ、先ほどまで発生していたworker_connectionsの枯渇エラーはなくなり、
かわりにタイムアウトエラーがnginxで発生しています。
ただ、ミラーサーバーのログを見ると、受け取ったレスポンスに対する処理は行っているため、
今回実現したい、
**「ミラーサーバーへリクエストは送って処理はさせるが、
nginxの負荷はなるべくかけずに、元環境の運用に支障をきたさない」**
を実現できるかな、と思います。

```
2020/12/04 22:22:44 [error] 32928#46776: *414 upstream timed out (10060: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond) while reading response header from upstream, client: 127.0.0.1, server: localhost, request: "GET / HTTP/1.1", subrequest: "/mirror", upstream: "http://127.0.0.1:3010/", host: "localhost"
```

## おわりに
実はまだ本番で試せていないのですが、今回検証してみて、いける感触が掴めました。
社内で前例がない取り組みで色々先が見えていない不安はあるものの、
もがきながら道を切り開いていくのが、**Develop fun!**
ということで締めさせていただきます。ありがとうございました。

## 参考記事
[Nginx 1.13 の http_mirror_module を試す] (https://tagomoris.hatenablog.com/entry/2018/04/03/102831)
[[Nginx]worker_connectionsとworker_rlimit_nofileの値は何がいいのか？](https://qiita.com/mikene_koko/items/85fbe6a342f89bf53e89)
[Module ngx_http_proxy_module](http://nginx.org/en/docs/http/ngx_http_proxy_module.html#proxy_read_timeout)