nisshiee.org

AWS Fargateのログが出力されない問題に対する仮説

2019-01-06

※ 注意

この記事に書いてある内容は、 「仮説」 と 「仮説に基づいたワークアラウンド」 です。
ワークアラウンドがちゃんと機能したため、遊びで使っていた僕はこれ以上踏み込みません。プロダクトで同じ問題が発生した場合はAWSのサポートに問い合わせてみると良いかもしれません。

実行しようとしていたタスク

AWS Fargateを使って以下のようなタスクを実行した。

  • タスクの実行時間は3秒程度
  • タスクの終了間際にログが出力される
    • Log Driverはawslogsを使用
  • CloudWatch Eventsでスケジュール実行

参考: タスク定義は↓こんな感じ

[
  {
    "name": "test",
    "image": "${ecr_server}/nisshiee/task:latest",
    "memory": 512,
    "memoryReservation": 384,
    "cpu": 256,
    "essential": true,
    "command": ["test", "start"],
    "environment": [
      {
        "name": "LOG_LEVEL",
        "value": "debug"
      }
    ],
    "logConfiguration": {
      "logDriver": "awslogs",
      "options": {
        "awslogs-group": "task",
        "awslogs-region": "ap-northeast-1",
        "awslogs-stream-prefix": "test",
        "awslogs-multiline-pattern": "^[FEWID],"
      }
    }
  }
]

起きた現象

Log Driverにawslogsを指定し、CloudWatch Logsでログを確認できることを期待していた。
しかし、実際には以下のような現象に遭遇した。

  • CloudWatch Logsで想定通りログを確認できるときとできないときがある

  • 「ログが確認できない」というのは、以下のような状況

  • 体感では、マネジメントコンソールからタスク実行したときより、CloudWatch Eventsでスケジュール実行したときの方がログ消失しやすい

    • 十分な回数試行して計測したわけではない

仮説

「CloudWatch Logs Agentがログを送信する前に居なくなってるのではないか」

状況証拠すらないので、正直、仮説というよりはただの勘。

  • 短い実行時間のタスクの終了間際にログが出力されている
  • ECS自体はもともと常駐するサービスを前提に設計されているハズ
  • 「なんかファイルクローズを忘れたときの挙動に似てるなぁ」みたいな直感

みたいなふんわりとした感覚で思いついただけで、あんまりカッコイイ原因特定ではない。

ワークアラウンド

手段

CloudWatch Logs エージェントのリファレンス - AWS ドキュメント

Fargateクラスタでこれと同じAgentが動いているという保証はないのだが、一旦これがデフォルト設定で動いていると仮定すると、

buffer_duration
ログイベントのバッチ期間を指定します。最小値は 5000ms で、デフォルト値は 5000ms です。

とのことなので、仮説が正しければ、最後のログが出力されてから5秒以上待ってからタスクが終了すれば全てのログがCloudWatch Logsに送られるはず。

というわけで、Docker ImageのENTRYPOINTに指定しているシェルスクリプトの最後に以下の行を追加した。

sleep 10

結果

この記事を書いている時点で、ワークアラウンドを実施してから15回程度しかタスク実行していないのだが、今のところ全てのタスクで正常にログが記録されている。