FireLensコンテナが137で終了するケースの１つ
はじめに
こんにちは。都内でソフトウェアエンジニアをしているtomoriです。
少し前からECSタスク内の FireLens コンテナが137で終了することがちらほら発生しており、その対応を行っていたので備忘録として記事にします。
簡単に言うと、コンテナ間の依存関係は正しく制御しましょう、と言う記事です。
前提や構成など
私が携わっている開発プロダクトでは、 ECS on Fargate のスケジュールされたタスクを使用して定期バッチ処理を実行しています。
タスクのコンテナ定義は、バッチ処理を行うためのアプリケーションコンテナと、そのログを収集するためのサイドカーコンテナの２つから構成されています。
また、ログ収集のためのサイドカーコンテナには Fluent Bit で動作する FireLens for Amazon ECS を使用しています。
バッチ処理用のタスク内で起動していたコンテナが0以外のステータスで終了していた場合、EventBridgeがトリガーされSlackにアラートが飛んでくるような構成になっています。
発生していた事象
- ちらほらとSlackにアラートが飛んでくるようになった
- タスクを確認すると、アプリケーションコンテナは終了ステータス0で正常終了しているが、ログ収集用のサイドカーコンテナが137で異常終了している
- アプリケーションコンテナのログはサイドカーコンテナによって正常に収集できている
- サイドカーコンテナ自身のログにはシグナルを受信した旨のログが出力されていない
通常 Fluent Bit はシグナルを受信した際、以下のようなメッセージをログとして出力します。
[2024/09/01 00:21:14] [engine] caught signal (SIGTERM)
また、タスク内のコンテナが137で終了する要因としては以下の２つがあるとされています。
- コンテナが SIGKILL を受信して強制終了された
- メモリ容量が不足し Out-of-memory (OOM) になった
137: Occurs when the Task was forced to exit (SIGKILL) for the container.
If you don't respond to a SIGTERM within a default 30-second period, then the SIGKILL value is sent and containers are forcibly stopped. You can configure the default 30-second period on the ECS container agent with the ECS_CONTAINER_STOP_TIMEOUT parameter. This exit code can also occur in an Out-of-Memory (OOM) situation. To verify whether OOM occurred, review your CloudWatch metrics.
対応
「メモリをそこまで必要とする処理ではない点」、「アプリケーションは正常終了している点」、「サイドカーコンテナ自身のログにシグナルを受信した旨のログが出力されていない点」の３点から、何らかの理由でサイドカーコンテナが SIGTERM を受信できず、最終的に実行環境から送信される SIGKILL によって強制終了されてしまっている、という仮説を立てました。
この ”何らかの理由でサイドカーコンテナが SIGTERM を受信できていない” という箇所に関して、「単に Fluent Bit のシグナルハンドラが登録される前に SIGTERM が送信されていて、 SIGTERM の処理がスルーされたまま30秒が経過し SIGKILL を受信してしまったんじゃないか？」と考え、起動順番を見直すことにしました。
「タスク定義で FireLens を使用するように設定していた場合、 FireLens のコンテナは FireLens をログドライバーとして使用するコンテナの起動に先立つ」という旨の説明がドキュメント上に記載されていたため、あえてこちら側で起動順やコンテナ間の依存を明記していなかったのですが、これが良くなかったようです。
Unless overridden with our Container Dependency feature, ECS ensures that the FireLens container starts first and stops last. (More precisely, it will start before any containers that use the awsfirelens log driver, and will stop after any containers that use the awsfirelens log driver).
デフォルトの設定だとアプリケーションコンテナの起動は FireLens がスタンバイ状態になっているかどうかまでは見ずに行われる（コンテナの ”起動” をトリガーにしている）ため、おそらく以下のようなフローでタスクが実行されていたのだと思います。
- タスクが起動する
- サイドカーコンテナが先に起動する
- サイドカーコンテナの起動をトリガーにしてアプリケーションコンテナが起動する
- アプリケーションコンテナの処理が完了する
- アプリケーションコンテナが終了する
- サイドカーコンテナに SIGTERM が送信される
- サイドカーコンテナのセットアップが完了し、スタンバイ状態になる
→ シグナルハンドラのセットアップが間に合わず 6 の SIGTERM は無視される - 30秒後にサイドカーコンテナに SIGKILL が送信される
- サイドカーコンテナは137で強制終了される
実際に後からログの日時を確認したところ、極端に実行時間が短い場合、 Fluent Bit のセットアップが完了するよりも前にアプリケーション側の処理が終了することがあるようだったため、こちらを正しく制御するように修正しました。
- サイドカーコンテナでヘルスチェックが実行できるように、 Fluent Bit の追加設定ファイルを読み込むようにする
- サイドカーコンテナの設定に
healthCheckを指定し、ヘルスチェックを導入する - アプリケーションコンテナの設定に
dependsOnを指定し、条件としてサイドカーコンテナの状態がHEALTHYであることを条件に指定する
タスク定義の差分は以下になります。
"containerDefinitions": [
{
"name": "log-router",
"image": "public.ecr.aws/aws-observability/aws-for-fluent-bit:2.32.0",
"logConfiguration": {
"logDriver": "awslogs"
},
"firelensConfiguration": {
+ "options": {
+ "config-file-type": "file",
+ "config-file-value": "/fluent-bit/configs/output-metrics-healthcheck.conf",
+ },
"type": "fluentbit"
},
+ "healthCheck": {
+ "command": [
+ "CMD-SHELL",
+ "curl -f http://localhost:2020/api/v1/health || exit 1"
+ ],
+ "interval": 10,
+ "retries": 5,
+ "startPeriod": 15,
+ "timeout": 3
+ }
},
{
"name": "application",
"image": "xxxxxxxxxxxx.dkr.ecr.ap-northeast-1.amazonaws.com/application:{VERSION}",
"logConfiguration": {
"logDriver": "awsfirelens"
},
+ "dependsOn": [
+ {
+ "condition": "HEALTHY",
+ "containerName": "log-router"
+ }
+ ],
},
],
これにより、 Fluent Bit がスタンバイ状態になった後にアプリケーションが起動することが確約されるようになり、シグナルハンドラ登録前にシグナルを受け取るといったことが発生しなくなります。
対応後は今回のケースに関するアラートは飛んでこなくなりました。
余談
今回 Fluent Bit のヘルスチェックを導入するにあたって、 FireLens 用のイメージ内にプリセットされた設定ファイルが同封されていることを初めて知りました。
「Fargate だと Fluent Bit の設定いじるためだけに自前でカスタムイメージ管理しないといけなくなるの嫌だなぁ」とか思っていたので、これ気づけて良かったです。
おわりに
結果的に行った対応自体はよくありがちな「コンテナ起動順（依存関係）の条件を正しく設定する」という初歩的な話だったのですが、突然発生し始めたと言うこともあり困惑しました。
また、開発環境はデータ量が少ないとはいえバッチ処理ではDBとの通信処理も行っているため、まさか Fluent Bit のセットアップよりも早く終了するとは思っておらず、こちらも盲点でした。
FireLens for Amazon ECS をお使いの方は「アプリケーションの実行時間が極端に短いと FireLens が137で終了することがある」という１つのケースとして頭の片隅にでも入れておくといつか役立つかもしれないです。
今回は別角度からの問題によって依存関係を見直すことになったのですが、この設定を入れないことでログの欠損に繋がる恐れもあるため、ぜひ一度コンテナの起動順や依存関係について見直してみてください。
参考リンク
Discussion