FireLens を使って fluentd logging driver 起因の fluentd の負荷を分散させる

Fluentd aggregator を構成する際に、Route 53 や NLB を使うことで、forwarder では 1 つのエンドポイントを指定しつつ簡単に fluend の台数を増減させることができます。ところが、Docker で fluentd logging driver を使う際にそのエンドポイントを指定すると、一度コネクションが確立されるとずっとそのコネクションが使い回されるため、大量のログを吐くコンテナと接続された fluentd ホストだけが高負荷な状態が続くことになります。
この問題を解消するために FireLens を使ってみたという話です。

Fluentd logging driver の実装

Fluentd logging driver の実装は daemon/logger/fluentd/fluentd.go ですが、コネクションにメッセージを書き込むところでエラーにならない限りずっとコネクションが使い回されるようになっていることがわかります。
cf. fluent/fluent-logger-golang/fluent/fluent.go#L357-L408

つまり、fluent-logger-golang と docker に手を入れない限り特定の fluentd ホストの負荷が偏る問題は解消できないということです。

FireLens とは何か？

公式ドキュメントは Custom log routing で、logging driver として awsfirelens を指定することで sidecar container の fluentd または fluent bit にログを送ることができ、fluentd, fluent bit から各種サービスにログを送ることができる機能です。

試しに https://docs.aws.amazon.com/AmazonECS/latest/userguide/using_firelens.html#firelens-example-forward を参考に次のような設定のタスクを起動してみます。

{
  "family": "firelens-example-forward",
  "containerDefinitions": [
    {
      "essential": true,
      "image": "906394416424.dkr.ecr.ap-northeast-1.amazonaws.com/aws-for-fluent-bit:latest",
      "name": "log_router",
      "firelensConfiguration": {
        "type": "fluentbit",
      },
      "logConfiguration": {
        "logDriver": "awslogs",
        "options": {
          "awslogs-group": "firelens-container",
          "awslogs-region": "ap-northeast-1",
          "awslogs-create-group": "true",
          "awslogs-stream-prefix": "firelens"
        }
      },
      "memoryReservation": 50
     },
     {
       "essential": true,
       "image": "httpd",
       "name": "app",
       "logConfiguration": {
         "logDriver":"awsfirelens",
         "options": {
          "Name": "forward",
          "Host": "172.31.22.30",
          "Port": "24224"
        }
      },
      "memoryReservation": 100
    }
  ]
}

172.31.22.30 は Fluentd が動いているホストの IP ですが、fluentd aggregator のエンドポイントとして NLB を使う場合は NLB のエンドポイントになります。

これで Web サーバにリクエストを送ると、5 秒ごとに新しいコネクションが作成されていることがわかります。

[ec2-user@ip-172-31-22-30 ~]$ while : ; do sudo nsenter -t $(docker inspect $(docker ps | awk '$2 == "httpd" { print $1 }') --format '{{.State.Pid}}') -n curl localhost; ss -tn | grep 24224; sleep 1; done
<html><body><h1>It works!</h1></body></html>
<html><body><h1>It works!</h1></body></html>
ESTAB   0         0              172.31.22.30:24224          172.17.0.3:49210
<html><body><h1>It works!</h1></body></html>
ESTAB   0         0              172.31.22.30:24224          172.17.0.3:49210
<html><body><h1>It works!</h1></body></html>
ESTAB   0         0              172.31.22.30:24224          172.17.0.3:49210
<html><body><h1>It works!</h1></body></html>
ESTAB   0         0              172.31.22.30:24224          172.17.0.3:49210
<html><body><h1>It works!</h1></body></html>
ESTAB   0         0              172.31.22.30:24224          172.17.0.3:49244
<html><body><h1>It works!</h1></body></html>
ESTAB   0         0              172.31.22.30:24224          172.17.0.3:49244
<html><body><h1>It works!</h1></body></html>
ESTAB   0         0              172.31.22.30:24224          172.17.0.3:49244
<html><body><h1>It works!</h1></body></html>
ESTAB   0         0              172.31.22.30:24224          172.17.0.3:49244
<html><body><h1>It works!</h1></body></html>
ESTAB   0         0              172.31.22.30:24224          172.17.0.3:49244
<html><body><h1>It works!</h1></body></html>
ESTAB   0         0              172.31.22.30:24224          172.17.0.3:49282
<html><body><h1>It works!</h1></body></html>
ESTAB   0         0              172.31.22.30:24224          172.17.0.3:49282
<html><body><h1>It works!</h1></body></html>
ESTAB   0         0              172.31.22.30:24224          172.17.0.3:49282
<html><body><h1>It works!</h1></body></html>
ESTAB   0         0              172.31.22.30:24224          172.17.0.3:49282

logging driver として awsfirelens を指定すると、内部的には logging driver として fluentd logging driver が使われていることがわかります。tag は <container-name>-firelens-<task-id> になります。
cf. agent/engine/docker_task_engine.go#L92-L93

[ec2-user@ip-172-31-22-30 ~]$ docker inspect $(docker ps | awk '$2 == "httpd" { print $1 }') | jq '.[0].HostConfig.LogConfig'
{
  "Type": "fluentd",
  "Config": {
    "fluentd-address": "unix:///var/lib/ecs/data/firelens/23e29749caef4e68903a88e9a60846d8/socket/fluent.sock",
    "fluentd-async-connect": "true",
    "fluentd-sub-second-precision": "true",
    "tag": "app-firelens-23e29749caef4e68903a88e9a60846d8"
  }
}

fluent bit の設定は次のようになっています。

[ec2-user@ip-172-31-22-30 ~]$ docker exec $(docker ps | awk '/fluent-bit/ { print $1 }') ps auxf
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root        36  0.0  0.7  51852  3368 ?        Rs   23:49   0:00 ps auxf
root         1  0.0  5.3 634200 25144 ?        Ssl  22:39   0:00 /fluent-bit/bin/fluent-bit -e /fluent-bit/firehose.so -e /fluent-bit/cloudwatch.so -e /fluent-bit/kinesis.so -c /fluent-bit/etc/fluent-bit.conf
[ec2-user@ip-172-31-22-30 ~]$ docker exec $(docker ps | awk '/fluent-bit/ { print $1 }') cat /fluent-bit/etc/fluent-bit.conf

[INPUT]
    Name forward
    unix_path /var/run/fluent.sock

[INPUT]
    Name forward
    Listen 0.0.0.0
    Port 24224

[INPUT]
    Name tcp
    Tag firelens-healthcheck
    Listen 127.0.0.1
    Port 8877

[FILTER]
    Name record_modifier
    Match *
    Record ec2_instance_id i-0d7b73bc6c6b97f7c
    Record ecs_cluster test
    Record ecs_task_arn arn:aws:ecs:ap-northeast-1:695137853892:task/test/23e29749caef4e68903a88e9a60846d8
    Record ecs_task_definition firelens-example-forward:6

[OUTPUT]
    Name null
    Match firelens-healthcheck

[OUTPUT]
    Name forward
    Match app-firelens*
    Host 172.31.22.30
    Port 24224

docker image に同梱されている設定ファイルはこれですが、host に配置されているもので上書きされていることがわかります。また、他のコンテナの logging driver からアクセスできるように、unix domain socket は bind mounts されたディレクトリ上に存在していることもわかります。

[ec2-user@ip-172-31-22-30 ~]$ docker inspect $(docker ps | awk '/aws-for-fluent-bit/ { print $1 }') | jq '.[0].HostConfig.Binds'
[
  "/var/lib/ecs/data/firelens/23e29749caef4e68903a88e9a60846d8/config/fluent.conf:/fluent-bit/etc/fluent-bit.conf",
  "/var/lib/ecs/data/firelens/23e29749caef4e68903a88e9a60846d8/socket/:/var/run/"
]

なお、今年の 9 月頃に nanoseconds をサポートしているので、少し古い ecs agent だとログの時刻は秒単位になってしまいます。
cf. [FireLens] [request]: Send nanoseconds of a log records to a log router · Issue #839 · aws/containers-roadmap

Custom configuration file で設定を変更する

https://docs.aws.amazon.com/AmazonECS/latest/developerguide/firelens-taskdef.html#firelens-taskdef-customconfig に書いてあるように、S3 などに追加の設定ファイルを配置することで設定を変更することができます。このオプションを利用すると、次のように /fluent-bit/etc/fluent-bit.conf に @INCLUDE /fluent-bit/etc/external.conf の 1 行が追加され、指定したファイルの内容が読み込まれるようになっています。

[ec2-user@ip-172-31-22-30 ~]$ docker exec $(docker ps | awk '/fluent-bit/ { print $1 }') cat /fluent-bit/etc/fluent-bit.conf

[INPUT]
    Name forward
    unix_path /var/run/fluent.sock

[INPUT]
    Name forward
    Listen 0.0.0.0
    Port 24224

[INPUT]
    Name tcp
    Tag firelens-healthcheck
    Listen 127.0.0.1
    Port 8877

[FILTER]
    Name record_modifier
    Match *
    Record ec2_instance_id i-0d7b73bc6c6b97f7c
    Record ecs_cluster test
    Record ecs_task_arn arn:aws:ecs:ap-northeast-1:695137853892:task/test/16cdc14c1e9c48bca7c2e28fe8c3fd51
    Record ecs_task_definition firelens-example-forward:14

@INCLUDE /fluent-bit/etc/external.conf

[OUTPUT]
    Name null
    Match firelens-healthcheck

[OUTPUT]
    Name forward
    Match app-firelens*
    Host 172.31.22.30
    Port 24224

これを利用すれば、例えば次の設定ファイルを指定することで <container-name>-firelens-<task-id> というタグを docker.<container-name> に変換することもできます。

[OUTPUT]
    Name null
    Match firelens-healthcheck

[FILTER]
    Name  rewrite_tag
    Match *-firelens*
    # cf. https://github.com/aws/amazon-ecs-agent/blob/v1.48.1/agent/engine/docker_task_engine.go#L1071
    Rule  $container_name ^/ecs-${TASK_FAMILY}-\d+-(.+)- docker.$1 false

[OUTPUT]
    Name forward
    Match *
    Host ${FLUENTD_HOST}
    Port ${FLUENTD_PORT}

タスク定義は次のように変わります。

{
  "family": "firelens-example-forward",
  "executionRoleArn": "arn:aws:iam::695137853892:role/ecsTaskExecutionRole",
  "containerDefinitions": [
    {
      "essential": true,
      "image": "906394416424.dkr.ecr.ap-northeast-1.amazonaws.com/aws-for-fluent-bit:latest",
      "name": "log_router",
      "firelensConfiguration": {
        "type": "fluentbit",
        "options": {
          "config-file-type": "s3",
          "config-file-value": "arn:aws:s3:::test.abicky.net/fluent-bit.conf"
        }
      },
      "logConfiguration": {
        "logDriver": "awslogs",
        "options": {
          "awslogs-group": "firelens-container",
          "awslogs-region": "ap-northeast-1",
          "awslogs-create-group": "true",
          "awslogs-stream-prefix": "firelens"
        }
      },
      "memoryReservation": 50,
      "environment": [
        {
          "name": "FLUENTD_HOST",
          "value": "172.31.22.30"
        },
        {
          "name": "FLUENTD_PORT",
          "value": "24224"
        },
        {
          "name": "TASK_FAMILY",
          "value": "firelens-example-forward"
        }
      ]
     },
     {
       "essential": true,
       "image": "httpd",
       "name": "app",
       "logConfiguration": {
         "logDriver":"awsfirelens"
      },
      "memoryReservation": 100
    }
  ]
}

fluent bit の設定には SERVICE を何個も書けるようなので、flush 間隔を短くしたい場合は次の内容をカスタム設定ファイルに書けば良いです。

[SERVICE]
    Flush 1

FireLens を使うと何が嬉しいのか？

単なる sidecar container であれば自前でも簡単に実現できそうです。ところが、実際にやってみようとすると、他のコンテナの logging driver からアクセスできるようにするにはホストから直接アクセスできるようにしなければならないことに気付きます。unix domain socket を使うにしても TCP を使うにしても、1 インスタンスに複数のタスクが配置される可能性を考慮すると、これは非常に面倒な問題です。FireLens を使う最大のメリットはそこの面倒をよしなに見てくれることでしょう。

FireLens を使わない選択肢としては DAEMON service として fluentd なり fluent bit なりを動かすことが考えられます。
cf. Centralized Container Logging with Fluent Bit

DAEMON service はインスタンスを draining にすると他のタスクより先に終了する可能性があったんですが、最近修正されたようです。
cf. https://github.com/aws/containers-roadmap/issues/128#issuecomment-736026241

draining にした後のログが見れないと困りますもんね。ただ、What’s New with Containers? にはそれらしい情報がないし、ecs agent にもそれらしい変更はないので詳細は不明ですが…

追記

Improving daemon services in Amazon ECS | Containers によれば、2020 年 11 月に修正されたようです

In November of 2020, we added an update to the ECS scheduler to drain daemon tasks last on a host. This ensures that when an instance is set to drain, ECS will terminate all other tasks before terminating the daemon task.

FireLens の微妙な点

FireLens を使うと嬉しいことについて言及しましたが、次の点は微妙だと思っています。

  • ログを収集するだけなら unix domain socket しか使わないのに 24224 番ポートを listen する
  • 環境変数として FLUENT_HOST, FLUENT_PORT という一般的な名前が使われている
    • cf. agent/engine/docker_task_engine.go#L95-L97
    • 例えば既にこれらの環境変数を使っていればコードを修正しないといけないし、環境変数がセットされることを知らなければ事故につながるかもしれない
      • 何故 FIRELENS_FLUENT_HOST, FIRELENS_FLUENT_PORT じゃない…
  • タグのフォーマットが <container-name>-firelens-<task-id> のようにハイフン区切りである
    • ドット区切りだと fluentd, fluent bit の設定ファイルで扱いやすいのに…

FireLens の一番の魅力は log driver に指定することができ、よしなに unix domain socket を使ってくれることであり、24224 番ポートに fluentd, fluent bit を立てるのであればわざわざ FireLens を使う必要がないわけで、このようなオプトアウト不可能な機能が提供されているのは疑問です。