Fluent Bit で ECS コンテナログから特定ログを抽出する

SREチームの左サイドバック @kenzo0107 です。

今回は ECS コンテナログから特定のリクエストによるログを抽出し、 Athena でクエリ捜査できる様にした話です。

コンテナログから特定リクエストによるログを抽出する目的

以下への一助としたい為に実装しました。

• アプリケーションの改善となるデータの集計
• 問題発生時の調査

コンテナログはどのように出力されるか

ECS コンテナログを JSON 形式で出力すると以下の様になります。

{
    "source":"stdout",
    "log":"{\"method\":\"GET\",\"path\":\"/sre/boshuchu\",\"format\":\"html\",\"controller\":\"SRE::BoshuchuController\",\"action\":\"show\",\"status\":200,\"duration\":11.07,\"view\":0.73,\"level\":\"INFO\",\"user_id\":null,\"ip\":null,\"referer\":null,\"user_agent\":null,\"time\":\"2022-09-29T01:14:40+00:00\",\"params\":{}}",
    "container_id": "596d27e777c54922a63fa0d11716ee26-265927825",
    "container_name": "web",
    "ecs_cluster": "main",
    "ecs_task_arn": "arn:aws:ecs:ap-northeast-1:123456789012:task/sre-love/h1a2p3p4y5l6i7f8e9s0r1e2",
    "ecs_task_definition": "sre-love:123"
}

上記例では log キーに lograge で JSON フォーマットされた Rails ログが含まれています。

参考: タスク定義の例 - Amazon Elastic Container Service

上記ログを特に整形せず、Athena でクエリ実行すると log キーに JSON 形式の文字列が表示されます。¹

Athena でクエリ実行した際の log キー : lograge で JSON フォーマットされた Rails ログ

このログにアプリケーションからキーを仕込み、そのキーが存在する場合を特定ログと見做すことができます。

また、この JSON の個々のキーで検索できる様にすることで先述の目的が達成できそうです。

lograge で JSON フォーマットした Rails ログの個々のキーを Athena でクエリ実行できる様にした Glue テーブル

構成

1. ログ配信は Fluent Bit コンテナに委譲
2. 特定ログは Kinesis Firehose に配信
3. コンテナログは CloudWatch Logs に配信²
4. Glue Crawler で S3 に保管されるログをクローリングし Glue テーブル作成
5. Athena から Glue テーブルに対しクエリ実行

Kinesis Firehose 等のリソースの構築は Terraform Cloud Private Registry を利用し手間を省力化しています。

Fluent Bit の処理の流れ

1. 全コンテナログは CloudWatch Logs に output
2. Stream Processor で Rails コンテナログのストリームを作成
3. 上記ストリームを Parser や Filter で整形し Kinesis Firehose に output

以下に Fluent Bit の実装内容をまとめています。³

github.com

トピック

• 実装例として、簡易的に log キーの第一階層に method キーが存在する場合を特定ログとした。
• Stream Processor で全コンテナログから別途 Rails ログをストリームとして作成し整形
• lua で特定ログを抽出
• パフォーマンス向上の為、 cloudwatch でなく cloudwatch_logs を採用

テスト実施方法

実は本ブログのメインはこちらになります。
皆様に聞いてみたかったのが設定ファイルのテスト実施方法についてです。
まずは皆様に聞く前に自身の手の内を見せたいと思います。

概要は以下になります。

1. テスト用 Fluent Bit コンテナを起動
2. テストデータを HTTP Plugin で Input
3. 出力されたデータが想定通りか確認

テストは GitHub Actions で実施してみました。 テスト実施に当たって工夫点を以下にまとめます。

INPUT は HTTP Plugin を採用する

http Input plugin を使用することで Fluent Bit を HTTP 経由で複数の任意のタグ付けしたログを POST できる様になります。

テスト用 Fluent Bit では設定ファイルをラップし http input plugin を設定しています。

test/test.conf#L1-L4

[INPUT]
    Name http

@include extra.conf

.github/workflows/test_fluentbit.yml#L50-L59

      - name: run fluentbit for testing
        run: >
          docker run --rm -d
          --name fluentbit
          ...
          -v $(pwd)/test/test.conf:/fluent-bit/etc/test.conf
          test-fluentbit:latest
          /fluent-bit/bin/fluent-bit -c /fluent-bit/etc/test.conf

他 Plugin との比較

• dummy input plugin は、テスト毎に conf ファイルを読み込ませ直す必要があり、 fluentbit を起動する必要があり、実行時間が掛かります。複数の dummy データを流すことも可能ですが、結果の判定のしにくさがありました。
• tail input plugin は、 上記同様、テスト毎に conf ファイルを読み込ませる必要があります。
• tcp input plugin は、外部からタグ指定できません。

テスト用に output.conf を上書き

商用環境で利用する output.conf を使用すると GitHub Actions 上のテスト時には Kinesis Firehose への接続ができずエラーとなる為、 テスト用に output.conf で上書きしエラーを回避しています。⁴

test/output.conf

[OUTPUT]
    Name file
    Match *
    Path /tmp/

[OUTPUT]
    Name stdout
    Match *

.github/workflows/test_fluentbit.yml#L56

        run: |
          docker run --rm -d \
          -v $(pwd)/docker/fluentbit/test/output.conf:/fluent-bit/etc/output.conf \
          test-fluentbit:latest \

file output plugin を利用しているのは、整形後のログをファイルとして出力し結果比較に利用します。

GitHub Actions 上で docker run で起動したコンテナにアクセスする為に network 作成

GitHub Actions 上で docker run で起動したコンテナは 127.0.0.1 ではアクセスできません。 その為、 docker network を作成しその network 上から curlimages/curl:latest 経由で curl ã‚’ fluentbit コンテナに対し実行しています。

.github/workflows/test_fluentbit.yml#L45-L70

      - name: fluentbit コンテナへ外部から http 経由でアクセスすべく、docker network を作成
        run: docker network create actions

      - name: run fluentbit for testing
        run: >
          docker run --rm -d
          --name fluentbit
          --network actions
          ...
          test-fluentbit:latest
          /fluent-bit/bin/fluent-bit -c /fluent-bit/etc/test.conf

      # NOTE: http://fluentbit:9880/web-firelens-dummy に対して curl することで
      #       tag=web-firelens-dummy を付与したログを fluentbit に POST できる。
      - name: fluentbit コンテナへ Rails コンテナログを http 経由で POST する
        run: >
          docker run --rm
          --network actions
          --link fluentbit:fluentbit
          -v $(pwd)/docker/fluentbit/test/web_container.log:/tmp/web_container.log
          curlimages/curl:latest -v -d @/tmp/web_container.log -XPOST -H "content-type: application/json"
          http://fluentbit:9880/web-firelens-dummy

expect filter plugin で対象ログが取得できているかチェック

expect filter plugin を使用しコンテナログから抽出したJSONフォーマットされたRailsログを expect で個々のキー値を検証します。
action exit でいずれかのチェックで失敗した場合、異常終了となります。

test/test.conf#L6-L26

[FILTER]
    name expect
    match eventlog

    key_val_eq method GET
    key_val_eq path /sre/boshuchu
    ...

    action exit

fluentbit が意図した振る舞いをしているかは出力するログファイルの内容を照合する

expect filter plugin は、抽出対象のログが取得できているかについて、キー単位でチェックが可能ですが、 「ログが配信されない」が正解の場合のテストには向きません。

以下は通常のコンテナログが改変されずにログ出力されるかのテストです。

      # NOTE: http://fluentbit:9880/web-firelens-dummy に対して curl することで
      #       tag=web-firelens-dummy を付与したログを fluentbit に POST できる。
      - name: fluentbit コンテナへ Rails コンテナログを http 経由で POST する
        run: >
          docker run --rm
          ...
          curlimages/curl:latest -v -d @/tmp/web_container.log -XPOST -H "content-type: application/json"
          http://fluentbit:9880/web-firelens-dummy
      - name: コンテナログファイルが生成されるまで待機する。生成されない場合、テスト失敗となる
        # NOTE: web-firelens-dummy タグでリクエストすると web_firelens_dummy というファイル名で生成される
        run: while [ ! -e /tmp/web_firelens_dummy ]; do sleep 1; done
      - name: Rails コンテナログが改変されず出力されること。実値と予測値が一致しない場合、テスト失敗とし異常終了する
        # NOTE: fluentbit 経由で出力されるログの JSON のキーは毎回順不同な為、 `--sort-keys` でキーを昇順にソートしています。
        run: |
          diff -q \
          <(sed 's|web_firelens_dummy: ||g' /tmp/web_firelens_dummy | jq -r --sort-keys '.[1]') \
          <(cat ./docker/fluentbit/test/web_container.log | jq --sort-keys .)

timestamp は変更されてしまう為、 ログ {"source":"stdout","log": ...}の内、第二要素の log キーを比較対象としています。
比較時に json は毎回順不同になる為、 --sort-keys でキーを昇順 (a→z) に並べています。 ⁵

        run: |
          diff -q \
          <(sed 's|web_firelens_dummy: ||g' /tmp/web_firelens_dummy | jq -r --sort-keys '.[1]') \
          <(cat ./docker/fluentbit/test/web_container.log | jq --sort-keys .)

fluentbit の構文チェック

      - name: fluentbit 設定ファイル構文チェック
        run: >
          docker run --rm
          -e DELIVERY_STREAM_WEB_LOG=dummy
          test-fluentbit:latest
          /fluent-bit/bin/fluent-bit -c /fluent-bit/etc/extra.conf --dry-run

設定ファイルの構文チェックを実施しています。

設定に問題がない場合は以下の様に正常終了します。

Fluent Bit v1.9.8
* Copyright (C) 2015-2022 The Fluent Bit Authors
* Fluent Bit is a CNCF sub-project under the umbrella of Fluentd
* https://fluentbit.io

configuration test is successful

不正な構文がある場合は異常終了します。

総評

元々、ngx_mruby で SSL 証明書の動的読み込みシステム構築した際に Nginx の挙動をテストした方法をヒントに Fluent Bit のテストを実装してみました。

本当に皆さんどのようなテストをしているのか気になってます。コメントいただけると嬉しいです 😭

今回は lograge で JSON フォーマットされた Rails のコンテナログが対象でしたが、 同様の方式で他 F/W でもアプリケーションログ専用の Glue テーブルを管理しています。

また、DB にログを蓄積しているプロジェクトもありましたが、 Fluent Bit でログを S3 保存することで DB のコストを削減できた例もあります。

以上
参考になれば幸いです。

---

是非読者になってください

---

メドピアでは一緒に働く仲間を募集しています。 ご応募をお待ちしております！

■募集ポジションはこちら

https://medpeer.co.jp/recruit/entry/

■開発環境はこちら

https://medpeer.co.jp/recruit/workplace/development.html

---

1. Kinesis Firehose で JSON → Parquet 変換、 S3 保存し、Glue Crawler で生成した Glue テーブルを想定しています。↩

2. CloudWatch Logs へコンテナログを配信することでタスク起動失敗時のログ調査が直ちにできる様に配慮しました。Kinesis Firehose はログが一定 byte (最大 128 MB)、もしくは、一定時間 (最大 15分間) S3 にログ配信しない様、バッファすることが可能です。バッファサイズを小さくし、ログレコードのサイズが小さくなると意図せぬコスト増となる可能性があります。弊社では、コスト抑制する意図から極力バッファの最大値を採用している関係で直ちに Glue テーブルに反映されないデメリットがあります。
   参考: https://docs.aws.amazon.com/ja_jp/firehose/latest/dev/limits.html
   プロジェクトの特性によってコンテナログを CloudWatch Logs でなく Kinesis Firehose に配信し、コスト削減を実施している場合もあります。↩

3. 実装意図をできる限り commit ログにまとめましたので参考にしていただけますと幸いです。↩

4. GitHub Actions で試用できる Kinesis Firehose コンテナの様なものがあればより実際の構成に近く利用したかったのですが、現状はなさそう。↩

5. 可読性が悪く、シェル芸飛び出てきたのでつらみが増してる箇所です。皆さんどんなテストしてるのか知りたいと思ったのはまさにこの時でした 😅↩