はじめに — バックエンドは無事なのに 502 が混ざります
トラフィックが増えたあとから、こんな報告が上がってきます。
- ロードバランサーのアクセスログに 502 が全体の0.05パーセントほど混ざります。
- 同じ時刻のバックエンドのアプリケーションログには、該当するリクエスト自体がまったくありません。
- CPU もメモリも余裕があり、ヘルスチェックは一度も失敗したことがありません。
- 再現しません。負荷テストを回すとむしろうまくいきます。
ここでよくある対応は、バックエンドを増やすかヘルスチェックの閾値を調整することです。どちらも効果がありません。この症状の原因は容量ではなくタイミングだからです。
アイドルコネクションをサーバーが閉じようとする瞬間と、クライアントがそのコネクションを再利用しようとする瞬間が重なると、リクエストと FIN が互いにすれ違います。サーバーはすでに閉じた接続に届いたデータに RST で答え、途中のプロキシはそれを 502 に翻訳します。この競合状態は HTTP/1.1 の構造上完全には無くせず、タイムアウトの順序を揃えて確率を0に近づけることが唯一の対応です。
この記事では、その順序がなぜそうでなければならないのか、そしてコネクション再利用にまつわる残りの判断をどう下すのかをまとめます。
接続を一つ開くコスト
まず、なぜ再利用が重要なのかを数字で見ます。新しい HTTPS 接続を一つ開くのに必要な往復はこうです。
DNS 照会 0~1 RTT (キャッシュされていれば 0)
TCP ハンドシェイク 1 RTT (SYN, SYN-ACK, ACK)
TLS 1.3 1 RTT
TLS 1.2 2 RTT
--------
合計 TLS 1.3 基準で最低 2 RTT
同じリージョンの中で RTT が1ミリ秒なら2ミリ秒です。無視できます。ところがソウルから米国東部までは RTT が180ミリ秒ほどになります。接続の確立だけで360ミリ秒を使います。サーバーの処理時間が20ミリ秒でも、ユーザーの体感は380ミリ秒です。
この地点からは、アプリケーションの最適化よりコネクション再利用が圧倒的に大きな効果を出します。再利用された接続では、この 2 RTT がまるごと0になるからです。
実際に測ってみると明確です。
cat > /tmp/curl-format.txt <<'EOF'
time_namelookup: %{time_namelookup}s
time_connect: %{time_connect}s
time_appconnect: %{time_appconnect}s
time_pretransfer: %{time_pretransfer}s
time_starttransfer: %{time_starttransfer}s
----------
time_total: %{time_total}s
num_connects: %{num_connects}
EOF
curl -s -o /dev/null -w "@/tmp/curl-format.txt" \
https://api.example.com/v1/orders \
https://api.example.com/v1/orders
time_namelookup: 0.004312s
time_connect: 0.184901s
time_appconnect: 0.371244s
time_pretransfer: 0.371402s
time_starttransfer: 0.393118s
----------
time_total: 0.394552s
num_connects: 1
time_namelookup: 0.000021s
time_connect: 0.000029s
time_appconnect: 0.000031s
time_pretransfer: 0.000094s
time_starttransfer: 0.022704s
----------
time_total: 0.023918s
num_connects: 0
最初のリクエストは394ミリ秒、二度目は24ミリ秒です。サーバーの処理時間はどちらも22ミリ秒で同じです。差の370ミリ秒はすべて接続確立のコストでした。
HTTP/1.1、HTTP/2、HTTP/3 がそれぞれ無くしたもの
バージョンごとに何を解決したのかを区別しておくと、選択が楽になります。
HTTP/1.1 は持続的接続を既定にしました。応答を一つ受け取って接続を閉じる代わりに、そのまま使い続けます。ただし一つの接続の上では、リクエストと応答が順番に一つずつしか行き交いません。パイプライニングは仕様にあったものの、中間装置の互換性問題で事実上廃棄されました。そのため同時性は接続の本数でしか得られません。ブラウザがドメインあたり6本の接続を開く慣行はここから来ています。これが HTTP 層のヘッドオブラインブロッキングです。
HTTP/2 は一つの TCP 接続の上で複数のストリームを多重化します。リクエストを100個同時に送っても接続は一つです。HTTP 層のヘッドオブラインブロッキングは消えます。ヘッダー圧縮とサーバー優先度もここで入りました。
ここで正しておくべき誤解があります。「HTTP/2 は接続が一つだからいつでも速い」という説明は、条件付きでしか正しくありません。TCP は順序を保証するので、セグメントが一つ失われると、そのあとに届いたすべてのデータがカーネルバッファに閉じ込められます。多重化された100本のストリームが全部そろって止まります。HTTP/1.1 の接続6本であれば、損失はそのうち一本にしか影響しなかったはずです。つまり損失率の高いモバイルネットワークでは HTTP/2 のほうが遅くなりえます。TCP 層のヘッドオブラインブロッキングが残っているからです。
HTTP/3 が QUIC の上へ移った理由がまさにこれです。QUIC は UDP の上でストリームごとに独立した損失回復を行います。あるストリームのパケットが消えても、ほかのストリームは進み続けます。おまけに TLS がトランスポート層に統合され、初回接続が 1 RTT、再接続は 0 RTT が可能です。そして接続 ID で接続を識別するので、Wi-Fi から LTE に変わっても接続が維持されます。
実務観点の結論はこうです。ユーザーとエッジの間は HTTP/2 か HTTP/3 が有利です。一方、データセンター内部のプロキシとバックエンドの間は損失率がほぼ0なので HTTP/1.1 の keepalive で十分ですし、むしろ接続数を調整しやすく運用が単純になります。実際、多くの構成ではエッジが HTTP/2、バックエンドが HTTP/1.1 の keepalive です。
プロトコルはこう確認します。
curl -sI --http2 https://api.example.com/v1/health -o /dev/null -w '%{http_version}\n'
curl -sI --http3 https://api.example.com/v1/health -o /dev/null -w '%{http_version}\n'
2
3
タイムアウトが食い違うと生まれる競合状態
ここからが核心です。リクエスト一つが通る経路には、アイドルタイムアウトが最低三つあります。
[クライアントプール] ---- 接続A ---- [ロードバランサー/プロキシ] ---- 接続B ---- [バックエンド]
idle timeout idle timeout keepalive_timeout
接続 B で起きることを時間順に見てみます。バックエンドの keepalive タイムアウトが5秒、ロードバランサーのアイドルタイムアウトが60秒だとします。
- リクエストが処理され、接続 B がアイドル状態になります。
- 5秒が過ぎてバックエンドが FIN を送ります。
- その FIN がロードバランサーに届くまで往復時間の半分がかかります。
- よりによってその間に新しいリクエストが入ってきて、ロードバランサーはまだアイドル一覧にある接続 B にリクエストを書き込みます。
- リクエストがバックエンドに届きます。バックエンドはすでに閉じたソケットなので RST で答えます。
- ロードバランサーはバックエンドが応答なしに接続を切ったと判断し、502 を出します。
バックエンドのアプリケーションログに何も残らない理由がここにあります。リクエストはアプリケーションのコードに到達したことがありません。
発生確率は低いものの0ではありません。そして毎秒数千リクエストなら、低い確率でも一日数百件になります。トラフィックが増えたときにだけ目につく理由です。
原則は一つです。コネクションを閉じる決定は、常にリクエストを送る側が下すべきです。リクエストを送る側が閉じれば競合はありません。自分が使わないと決めた接続だからです。逆に受け取る側が閉じれば必ず競合が生じます。
したがってタイムアウトは、外側から内側へ行くほど長くなければなりません。クライアントプールのアイドルタイムアウトが最も短く、ロードバランサーがそれより長く、バックエンドが最も長くあるべきです。
AWS の ALB の既定のアイドルタイムアウトは60秒なので、バックエンドはそれより余裕をもって長く取ります。
# nginx がバックエンドのとき — ALB の60秒より長く
keepalive_timeout 75s;
keepalive_requests 10000;
# Node.js バックエンド
# server.keepAliveTimeout = 75000;
# server.headersTimeout = 80000; # keepAliveTimeout より大きくなければならない
# Go バックエンド
# srv := &http.Server{ IdleTimeout: 75 * time.Second }
Node.js の既定の keepAliveTimeout が5秒だという事実は、とりわけ頻繁に事故を起こします。ALB や nginx の後ろに Node サーバーをそのまま載せると、上のシナリオがそのまま再現します。headersTimeout を keepAliveTimeout より大きくしておくことも合わせて覚えておくべきです。
nginx がプロキシ側のときは、アップストリームの keepalive を有効にする設定を落としがちです。三行すべてがそろって初めて実際に再利用されます。
upstream backend {
server 10.0.3.11:8080;
keepalive 64; # ワーカーあたり維持するアイドルコネクション数
keepalive_timeout 60s;
keepalive_requests 10000;
}
server {
location / {
proxy_pass http://backend;
proxy_http_version 1.1; # ないと 1.0 で出ていき keepalive が無効になる
proxy_set_header Connection ""; # 既定の close ヘッダーを除去しなければならない
}
}
proxy_http_version 1.1 と空の Connection ヘッダーのどちらか一つでも欠けると、アップストリームの接続がリクエストのたびに新しく開かれます。設定はあるのに効果がないという申告のほとんどが、この二行です。確認はバックエンドで数えます。
# バックエンドでプロキシから来た ESTABLISHED 接続数を数える
ss -tan state established '( sport = :8080 )' | wc -l
watch -n1 "ss -tan state established '( sport = :8080 )' | wc -l"
この値がリクエスト量に比例して上下し続けるなら再利用されておらず、安定した水準で維持されるなら再利用されています。
競合状態を確率的に減らすこととは別に、クライアント側のリトライも合わせて備えるべきです。Go の net/http は、再利用された接続で応答バイトを一つも受け取る前に失敗した場合、冪等なリクエストを自動でもう一度試みます。Java の Apache HttpClient は validateAfterInactivity で貸し出す前に接続状態を検査します。こうした安全装置のないクライアントなら、GET や PUT のような冪等なリクエストに限って明示的なリトライを入れるほうがよいでしょう。
curl -w で区間を分けてボトルネックを特定する
遅延を報告するとき「遅い」という表現は役に立ちません。どの区間が遅いのかが、そのまま担当チームと対処を決めます。curl のタイミング変数がこの仕事を正確にやってくれます。
| 変数 | 測定する区間 | 大きくなったら疑うもの |
|---|---|---|
| time_namelookup | 開始から DNS 解決完了まで | リゾルバの遅延、search ドメイン過多、キャッシュ未適用 |
| time_connect | DNS 完了から TCP ハンドシェイク完了まで | 物理的距離、経路の輻輳、SYN 再送 |
| time_appconnect | TCP 完了から TLS ハンドシェイク完了まで | TLS 1.2 の使用、証明書チェーン過多、OCSP 照会 |
| time_pretransfer | リクエスト送信の直前まで | プロキシ交渉、クライアント側の準備遅延 |
| time_starttransfer | リクエスト送信後から最初の応答バイトまで | サーバー処理時間、バックエンドのキューイング、DB 遅延 |
| time_total | 全体 | 本文の転送量、帯域、受信側の処理速度 |
読み方は引き算です。
curl -s -o /dev/null -w "@/tmp/curl-format.txt" https://api.example.com/v1/orders
time_namelookup: 0.004312s
time_connect: 0.031104s
time_appconnect: 0.098742s
time_pretransfer: 0.098901s
time_starttransfer: 0.341285s
time_total: 0.343990s
- DNS: 4.3ミリ秒です。正常です。
- TCP ハンドシェイク: 31.1から4.3を引くと26.8ミリ秒、つまり RTT はおよそ27ミリ秒です。
- TLS: 98.7から31.1を引くと67.6ミリ秒です。RTT のおよそ2.5倍なので TLS 1.2 の可能性が高いです。TLS 1.3 なら27ミリ秒あたりのはずです。
- サーバー処理: 341.3から98.9を引くと242.4ミリ秒です。全体の70パーセントです。
- 本文転送: 344.0から341.3を引くと2.7ミリ秒です。
結論は明確です。このリクエストのボトルネックはネットワークではなくサーバーの処理時間です。ただし TLS 1.3 に上げれば40ミリ秒をさらに削れますし、コネクションを再利用すれば95ミリ秒をまるごと無くせます。
何度も測って分布を見るにはこう使います。
for i in $(seq 1 20); do
curl -s -o /dev/null -w '%{time_connect} %{time_appconnect} %{time_starttransfer} %{time_total}\n' \
https://api.example.com/v1/orders
done | sort -k4 -n | tail -5
0.028112 0.094221 0.298104 0.301002
0.029004 0.096118 0.312880 0.315442
0.031104 0.098742 0.341285 0.343990
0.030221 0.097009 0.512033 0.515118
0.029880 0.095442 1.204118 1.207002
前の二列は安定しているのに三列目だけ跳ねるなら、ネットワークではなくサーバー側のテールレイテンシです。逆に time_connect が跳ねるなら、そのときこそネットワークを見る番です。
コネクションプールのサイズ算定
プールのサイズは勘で決める値ではありません。リトルの法則で計算します。
同時に浮いている必要のあるリクエスト数は、スループットと応答時間の積です。
同時リクエスト数 = 秒間リクエスト数 × 平均応答時間
例) インスタンス一台が秒間500リクエスト、平均応答80ミリ秒
500 × 0.08 = 40
テールレイテンシを見込んで1.5倍の余裕を取る
推奨プールサイズ = 60
ここに二つの上限を合わせて見る必要があります。
一つめ、接続の総数です。アプリケーションのインスタンスが40台で各プールが60なら、バックエンドは最大2400本の接続を受けることになります。バックエンドのファイルディスクリプタ上限と最大接続設定がこれを賄えなければなりません。データベースなら特に危険です。Postgres の max_connections が200なのにアプリケーションのプール総和が2400なら、デプロイ直後の接続殺到で障害になります。
二つめ、アイドルコネクションを維持するコストです。プールを大きく取ると大半がアイドル状態で残り、その接続たちが先ほど見た競合状態の候補になります。必要以上に大きく取る理由はありません。
主要ランタイムの既定値も知っておく必要があります。Go の http.DefaultTransport は MaxIdleConns が100ですが、ホストあたりのアイドル接続である MaxIdleConnsPerHost は2です。この値を上げないと、一つのバックエンドにいくら多くリクエストしてもアイドル接続は2本しか維持されず、残りは毎回新しく開かれます。マイクロサービスで最も頻繁に見落とされる既定値です。
# Go で必ず調整すべき値
# t := http.DefaultTransport.(*http.Transport).Clone()
# t.MaxIdleConns = 200
# t.MaxIdleConnsPerHost = 100
# t.IdleConnTimeout = 90 * time.Second
実際の再利用率はこう確認します。
# クライアントホストから特定のバックエンドへ向かう接続状態の分布
ss -tan dst 10.0.3.11 | awk 'NR>1 {print $1}' | sort | uniq -c | sort -rn
58 ESTAB
3 TIME-WAIT
ESTAB が安定して維持され TIME-WAIT が少なければ、再利用がうまくできています。逆の形なら毎リクエスト新しい接続を開いている最中です。
TIME_WAIT が問題になる条件とならない条件
ss -tan | grep TIME-WAIT | wc -l が数万を叩き出すのを見て驚くことがよくあります。ほとんどは問題ではありません。いつ問題になるのかを正確に分けるべきです。
TIME_WAIT は接続を先に閉じた側、つまりアクティブクローズをした側にだけ生じます。Linux では60秒固定であり sysctl で調整できません。目的は二つです。遅れて届いた古いセグメントが同じ4タプルの新しい接続に混ざるのを防ぐことと、最後の ACK が失われたときに再送できるようにすることです。
問題にならない場合から見てみます。
サーバーが応答後に接続を閉じる構成なら、TIME_WAIT はサーバー側に積もります。ところがこれらの項目はローカルポートがすべて443で同じであり、リモートアドレスとポートだけが違います。4タプルが重ならないのでポート枯渇は起きません。残るコストはメモリだけであり、項目あたり数百バイト程度です。3万個でも数十メガバイトです。無視して構いません。
問題になる場合は違います。アウトバウンド接続を大量に開く側です。プロキシ、API ゲートウェイ、バッチ処理がこれに該当します。このときは宛先の IP とポートが固定されているので、区別されるのはローカルポートだけです。
sysctl net.ipv4.ip_local_port_range
net.ipv4.ip_local_port_range = 32768 60999
使用可能なポートが28232個で、各ポートが60秒間縛られます。つまり一つの宛先に対して毎秒およそ470本の新規接続が理論上の上限です。それを超えるとこんなエラーが出ます。
dial tcp 10.0.3.11:8080: connect: cannot assign requested address
この EADDRNOTAVAIL がポート枯渇の本当の合図です。TIME_WAIT の個数そのものではなく、このエラーが出るかどうかを見るべきです。
# 宛先別に TIME-WAIT を数えて、どこが枯渇しているのかを見る
ss -tan state time-wait | awk 'NR>1 {print $4}' | cut -d: -f1 | sort | uniq -c | sort -rn | head
26104 10.0.3.11
412 10.0.3.12
88 169.254.169.254
ここで広まっている誤った処方を整理しておく必要があります。
net.ipv4.tcp_tw_recycle は使ってはいけません。NAT の背後の複数クライアントが互いに違うタイムスタンプを送ると接続が無作為に拒否されるという深刻な問題があり、そのため Linux 4.12 で完全に削除されました。いまだにこの値を勧めるブログが多くあります。
net.ipv4.tcp_tw_reuse は条件付きで有効です。アウトバウンド接続にだけ適用され、タイムスタンプオプションが両側で有効になっている必要があります。サーバー側に積もった TIME_WAIT には何の効果もありません。
# アウトバウンドの多いホストでだけ意味がある
sudo sysctl -w net.ipv4.tcp_tw_reuse=1
sudo sysctl -w net.ipv4.ip_local_port_range="10240 65535"
ポート範囲を広げれば上限はおよそ920まで上がります。しかしこれらはすべて症状の緩和です。
本当の解法は、コネクションを再利用して新規接続そのものを減らすことです。毎秒470本もの新規接続が必要な理由は何なのかを、まず問うべきです。keepalive が無効になっているか、プールがないか、リクエストのたびにクライアントオブジェクトを新しく作っている可能性が高いです。Python の requests で requests.get() を直接呼ぶコードが代表例です。Session オブジェクトを作って再利用すれば、この問題はまるごと消えます。
おわりに — 順序を揃えて再利用してください
三つの文にまとめられます。
間欠的な 502 でバックエンドのログが空なら、コネクション再利用の競合を疑い、タイムアウトの順序を確認してください。リクエストを送る側のアイドルタイムアウトが最も短く、受け取る側が最も長くなければなりません。バックエンドの keepalive をロードバランサーのアイドルタイムアウトより余裕をもって長く取ることが、この原則の具体的な適用です。
遅延を報告するときは必ず区間を分けてください。curl の namelookup、connect、appconnect、starttransfer の四点さえあれば、DNS の問題なのか距離の問題なのか TLS 設定の問題なのかサーバー処理の問題なのかが即座に分かれます。この四つの数字なしに行う性能議論は、ほとんどが推測です。
そして TIME_WAIT の個数に驚く前に、cannot assign requested address が実際に出ているかを確認してください。sysctl をいじるよりコネクションを再利用するほうが常に優れています。接続を開くコストは遠距離通信では応答時間の半分を超えることもあり、そのコストを無くすことはたいていのアプリケーション最適化より効果が大きいのです。
현재 단락 (1/171)
トラフィックが増えたあとから、こんな報告が上がってきます。