概要 #
ロードバランサの設定値は、既定のままでも動きます。動くので、何秒で効くのかを知らないまま運用に入りがちです。
デプロイの手順を書いていて、次のような形にすることがあります。
# バックエンドを1台外す
gcloud compute network-endpoint-groups update NEG --remove-endpoint ...
# 外れたので入れ替える
...
このコマンド、Provider の既定値（draining=300秒）のままだと5分以上終わりませんでした。 しかも新しいリクエストは、その前に届かなくなっています。
detachNetworkEndpoints は Operation を返す非同期APIで、gcloud はその完了を待ってから戻ります。 以下で「5分」と書くのは、この完了待ちを含んだ時間です。HTTP応答そのものの速さは測っていません。
対象はリージョン外部 Application Load Balancer です。検出にかかる時間と、バックエンド削除の挙動を実測します。
Google Cloud のロードバランサを触ったことがある人向けです。構成の作り方は前の記事で扱っており、ここでは時間だけを見ます。
検証環境 #
- Terraform v1.14.3、
hashicorp/googlev7.46.0 - Google Cloud SDK 562.0.0
使用するコードは Advanced-Examples/08-regional-external-alb-neg です。:81 はゾーンaの2台（backend-a / backend-a2）、:82 はゾーンcの1台（backend-b）に向きます。
バックエンドは python3 -m http.server で、自分の名前を返すだけです。
測る前の確認 #
構成は前の記事と同じです。時間を測る対象が2つあるので、どこに付いている値かを先に置きます。
flowchart LR
C["クライアント"] -->|":81"| BSA["バックエンドサービス bs-a
draining 300秒"]
C -->|":82"| BSB["バックエンドサービス bs-b
draining 300秒"]
BSA --> NEGA["neg-a（ゾーンa）"]
BSB --> NEGB["neg-b（ゾーンc）"]
NEGA --> A["backend-a"]
NEGA --> A2["backend-a2
10.80.0.4:8080"]
NEGB --> B["backend-b"]
HCA["hc-a
5秒ごと・閾値2"] -.->|"プローブ"| A
HCA -.-> A2
HCB["hc-b
5秒ごと・閾値2"] -.-> B
点線がヘルスチェック、実線がリクエストです。検出の速さはヘルスチェックに、切り離しの遅さはバックエンドサービスに付いています。 同じ「何秒」でも、変える場所が違います。
測り始める前に、3台とも健全で振り分けが効いていることを見ます。
$ terraform apply
Apply complete! Resources: 33 added, 0 changed, 0 destroyed.
$ gcloud compute backend-services get-health tf-adv-elb08-bs-a --region=asia-northeast1 \
--format="value(status.healthStatus[].instance.basename(),status.healthStatus[].healthState)"
tf-adv-elb08-a;tf-adv-elb08-a2 HEALTHY;HEALTHY
$ for i in $(seq 1 20); do curl -sS "http://$(terraform output -raw vip):81/"; done | sort | uniq -c
10 backend-a
10 backend-a2
20回で 10/10 に割れました。 同じNEGの中でどちらを選ぶかは localityLbPolicy が決めます。このサンプルは指定しておらず、sessionAffinity が NONE のときの既定は ROUND_ROBIN です。RATE と max_rate_per_endpoint はグループへの配分と容量の設定で、グループ内の選択ではありません。
20回で必ず 10/10 になる保証ではありません。 この状態を基準にします。
既定値を読む #
このサンプルは、ヘルスチェックの4項目をどれも指定していません。
resource "google_compute_region_health_check" "hc_a" {
name = "tf-adv-elb08-hc-a"
region = var.region
http_health_check {
port = 8080
request_path = "/"
}
}
作られたものを読むと、値が入っています。
以下は --format=json の出力から、必要な項目を抜き出したものです。
$ gcloud compute health-checks describe tf-adv-elb08-hc-a --region=asia-northeast1 --format=json
checkIntervalSec 5
timeoutSec 5
healthyThreshold 2
unhealthyThreshold 2
type HTTP
バックエンドサービス側も同じです。connection_draining_timeout_sec は hashicorp/google v7.46.0 で既定値 300 が入ります。以下の「既定」は、この Provider で作った構成での既定を指します。
$ gcloud compute backend-services describe tf-adv-elb08-bs-a --region=asia-northeast1 \
--format="value(connectionDraining.drainingTimeoutSec,timeoutSec)"
300 30
| 項目 | 値 | 何を決めるか |
|---|---|---|
checkIntervalSec |
5 | 何秒ごとに呼ぶか |
timeoutSec（ヘルスチェック） |
5 | プローブの応答を何秒待つか |
healthyThreshold |
2 | 何回連続成功で HEALTHY にするか |
unhealthyThreshold |
2 | 何回連続失敗で UNHEALTHY にするか |
connectionDraining.drainingTimeoutSec |
300 | 外したバックエンドの通信をいつまで残すか（Provider の既定値） |
timeoutSec（バックエンドサービス） |
30 | バックエンドの応答を何秒待つか |
同じ名前の timeoutSec が2つあります。ヘルスチェックのものはプローブ用、バックエンドサービスのものはリクエスト用です。
検出に何秒かかるか #
:82 のバックエンド1台を止めて、UNHEALTHY になるまでを測ります。単一のVMなので状態が読みやすいです。
sudo systemctl stop be-http
2秒おきに get-health を呼び、変わった時刻を記録します。
## 設定: checkIntervalSec=5 timeoutSec=5 healthy=2 unhealthy=2
20秒: UNHEALTHY <= UNHEALTHY を検出
18秒: HEALTHY に復帰
unhealthyThreshold × checkIntervalSec は 10秒ですが、実測は20秒でした。
値を縮めて、もう一度測ります。
$ gcloud compute health-checks update http tf-adv-elb08-hc-b --region=asia-northeast1 \
--check-interval=2 --timeout=2 --unhealthy-threshold=1 --healthy-threshold=1
Updated [...].
## 設定: checkIntervalSec=2 timeoutSec=2 healthy=1 unhealthy=1
6秒: UNHEALTHY
8秒: HEALTHY
| 設定 | 検出 | 復帰 | 閾値×間隔 |
|---|---|---|---|
5 / 2（既定） |
20秒 | 18秒 | 10秒 |
2 / 1 |
6秒 | 8秒 | 2秒 |
比較用に 閾値 × 間隔 を計算すると10秒と2秒ですが、この積は観測できるまでの時間を保証する式ではありません。 実測との比は、既定で検出2.0倍・復帰1.8倍、変更後で検出3.0倍・復帰4.0倍でした。
この差には、プローブの失敗そのもの以外が入っています。判定が get-health に反映されるまでの時間と、こちらのポーリング間隔（2秒）です。測っているのは「APIで見えるようになるまで」で、内部で状態が変わった瞬間ではありません。
内訳までは分かっていません。 どちらも各1回の測定で、プローブの実施時刻を突き合わせていません。詰めるならヘルスチェックのログを有効にして probeCompletionTimestamp と比べ、複数回測ります。
それでも、「10秒で気づくはず」で見積もるのは危ないことは言えます。通知までの時間は、使う監視経路で別に測ります。
バックエンドを外すと何が起きるか #
:81 の2台から1台を外します。外すのは NEG のエンドポイントです。
gcloud compute network-endpoint-groups update tf-adv-elb08-neg-a --zone=asia-northeast1-a \
--remove-endpoint "instance=tf-adv-elb08-a2,ip=10.80.0.4,port=8080"
最初の測定を失敗しました。このコマンドの完了を待ってから測り始めたところ、1回目のサンプルがこうなりました。
323秒: a=10 a2=0 その他=0
a2 への振り分けはもう終わっています。コマンドが終わるまでに300秒以上かかっていたためです。
削除リクエストを背景に投げ、送信した瞬間から測り直します。
0秒: a=6 a2=4 その他=0
5秒: a=8 a2=2 その他=0
9秒: a=10 a2=0 その他=0
13秒: a=10 a2=0 その他=0
18秒: a=10 a2=0 その他=0
gcloudが終了した: 320秒
9秒のサンプル以降、a2 からの応答は0件でした。gcloud が終わったのは320秒後です。失敗したリクエストはありません。
sequenceDiagram
participant GC as gcloud
participant LB as bs-a
participant A2 as backend-a2
participant CL as 5秒おきの計測
GC->>LB: detachNetworkEndpoints（非同期API）
Note over GC: Operation の完了を待って戻る
CL->>LB: 0秒
LB->>A2: 10回中4回
CL->>LB: 9秒
LB--xA2: 振り分けは止まっている（0件）
Note over LB,A2: draining の猶予はまだ続く（既定300秒）
LB-->>GC: 320秒: Operation 完了
Note over GC: gcloud が戻るのはここ
待っているのはコマンドだけで、リクエストは9秒の時点でもう来ていません。 図の上半分と下半分で、300秒ぶんの開きがあります。
これは短いリクエストを5秒おきに10回ずつ投げた観測で、振り分けが止まった正確な時刻ではありません。切り離しをまたぐ長いリクエストがどうなるかも、別に測る必要があります。
5分の正体 #
300秒という長さは、connectionDraining.drainingTimeoutSec の既定値と同じです。確かめます。
$ gcloud compute backend-services update tf-adv-elb08-bs-a --region=asia-northeast1 \
--connection-draining-timeout=10
Updated [...].
同じ手順で、もう一度外します。
0秒: a=5 a2=5 その他=0
5秒: a=10 a2=0 その他=0
9秒: a=10 a2=0 その他=0
13秒: a=10 a2=0 その他=0
gcloudが終了した: 25秒
サーバ側の記録でも確かめます。どのNEGに対する操作かを targetLink で特定します。
gcloud compute operations list --filter="operationType=DetachNetworkEndpoints" \
--sort-by="~insertTime" --format="value(name,targetLink,insertTime,endTime)"
所要時間は endTime - insertTime を自分で計算したもので、コマンドが直接出す値ではありません。
01:35:04 所要 22秒 neg-a <= bs-a を draining=10 にしたあと
01:35:04 所要 314秒 neg-b <= bs-b は 300 のまま
01:34:06 所要 23秒 neg-a
01:27:42 所要 323秒 neg-a <= bs-a が draining=300 だったとき
01:21:23 所要 318秒 neg-a
同じ neg-a が、323秒から22秒に変わっています。 変えたのは、その NEG を持つ bs-a の draining だけです。bs-b は300のままで、314秒かかっています。
drainingTimeoutSec |
a2 の応答が0になったサンプル | gcloud が終了するまで | 失敗 |
|---|---|---|---|
| 300（Provider既定） | 9秒 | 320秒 | 0件 |
| 10 | 5秒 | 25秒 | 0件 |
新しいリクエストは待ちません。待っているのは切り離しオペレーションのほうです。
何に効くか #
デプロイの手順に、こう書いていたとします。
gcloud compute network-endpoint-groups update NEG --remove-endpoint ... # ここで5分
# 入れ替えて戻す
既にトラフィックが来なくなったバックエンドを、5分待つことになります。 台数ぶん直列に回せば、それだけ伸びます。
短くする判断もできますが、draining の役目は処理中の通信を途中で切らないことです。
今回は短いリクエストで失敗を観測しませんでした。長いリクエストは測っていません。 猶予のあいだは既存リクエストの完了を待ち、過ぎれば対象への通信を止めます。10秒に縮めるなら、その猶予に収まらないリクエストが中断されうる、という前提で決めます。
先に測るのは「自分のリクエストがどれだけ長いか」です。 そこから draining を決め、削除にかかる時間はその結果として受け入れます。
測り方でつまずいたこと #
3つあります。どれも、そのままだと間違った結論になりました。
gcloud compute ssh --command で nohup ... & を使ったら、起動していませんでした。 あとで見るとプロセスがなく、ローカルからも応答しません。原因は切り分けていないので、nohup 一般の話とは言えません。 以降は状態とログを確認できる systemd-run にしました。
sudo systemd-run --unit=be-http python3 -m http.server 8080 --bind 0.0.0.0 --directory /var/www
systemd-run の一時ユニットは、正常停止すると消えます。 systemctl stop のあと start が失敗しました。
最初は --collect のせいだと思い、外せば直ると書きかけました。確かめたら違いました。
$ sudo systemd-run --unit=probe-unit sleep 600 # --collect なし
Running as unit: probe-unit.service
$ sudo systemctl stop probe-unit
$ sudo systemctl start probe-unit
Failed to start probe-unit.service: Unit probe-unit.service not found.
--collect が変えるのは、失敗状態のユニットも回収するかどうかです。止めて再開を繰り返すなら、一時ユニットではなく通常の unit ファイルを置きます。今回は毎回 systemd-run で起動し直しました。
そして、いちばん危なかったのが削除APIの待ち時間です。 コマンド完了後から測り始めたため、最初は「300秒の draining が効いてトラフィックが止まった」と読めていました。測り直すと、9秒のサンプル以降は a2 から応答が来ていませんでした。 320秒は gcloud が Operation の完了を待っていた時間です。因果が逆になるところでした。
サンプルのコードにあった不具合 #
測っている途中で、terraform plan に恒常的な差分が出ることに気づきました。
$ terraform plan
# google_compute_network_endpoint.ep_a must be replaced
~ instance = "tf-adv-elb08-a" -> "https://.../instances/tf-adv-elb08-a" # forces replacement
Plan: 3 to add, 0 to change, 3 to destroy.
instance に self_link（完全なURL）を渡していましたが、state には短い名前が入ります。毎回置き換えになります。
- instance = google_compute_instance.be["a"].self_link
+ instance = google_compute_instance.be["a"].name
置き換えのたびに detach が走るので、この記事で測った300秒がそのまま apply の待ち時間になっていました。 直したあとは差分が出ません。
$ terraform plan -detailed-exitcode
No changes. Your infrastructure matches the configuration. # exit 0
恒常的な差分は「動いているから」で放置しがちです。 今回はそれが、実験のたびに5分を足していました。
まとめ #
- 既定値は
5/5/2/2とdraining=300。 サンプルのコードには書かれていない（後者は Provider の既定値） get-healthで見えるまで、検出 20秒 / 復帰 18秒。各1回の測定で、閾値 × 間隔（10秒）との比は 2.0 と 1.82/1にすると 6秒 / 8秒。比は 3.0 と 4.0 で、縮めるほど積から離れた- 測っているのは「APIで見えるまで」。 内部で状態が変わった瞬間ではない
- バックエンドを外すと、9秒後のサンプルから応答が来なくなり、gcloud は320秒終わらない
- その長さは
connectionDraining.drainingTimeoutSecで変わる。10秒にすると25秒で終わった - 同じ名前の
timeoutSecが2つある。 ヘルスチェック用とバックエンドサービス用 - 恒常的な差分を放置しない。
self_linkを渡していたため毎回 NEG エンドポイントが置き換わり、実験のたびに5分足されていた