こちらは iRidge Advent Calendar 2020 20 日目の記事です。
サーバーサイドエンジニアの @orfx がお送りします。
TL;DR
AWS の NAT ゲートウェイには通信のアイドル状態が350秒以上続くと、タイムアウトする仕様があります。
インターネット接続が 350 秒後に中断される
問題
インスタンスはインターネットにアクセスできますが、350 秒後に接続が切断されます。
原因
NAT ゲートウェイを使用する接続が 350 秒以上アイドル状態のままになっていると、その接続はタイムアウトします。
ソリューション
接続が中断されないように、接続を介して追加のトラフィックを開始することができます。または、インスタンスで、350 秒未満の値で TCP キープアライブを有効にできます。
この仕様によって、例えばリクエストを受け付けてからレスポンスを送信し始めるのに長時間かかるようなAPIへのリクエストを行う場合、NAT ゲートウェイ側でタイムアウトによって接続を切断されてしまい、永遠にレスポンスが返ってこない事象が発生する事があります。
通常の対処法
対処法としては、ドキュメント記載の通り TCP キープアライブ を調整すれば切断されなくなります。
例えば、Linux を使用していて、カーネルパラメータを変更できる環境である場合、下記パラメータを 350 秒未満に設定します。Linux デフォルトは 7200 秒です。
net.ipv4.tcp_keepalive_time
また、関連して下記のカーネルパラメータも変更すると、通信途中で何らかの理由により疎通不可になった際、切断までにかかる時間を調整できます。
net.ipv4.tcp_keepalive_intvl
net.ipv4.tcp_keepalive_probes
ECS Fargate での対処法
ECS Fargate 環境の場合、2020年12月時点ではカーネルパラメーターの変更はサポートされていません。
そのため、通信を行うアプリケーションからTCP キープアライブの設定を行う必要があります。
Python socket
Python 標準ライブラリの socket を使った通信であれば、socket.setsockopt() を使用して設定することができます。
下記の例の様に、 二番目の引数に対象のカーネルパラメータ、三番目の引数に設定したい値を渡します。
import socket
s = socket.socket()
s.setsockopt(socket.SOL_SOCKET, socket.SO_KEEPALIVE, 1) # keepalive 有効化
s.setsockopt(socket.IPPROTO_TCP, socket.TCP_KEEPIDLE, 349) # tcp_keepalive_time
s.setsockopt(socket.IPPROTO_TCP, socket.TCP_KEEPINTVL, 10) # tcp_keepalive_intvl
s.setsockopt(socket.IPPROTO_TCP, socket.TCP_KEEPCNT, 3) # tcp_keepalive_probes
Python requests
OSS ライブラリの requests は同じく OSS ライブラリの urllib3 をラップした作りになっており、HTTPConnection.default_socket_options に設定を追加することで、requests を使った通信でも TCP キープアライブの設定を行うことができます。
urllib3 もまた、sock.setsockopt() を内部で呼び出しているので、追加する設定は socket の例とほぼ同様の形になります。
import requests
import socket
import sys
from urllib3.connection import HTTPConnection
HTTPConnection.default_socket_options = HTTPConnection.default_socket_options + [
(socket.SOL_SOCKET, socket.SO_KEEPALIVE, 1),
(socket.IPPROTO_TCP, socket.TCP_KEEPIDLE, 349),
(socket.IPPROTO_TCP, socket.TCP_KEEPINTVL, 10),
(socket.IPPROTO_TCP, socket.TCP_KEEPCNT, 3),
]
test = requests.get("http://google.com/")
調査経緯
ここからは対処法を求めて閲覧された方には蛇足になりますが、この様な調査が必要となった経緯をお話しさせていただきます。
発端は、弊社のとあるウェブサービスの管理画面にて、CSVファイルのダウンロードで 504 Gateway Time-out が発生する、とのお問い合わせでした。
この管理画面は ECS Fargate 上で稼働している Python アプリケーションで、別のバックエンドAPIからCSVファイル生成に必要なデータを生成しています。
当該リクエストは、各コンポーネントのログに下記のように記録されていました。
| ログ | レスポンスタイム | レスポンスコード | 備考 |
|---|---|---|---|
| ALB1 アクセスログ | - | ELB 504 | アイドルタイムアウト(設定値: 1,200秒) による切断 |
| 管理画面 nginx ログ | 1200.000 sec | HTTP 499 | アイドルタイムアウト(設定値: 1,200秒) による切断 |
| ALB2 アクセスログ | 363.627 sec | HTTP 200 |
この記録は NAT ゲートウェイの仕様を把握していなかった私にとって奇妙なものでした。504 Gateway Time-out のレスポンスは、ALB によってアイドルタイムアウトでレスポンスされたものでしたが、バックエンド API は6分程で正常にレスポンスを送信していたからです。
このような調査は検証環境で再現できるかどうかで解決難易度が大きく変わるため、まず再現方法を模索しました。その結果、どうやらCSVファイルのダウンロード時間が360秒を超えるリクエストは高確率で再現することが判明しました。しかし、各種ミドルウェアやインフラコンポーネントに360秒前後で何か閾値を設定している箇所は見当たりませんでした。
次に疑いの目をアプリケーション側の実装に移し、ローカル環境での検証を始めたのですが、そこで不幸にも同様の事象が再現してしまいました。これはローカル環境のネットワークで偶然似たような設定が入っていたことによるものと後から判明したのですが、アプリケーション側の実装によるものと誤認した私は、通信に使用するライブラリをより深く調査する作業に入りました。ここで requests の構造や、VS Code の Python デバッガが機能豊富で強力なこと、hyper や curl では再現しないなど、結果的には対処法の検討に役立った知見を得られたのですが、根本原因はアプリケーションの実装ではなかったため、調査は当然行き詰りました。
最終的にはネットワーク側の調査に再度入り、tcpdump でパケットレベルで調査を行い始めつつ、ふと NAT ゲートウェイに疑いの目を向けたところ、アイドルタイムアウトの仕様が記載されたAWS公式ドキュメントを発見し、あっけない解決となりました。
対処法の検討
発見したAWS公式ドキュメントにはTCP キープアライブによる対処法も書かれていましたが、管理画面が稼働している ECS Fargate はカーネルパラメータをタスク定義から直接変更する機能はサポートされていないことを、別件の調査で把握していました。そのため、別の方法でTCP キープアライブを設定する方法を探す必要がありましたが、これまでの調査で得た知見が役に立ち、バックエンドAPIへのリクエストに使用している requests をそのまま使用しつつ、シンプルに設定する方法を見つけることが出来ました。
ECS Fargate 環境でもTCP キープアライブの設定が反映されていることの検証には、リクエスト先のバックエンドAPIを模した EC2 サーバで tcpdump を行い、TCP Keep-Alive パケットが設定値通りの間隔で ECS Fargate 環境のアプリケーションから送信されていることを確認しました。
最後に
このような対処法を行ったところ、同様の事象は発生しなくなり、問題を解決することができました。結果的には、単にAWSマネージドサービスの仕様によるものであり、対処法もシンプルな修正となりましたが、そこにたどり着くまでには、何回もの観察・推論・仮説・検証・考察のサイクルが必要となりました。今回は、誤った仮説に導く不運な偶然も発生し、最短距離での解決とはなりませんでしたが、寄り道で得た知見は無駄ではなく、いつか役に立つものだと信じて、これからも問題解決に当たりたいと思います。