まとめ
Terminate instance on failureをfalseにしてもテスト用のインスタンスは殺される- S3へのログ保存は絶対に有効にしろ
- ステップはなるべく小分けに
事の起こり
- EC2 ImageBuilder でゴールデンAMIを作っている
- ある日昨日まで成功してたテストをパスしなくなった
- エラー内容を見ても
failed to run commands: exit status 1のようなのでよくわからない
デバッグ
AWS Systems Manager オートメーション
EC2 ImageBuilder のタスクは、AWS Systems Manager オートメーションを利用して動いています。 [AWS Systems Manager] => [アクションと変更] => [自動化] から自動化の実行の一覧を確認します。
- ImageBuilderBuildImageDocument
- ImageBuilderTestImageDocument
がそれぞれ、ビルド、テストに使ったドキュメントです。
ですが、ここだけ見てもエラーの詳細はさっぱりわからないので後に書く S3 へのログのアップロードを有効化しておく必要があります。
Image Pipeline の Troubleshooting settings
Image Pipeline を作るとき、変更するときに指定できるデバッグ用のオプションが用意されています。 デフォルトでは無効になっているので注意しましょう。
Terminate instance on failure
デフォルトで true チェックを外すとビルド失敗時にビルドに使ったEC2インスタンスを起動したままにしておいてくれるので、実際に環境にログインして調査することができます。
ただ、テストフェーズで失敗した場合は機能しないようです。
なお、EC2インスタンスはプライベートサブネットに作成されるため、SSHには踏み台が必要です。
Key pair
Logs
設定すると、自動化処理中の以下のようなログを指定したS3バケットにアップロードしてくれます。 Image pipelineの実行IAM roleに指定したS3バケットへのPut権限をつける必要があると思います。 S3バケット中のフォルダ名は、AWS Systems Manager オートメーションの自動化の実行IDを元にした名前になるので、まず実行IDを特定して、S3を探すことになります。
実行IDは EC2 Image Builder images の実行の詳細画面 Reason for failure に書いてあります。 または、AWS Systems Manager オートメーションの自動化の一覧から探してもよいでしょう。
ログフォルダの中身は以下のような内容になっています。
detailedoutput.json
どのステップで失敗したのか？どんなコマンドを実行したのか？がわかります。
{ "executionId": "02bb195c-7143-11ea-a1f0-0603d891b362", "status": "failed", "startTime": "2020-03-29T07:25:22+09:00", "endTime": "2020-03-29T07:27:32+09:00", "failureMessage": "Document TOE_2020-03-28_22-25-21_UTC-0_02bb195c-7143-11ea-a1f0-0603d891b362/0__myapp-install__0.0.7_1.yml failed!", "documents": [ { "name": "MyApp Install", "filePath": "TOE_2020-03-28_22-25-21_UTC-0_02bb195c-7143-11ea-a1f0-0603d891b362/0__myapp-install__0.0.7_1.yml", "status": "failed", "description": "This is MyApp Install testing document.", "startTime": "2020-03-29T07:25:22+09:00", "endTime": "2020-03-29T07:27:32+09:00", "failureMessage": "Phase test failed!", "phases": [ { "name": "test", "status": "failed", "startTime": "2020-03-29T07:25:22+09:00", "endTime": "2020-03-29T07:27:32+09:00", "failureMessage": "Step CheckResponse failed!", "steps": [ { "name": "HelloWorldStep", "status": "success", "failureMessage": "", "timeoutSeconds": 7200, "onFailure": "Abort", "maxAttempts": 1, "action": "ExecuteBash", "startTime": "2020-03-29T07:25:22+09:00", "endTime": "2020-03-29T07:25:22+09:00", "inputs": "[{\"commands\":[\"echo \\\"Hello World! Test.\\\"\"]}]", "outputs": "[{\"stdout\":\"Hello World! Test.\"}]" } { "name": "CheckResponse", "status": "failed", "failureMessage": "exit status 244", "timeoutSeconds": 7200, "onFailure": "Abort", "maxAttempts": 3, "action": "ExecuteBash", "startTime": "2020-03-29T07:27:26+09:00", "endTime": "2020-03-29T07:27:32+09:00", "inputs": "[{\"commands\":[\"echo \\\"curl -LI http://localhost/\\\"\\nSTATUS_CODE=$(curl -LI http://localhost/ -o /dev/null -w '%{http_code}\\\\n' -s)\\nif [[ $STATUS_CODE == \\\"200\\\" ]]; then\\n echo \\\"MyApp was successfully invoked.\\\"\\nelse\\n echo \\\"MyApp was not successfully invoked. Failing.\\\"\\n exit $STATUS_CODE\\nfi\\n\"]}]", "outputs": "null" },
console.log
どのステップで失敗したのか？どんなコマンドを実行したのか？がわかります。
2020-03-29 07:25:22 Info Document TOE_2020-03-28_22-25-21_UTC-0_02bb195c-7143-11ea-a1f0-0603d891b362/0__myapp-install__0.0.7_1.yml 2020-03-29 07:25:22 Info Phase test 2020-03-29 07:25:22 Info Step HelloWorldStep 2020-03-29 07:25:22 Info Command execution completed successfully 2020-03-29 07:25:22 Info Stdout: Hello World! Test. 2020-03-29 07:25:22 Info Stderr: 2020-03-29 07:25:22 Info ExitCode 0 2020-03-29 07:27:26 Info Step CheckMonitorStatus 2020-03-29 07:27:27 Info Command execution resulted in an error 2020-03-29 07:27:27 Info Stdout: curl -LI http://localhost/ MyApp was not successfully invoked. Failing. 2020-03-29 07:27:27 Info Stderr: 2020-03-29 07:27:27 Info ExitCode 244 2020-03-29 07:27:29 Info Command execution resulted in an error 2020-03-29 07:27:29 Info Stdout: curl -LI http://localhost/ MyApp was not successfully invoked. Failing. 2020-03-29 07:27:29 Info Stderr: 2020-03-29 07:27:29 Info ExitCode 244 2020-03-29 07:27:31 Info Command execution resulted in an error 2020-03-29 07:27:31 Info Stdout: curl -LI http://localhost/ MyApp was not successfully invoked. Failing. 2020-03-29 07:27:31 Info Stderr: 2020-03-29 07:27:31 Info ExitCode 244
なお、今回の原因
ログを確認したところ、テストフェーズでdockerのインストールなどを行ったこともあり、disk full になったのが原因でした。 ImageBuilder で使うEC2インスタンスのストレージサイズを変更したレシピを作成したところ成功しました。
