nginx upstream パッシブヘルスチェックはかなり使える (max_fails, fail_timeout)

今回は nginx upstream のパッシブヘルスチェックの挙動について調べます。

前回の consistent hash (http://neinvalli.hatenablog.com/entry/2017/10/29/235721) の調査でも出てきた下記の設定について、今度はヘルスチェックの挙動がどうなっているのか調査しました。

upstream myapp1 {
    hash $host$uri consistent;
    server  127.0.0.1:10080  max_fails=100 fail_timeout=10;
    server  127.0.0.2:10080  max_fails=100 fail_timeout=10;
    server  127.0.0.3:10080  max_fails=100 fail_timeout=10;
    server  127.0.0.4:10080  max_fails=100 fail_timeout=10;
}

ヘルスチェックの仕様について

公式のドキュメントによると、下記のようになっています。

http://nginx.org/en/docs/http/ngx_http_upstream_module.html#server https://www.nginx.com/resources/admin-guide/load-balancer/

max_fails=number

sets the number of unsuccessful attempts to communicate with the server that should happen in the duration set by the fail_timeout parameter to consider the server unavailable for a duration also set by the fail_timeout parameter. By default, the number of unsuccessful attempts is set to 1. The zero value disables the accounting of attempts.

fail_timeout=time

the time during which the specified number of unsuccessful attempts to communicate with the server should happen to consider the server unavailable; and the period of time the server will be considered unavailable.

ドキュメントを読む限りは fail_timeout の秒数の間にバックエンドへの通信が max_fails の回数以上失敗した場合に fail_timeout の時間そのバックエンドは使われなくなる。というように読み取れます。

nginx のヘルスチェックの問題点

バックエンドへの通信がどうなると失敗と評価されるのかは proxy_next_upstream のパラメーターで設定します。

例えば、proxy_next_upstream error timeout; と設定した場合で、バックエンドサーバーがダウンしてしまった場合、proxy_connect_timeout で設定した秒数まで失敗したかどうかわからないことにあるため、大量に通信が来ている場合は該当バックエンドがダウンしたと評価されるまでにそれなりの数のリクエストがタイムアウトしてしまいます。

proxy_next_upstream_tries を 2以上に設定している場合は、次のバックエンドへ通信をプロキシしてくれるのですが、どちらにしてもタイムアウトの時間を待っている間はエンドユーザーへのレスポンスが大幅に遅くなってしまいます。

上記のように考えると、この挙動は品質的にはよろしくないです。

下記のようになると考えられるからです。

バックエンドの1台がダウン(バックエンドA とする)
プロキシからバックエンドA への通信が max_fails 回数タイムアウトするまでの間、バックエンドA へ流した通信(かなりの数になると思われる)がタイムアウトしてしまう
max_fails 回数タイムアウトし、バックエンドA がダウンしていると評価される。
fail_timeout の時間の間はバックエンドA には通信は流れない
fail_timeout の時間経過後、バックエンドA の「ダウンしている評価」が解除される
バックエンドA は実際はダウンしたままなので、上記 2から繰り返しとなる

ここで問題なのが、fail_timeout の時間ごとにバックエンドA がダウンしていると評価されるまでの感のバックエンドA へ流しているコネクションがタイムアウトしてしまい、エンドユーザーに待たせてしまうことになることです。

アクティブヘルスチェックは有料版のみ

これは品質的によくないです。この形式の「実際のユーザーの通信を利用してヘルスチェックを行う方法」をパッシブヘルスチェックと言うそうです。逆に通常のロードバランサーのように、バランサー自身が専用のコネクションでヘルスチェックだけを行う機能があればいいですね。

パッシブチェックに対して、こういうヘルスチェックをアクティブヘルスチェックと言います。先ほどの nginx 公式のページにも「Active Health Monitoring」なる項目があります。

https://www.nginx.com/resources/admin-guide/load-balancer/

ただ、残念なことにアクティブヘルスチェックは NGINX Plus という有料版のみの機能のようです。

パッシブチェックは本当に使えないのか、実験で確かめる

nginx のパッシブチェックの挙動が上で公式ドキュメントから読み取った内容通りなのかどうか、実験で確認します。

今回の実験で使用する設定は下記のとおりです

upstream myapp1 {
    hash $host$uri consistent;
    server  127.0.0.1:10080  max_fails=100 fail_timeout=10;
    server  127.0.0.2:10080  max_fails=100 fail_timeout=10;
    server  127.0.0.3:10080  max_fails=100 fail_timeout=10;
    server  127.0.0.4:10080  max_fails=100 fail_timeout=10;
}

log_format  chash-proxy-v2  'uri:$uri\t'
                            'upstream_addr:$upstream_addr\t';

server {
    listen 80 default_server;

    root /var/www/html;

    index index.html index.htm index.nginx-debian.html;

    server_name _;

    access_log /var/log/nginx/chash-access-v2.log chash-proxy-v2;
    error_log /var/log/nginx/chash-error.log;

    location / {
        proxy_pass http://myapp1;
        proxy_next_upstream error timeout;
        proxy_next_upstream_tries 0;
        proxy_next_upstream_timeout 10;
        proxy_connect_timeout 4s;
        proxy_send_timeout 5s;
        proxy_read_timeout 5s;
    }
}

この設定の nginx へ前回使用した 10000パターンの URL に対してアクセスしてみます。
アクセスを流しつつ、iptables -A INPUT -d 127.0.0.3 -j DROP を流し込み、127.0.0.3:10080 へつながらないようにします。
ただ、max_fails=100 fail_timeout=10 の設定を入れているため、10秒間の間に 100回タイムアウトすれば該当バックエンドがダウンしたと評価され、別のサーバーへアクセスが振られるようになります。
その 10秒後に「ダウン状態が解除」された時にどの程度アクセスが流れているのかチェックします。

チェックはエラーログを確認します。バックエンドへの通信が失敗した場合には、下記のようなエラーメッセージがエラーログに出ます。

2017/10/29 18:16:11 [error] 8692#8692: *27312 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /4992 HTTP/1.1", upstream: "http://127.0.0.3:10080/4992", host: "127.0.0.1"

テストの結果は以下のとおりです。エラーログを見れば一目瞭然です。(大量のエラーが出ているので、途中を省略します。)

2017/10/29 18:16:11 [error] 8692#8692: *27312 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /4992 HTTP/1.1", upstream: "http://127.0.0.3:10080/4992", host: "127.0.0.1"
2017/10/29 18:16:11 [error] 8692#8692: *27324 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /3498 HTTP/1.1", upstream: "http://127.0.0.3:10080/3498", host: "127.0.0.1"
2017/10/29 18:16:11 [error] 8692#8692: *27334 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /6045 HTTP/1.1", upstream: "http://127.0.0.3:10080/6045", host: "127.0.0.1"
2017/10/29 18:16:11 [error] 8692#8692: *27338 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /3243 HTTP/1.1", upstream: "http://127.0.0.3:10080/3243", host: "127.0.0.1"
2017/10/29 18:16:11 [error] 8692#8692: *27360 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /9629 HTTP/1.1", upstream: "http://127.0.0.3:10080/9629", host: "127.0.0.1"
...(140行ほど同じタイミングでの同じエラーが出ている。省略)...
2017/10/29 18:16:11 [error] 8692#8692: *28306 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /7639 HTTP/1.1", upstream: "http://127.0.0.3:10080/7639", host: "127.0.0.1"
2017/10/29 18:16:16 [error] 8692#8692: *28309 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /4503 HTTP/1.1", upstream: "http://127.0.0.3:10080/4503", host: "127.0.0.1"
2017/10/29 18:16:16 [error] 8692#8692: *28314 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /4960 HTTP/1.1", upstream: "http://127.0.0.3:10080/4960", host: "127.0.0.1"
2017/10/29 18:16:16 [error] 8692#8692: *28316 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /0120 HTTP/1.1", upstream: "http://127.0.0.3:10080/0120", host: "127.0.0.1"
2017/10/29 18:16:16 [error] 8692#8692: *28320 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /2747 HTTP/1.1", upstream: "http://127.0.0.3:10080/2747", host: "127.0.0.1"
2017/10/29 18:16:16 [error] 8692#8692: *28336 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /5761 HTTP/1.1", upstream: "http://127.0.0.3:10080/5761", host: "127.0.0.1"
2017/10/29 18:16:32 [error] 8692#8692: *92392 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /5822 HTTP/1.1", upstream: "http://127.0.0.3:10080/5822", host: "127.0.0.1"
2017/10/29 18:16:48 [error] 8692#8692: *158836 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /7273 HTTP/1.1", upstream: "http://127.0.0.3:10080/7273", host: "127.0.0.1"
2017/10/29 18:17:04 [error] 8692#8692: *225872 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /3417 HTTP/1.1", upstream: "http://127.0.0.3:10080/3417", host: "127.0.0.1"
2017/10/29 18:17:20 [error] 8692#8692: *291484 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /7083 HTTP/1.1", upstream: "http://127.0.0.3:10080/7083", host: "127.0.0.1"
2017/10/29 18:17:36 [error] 8692#8692: *358310 upstream timed out (110: Connection timed out) while connecting to upstream, client: 127.0.0.1, server: _, request: "GET /1997 HTTP/1.1", upstream: "http://127.0.0.3:10080/1997", host: "127.0.0.1"

公式ドキュメントの仕様からの考察再掲

公式ドキュメントの仕様からの考察を以下に再掲します。

バックエンドの1台がダウン(バックエンドA とする)
プロキシからバックエンドA への通信が max_fails 回数タイムアウトするまでの間、バックエンドA へ流した通信がタイムアウトしてしまう
max_fails 回数タイムアウトし、バックエンドA がダウンしていると評価される。
fail_timeout の時間の間はバックエンドA には通信は流れない
fail_timeout の時間経過後、バックエンドA の「ダウンしている評価」が解除される
バックエンドA は実際はダウンしたままなので、上記 2から繰り返しとなる

実験結果では、最後の「上記 2から繰り返しとなる」以降が違います。 具体的には一度ダウンしたと評価されたバックエンドへのパッシブチェックは fail_timeout の時間ごとに 1コネクションだけ流されるようです。

上記考察を実験結果で修正したものは下記のとおりです。

実験結果を見て判明した挙動

バックエンドの1台がダウン(バックエンドA とする)
プロキシからバックエンドA への通信が max_fails 回数タイムアウトするまでの間、バックエンドA へ流した通信がタイムアウトしてしまう (実験では max_fails=10 だが、10通信がタイムアウトしたと判明するまでに合計 150 ほどタイムアウト)
max_fails 回数タイムアウトし、バックエンドA がダウンしていると評価される。
fail_timeout の時間の間はバックエンドA には通信は流れない
fail_timeout の時間経過後、バックエンドA が復活したかどうか確認するため、1コネクションだけ流される
バックエンドA は実際はダウンしたままなので、再度 fail_timeout の間はダウンと評価したままとなる。
上記 5 から繰り返しとなる。

ポイントは 5 の箇所です。考察では fail_timeout の時間ごとに大量のコネクションがタイムアウトしてしまう、という内容でしたが、想定外にかなり許容できる挙動になっています。

ちなみに、バックエンドのパッシブヘルスチェックの結果は nginx のワーカーごとに持っているようで、ワーカーが多い場合は fail_timeout ごとのチェックのための 1コネクションがワーカー数分発生します

consistent hash の挙動はどうなっているのか

前回挙動を確認した consistent hash ですが、パッシブヘルスチェックでバックエンドがダウン状態となった場合、consistent hash がちゃんと効くのかどうか、ですが、同じようにしっかりと効いていました。

ちなみに下記のような設定でバックエンドへの通信がタイムアウトやエラーとなった場合に次のバックエンドが選ばれますが、これについても consistent hash が効いていました。

proxy_next_upstream error timeout;
proxy_next_upstream_tries 2;

この「効いていた」というのは、サーバーを外したときの consistent hash と同じ振り分け先となっていた、という意味です。表にすると下記のとおりです

前回の記事のデータを再掲します。

基準データ

サーバー	URL パターン数
1	2295
2	2302
3	2977
4	2426

各種ダウン状態の consistent hash の数字

サーバー	基準データ	サーバー3 を事前に外す	サーバー3 が max_fails 以上のエラーでダウン	サーバー3 への通信失敗で次のバックエンドへ	備考
1	2295	3259	3259	3259	3つともサーバー3 から 964 件移動
2	2302	3574	3574	3574	3つともサーバー3 から 1272 件移動
3	2977	0	0	0	0
4	2426	3167	3167	3167	3つともサーバー3 から 741 件移動

上記表の意味は下記のとおりです。

サーバー3 を事前に外す → server 127.0.0.3:10080 max_fails=100 fail_timeout=10 down; の設定で予め外した状態
サーバー3 が max_fails 以上のエラーでダウン評価 → サーバー3 がダウン評価を受けた場合に、代わりに振り分け先となるバックエンドがどれか
サーバー3 への通信失敗で次のバックエンドへ → proxy_next_upstream error timeout; proxy_next_upstream_tries 2; 等の設定で、次の振り分け先のバックエンドがどれになるか

アクティブヘルスチェックとの差を考える

アプライアンスのバランサー等でアクティブチェックしている場合でも、 timeout=5s, interval=30s, retry=3, retry-interval=3s というような設定にしているかと思うのですが、この場合でも最初にバックエンドがダウン状態と評価されるまでの 10秒程度の間は該当バックエンドに流れているコネクションはタイムアウトしてしまいます。そう考えると nginx のパッシブチェックも意外に頑張っていると思われます。

まとめ (nginx のパッシブヘルスチェックはかなり使える)

NGINX Plus へユーザーを流すためにわざと機能を弱めにしてるというイメージだったのですが、 nginx のパッシブヘルスチェックは意外にもかなり使い物になることがわかりました。コネクションの取りこぼしができるだけ起きないようにしないといけないシビアな環境でなければ気軽に使ってもよさそうです。

Neinvalli

研究テーマは ”IT 環境でのリソース最適化” です