AWS SAM CLI のトラブルシューティング

はじめに

こんにちは、DevOps グループの中島です。

サーバレスアプリケーションを AWS 上に構築する際に便利なフレームワークとして AWS SAM を利用する方法があります。弊社でもいくつかのプロジェクトでサーバレスアプリケーションの構築に利用しています。

今回は AWS SAM CLI を利用したデプロイにおいて、見慣れないエラーが発生した際に行ったトラブルシューティング内容について紹介します。

エラーの内容

sam deploy コマンドにおいて、以下のエラーが発生しました。

File with same data already exists at xxx, skipping upload
...
    Deploying with following values
    ===============================
    Stack name                   : ...
    Region                       : ap-northeast-1
    Confirm changeset            : False
    Disable rollback             : False
    Deployment s3 bucket         : xxx
    Capabilities                 : ["CAPABILITY_IAM"]
    Parameter overrides          : {"xxx": "xxx"}
    Signing Profiles             : {}
Initiating deployment
=====================
File with same data already exists at xxx.template, skipping upload
Waiting for changeset to be created..
Error: Waiter ChangeSetCreateComplete failed: Max attempts exceeded
ERROR: Job failed: exit code 1

Error: Waiter ChangeSetCreateComplete failed: Max attempts exceeded

エラーの内容から、チェンジセットの作成完了を待つ Waiter で試行回数を超過していることが読み取れます。

Waiter とは

Waiter は AWS SDK に実装されている、非同期処理の完了までブロックする機能です。

例えば EC2 インスタンスの作成など時間がかかる API では、作成を開始したというレスポンスがすぐに返却されますが、その時点では作成完了していません。
Waiter を利用することで、作成完了してステータスが running になった時点で処理を継続することができます。

今回の ChangeSetCreateComplete は Cloudformation の Waiter で、
チェンジセットの作成完了を待機するものです。

チェンジセットは作成されたのか

SAM CLI からはチェンジセット作成完了まで確認ができなかったということなので
実際に作成されているかをコンソールから確認してみると、問題なく作成はされています。
結果的に作成は完了しているが、AWS SAM 上ではそれが確認できずにエラーとなっていることが分かります。

Waiter のリトライ頻度

aws cli waiter changeset などで検索して AWS CLI のドキュメントを見つけると、
以下のように記載があります。

It will poll every 30 seconds until a successful state has been reached. This will exit with a return code of 255 after 120 failed checks.

30秒 * 120 回なので 1 時間でタイムアウトとなるようになっています。
しかし、今回のデプロイはそれほど待っていないので、この値が使われていないと考えられます。

AWS のせいにしたい気持ち

ここまで来たら Cloudformation の特定のエンドポイント (チェンジセットの作成状態を確認する API) が落ちてるのではないか、そう考えるのが自然ではないでしょうか。
~~大体いつもしれっと落ちてしれっと復旧して報告ないですからね。~~
しかし、以下のように AWS CLI から実行してみると、すぐに完了してしまいました。

aws cloudformation wait change-set-create-complete --change-set-name xxx

再度デプロイしても同様のエラーだったのでエンドポイントが落ちていたわけではなさそうです。

AWS SAM CLI のソースを見に行く

ここでタイムアウトの設定値が短すぎる説を検証します。
AWS SAM CLI のコードを適当に grep すると、ユーザ設定の値で上書きしていることが分かります。

# Wait for changeset to be created
waiter = self._client.get_waiter("change_set_create_complete")
# Use default client_sleep to set the delay between polling
# To override use SAM_CLI_POLL_DELAY environment variable
waiter_config = {"Delay": self.client_sleep}
try:
    waiter.wait(ChangeSetName=changeset_id, StackName=stack_name, WaiterConfig=waiter_config)

client_sleep の値はデフォルトでは 0.5 秒となっていて
リトライ回数は未設定なのでデフォルトの 120 回とすると 0.5 秒 * 120 回となり 1 分でタイムアウトしそうです。
デプロイから 1 分ほどでエラーとなっていたので、このタイムアウト値なら今回の事象と合致します。