Kubernetes上のCRI形式のフォーマットで吐かれたコンテナのログをFluent Bitで集約してみる
今回はFluent BitでKubernetes上のPodから生成されたログを集約してみます。 集約といっても、やることは1ファイルに纏めるだけで大したことはしません。
今回は以下の流れでやってみます。 また、今回の記事では、kindで試します。
- はじめに
- Fluent Bitとは
- 公式 が出しているマニフェストを参考にログをtailしてみる
- ログをCRI形式のログとして取り扱う
- Kubernetes filterを使ってKubernetesの情報を付与してみる
- Kubernetes filterの機能を使ってPodのJSONログのparseをしてみる
- /var/log/podsの下のログをtailしてみる
- /var/log/podsのログでもKubernetesの情報を付与できるようにする
- 終わりに
今回試した環境はこちらです。また、Fluent Bitのバージョンは1.9.2を使いました。
$ kind version
kind v0.12.0 go1.16.3 linux/amd64
$ kubectl version
Client Version: version.Info{Major:"1", Minor:"23", GitVersion:"v1.23.5", GitCommit:"c285e781331a3785a7f436042c65c5641ce8a9e9", GitTreeState:"clean", BuildDate:"2022-03-16T15:58:47Z", GoVersion:"go1.17.8", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"23", GitVersion:"v1.23.4", GitCommit:"e6c093d87ea4cbb530a7b2ae91e54c0842d8308a", GitTreeState:"clean", BuildDate:"2022-03-06T21:32:53Z", GoVersion:"go1.17.7", Compiler:"gc", Platform:"linux/amd64"}
はじめに
Kubernetesで吐かれたログをどこかの検索しやすい場所に集約することは大事です。 Elasticsearchやgrafana/lokiなどの自前でホストしているバックエンドや DatadogやCloudWatch LogsなどのSaaSやクラウドのサービスなどに集約して 検索を容易にし、調査を簡単にすることは大事です。 なぜ大事かというと、問題が発生した場合にすぐに調べられるような環境が大事という話で Observabilityにも繋がる話ですね。
そこで、今回はKubernetes上のPodから生成されたログを集約してみます。 Kubernetesでクラスタのログを集約する場合、公式のドキュメントでは以下のようなオプションが提示されています。
- 全てのノードで実行されるノードレベルのロギングエージェントを使用します。
- アプリケーションのPodにログインするための専用のサイドカーコンテナを含めます。
- アプリケーション内からバックエンドに直接ログを送信します。
今回の記事では、「全てのノードで実行されるノードレベルのロギングエージェントを使用する」という選択肢を取ります。 この場合、DaemonSetを使うので、EKS on Fargateだと使えないのかなと思ったんですが 以下のリリースが出ていて、EKS on Fargateでもfluent-bitでログを集約するのは出来そうですね。 Fluent Bit for Amazon EKS on AWS Fargate is here | Containers EKS on Fargateの場合、設定を追加するだけでログの集約ができそうです。
Fluent Bitとは
公式サイトには「Fluent Bit is a super fast, lightweight, and highly scalable logging and metrics processor and forwarder. It is the preferred choice for cloud and containerized environments.」と 書かれており、高速で軽量でスケーラブルなロギングやメトリクスの処理が行えるようです。 メトリクス・・・？となったのですが、一言だけ書いて今回は置いておきます。
横道:
prometheus_remote_writeの Output プラグインがあってnode_exporterのメトリクスを 集約するサンプルが書いてありますね。prometheusから処理せずPull型とPush型の中間のアプローチって感じなんでしょうか。
Fluent Bitでデータを処理する中では、4つ程度の構成要素が伺えます。
- Parser
- Input
- Filter
- Output
の4つです。他にもコンセプトとしてはあるようですが一旦置いておきます。
Parserとは、名前そのままで、生のデータや構造化されていないログを構造化データに変換するもの、と公式サイトには書かれています。 InputやOutputも名前のままで、入力と出力の定義をする部分です。といっても色々プラグインがあるので公式サイトのドキュメントを見ながら使うことになるとは思います。 Filterはデータを絞るのを想像してしまいますが、データを送る前に変更することができる機能、だそうです。
今回の記事ではFilterはKubernetesのFilterプラグインを使います。 これは、Kubernetesの情報をデータに付与するためのプラグインです。 これを使うことで、namespaceやannotation、labelなどの情報を付与することができ 集約後にこれらで検索することも可能になるでしょう。 今回はそこまでしませんが。
公式が出しているマニフェストを参考にログをtailしてみる
公式が出しているKubernetesのマニフェストがここにあります。これを参考に見ながらやっていきます。
まずはinputの定義です。公式を参考にしつつ、シンプルにして抜き出してみました。
/var/log/containersの下にログがあることがわかります。そこから.logファイルをtailして、入力とするようです。
Fluent Bitの設定は以下のような形になりました
[SERVICE]
Flush 1
Daemon Off
Log_Level info
Parsers_File /fluent-bit/etc/parsers.conf
[INPUT]
Name tail
Tag kube.*
Path /var/log/containers/*.log
Parser docker
DB /var/log/flb_kube.db
# テストのために短くしている
Refresh_Interval 1
[OUTPUT]
Name file
Match *
Path /var/log/
File test.log
Parsers_Fileで指定されているparsers.confの中身は以下のような内容です
[PARSER]
Name docker
Format json
Time_Key time
Time_Format %Y-%m-%dT%H:%M:%S.%L
Time_Keep On
[PARSER]
Name json
Format json
Time_Key timestamp
Time_Format %Y-%m-%dT%H:%M:%S%z
Time_Keep true
/var/log/containers の下のログファイルを /var/log/flb_kube.db にどこまで読んだかを書き込みながら
/var/log/test.log に集約する形です。
これを動かしてみます。動かすには以下のKubernetesのマニフェストを使っていきます。
apiVersion: apps/v1 kind: DaemonSet metadata: name: fluent-bit spec: selector: matchLabels: app: fluent-bit template: metadata: labels: app: fluent-bit spec: serviceAccountName: fluent-bit containers: - name: fluent-bit image: fluent/fluent-bit:1.9.2 volumeMounts: - name: varlog mountPath: /var/log - name: varlibdockercontainers mountPath: /var/lib/docker/containers readOnly: true - name: fluent-bit-config mountPath: /fluent-bit/etc/ volumes: - name: varlog hostPath: path: /var/log - name: varlibdockercontainers hostPath: path: /var/lib/docker/containers - name: fluent-bit-config configMap: name: fluent-bit-config --- apiVersion: rbac.authorization.k8s.io/v1 kind: ClusterRole metadata: name: fluent-bit-read rules: - apiGroups: [""] resources: - namespaces - pods verbs: ["get", "list", "watch"] --- apiVersion: v1 kind: ServiceAccount metadata: name: fluent-bit --- apiVersion: rbac.authorization.k8s.io/v1 kind: ClusterRoleBinding metadata: name: fluent-bit-read roleRef: apiGroup: rbac.authorization.k8s.io kind: ClusterRole name: fluent-bit-read subjects: - kind: ServiceAccount name: fluent-bit namespace: default
今回は設定をすぐ反映したかったので、kustomizeでconfigMapGeneratorを使いました。 kustomization.yamlも置いておきます。
apiVersion: kustomize.config.k8s.io/v1beta1 kind: Kustomization resources: - fluent-bit.yaml configMapGenerator: - name: fluent-bit-config files: - parsers.conf=./parsers.conf - fluent-bit.conf=./fluent-bit.conf
というわけで、やっとfluent-bitでログを集約する準備が終わりました。 Kubernetesにデプロイしてみてください。
kindを使っているので、dockerのコンテナがKubernetesのホストになります。
docker ps CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 84a0714a8092 kindest/node:v1.23.4 "/usr/local/bin/entr…" 2 weeks ago Up 2 weeks 127.0.0.1:40199->6443/tcp kind-control-plane
というわけで、以下のような形で集約されたログが確認できます。
docker exec -it ${KindのContainerID} tail /var/log/test.log
発生したログを抜き出してみました。
kube.var.log.containers.kindnet-rpsht_kube-system_kindnet-cni-e15e2f44bd121b9c4bfbd2575d350985d47b134598ec3108891a6216546d0ea4.log: [1650758707.595139580, {"log":"2022-04-24T00:05:07.595076354Z stderr F I0424 00:05:07.594746 1 main.go:227] handling current node"}]
{"log": "2022-04-24T00:05:07.595076354Z stderr F I0424 00:05:07.594746 1 main.go:227] handling current node"}
といった形で、非構造化ログが出力されています。これはどういうことでしょうか？
これは、kindの場合、containerdでのコンテナの実行が行われるため CRI形式のログが出力されるようです。fluent-bitの設定を弄る必要があるようです。
ログをCRI形式のログとして取り扱う
parsers.confに以下の設定を追加しました。 これがCRI形式のフォーマットのログだそうです。 公式リポジトリのマニフェストを眺めていたら書かれていたのでこれを参考にしました。
[PARSER]
Name cri
Format regex
Regex ^(?<time>[^ ]+) (?<stream>stdout|stderr) (?<logtag>[^ ]*) (?<log>.*)$
Time_Key time
Time_Format %Y-%m-%dT%H:%M:%S.%L%z
また、inputの定義を変更しています。先程定義したcriのParserを使うようにしています。
...
[INPUT]
Name tail
Tag kube.*
Path /var/log/containers/*.log
- Parser docker
+ Parser cri
DB /var/log/flb_kube.db
# テストのために短くしている
Refresh_Interval 1
...
設定を反映後、集約されたログを抜き出してみました。
kube.var.log.containers.kube-controller-manager-kind-control-plane_kube-system_kube-controller-manager-76d380c2aab265fb11b69254f06fc54afda39c7246d200900abee612ace006d9.log: [1650759325.670653352, {"stream":"stderr","logtag":"F","log":"I0424 00:15:25.670474 1 event.go:294] \"Event occurred\" object=\"default/fluent-bit\" kind=\"DaemonSet\" apiVersion=\"apps/v1\" type=\"Normal\" reason=\"SuccessfulCreate\" message=\"Created pod: fluent-bit-jz6sm\""}]
よりマシな構造化されたデータになったんじゃないかと思います。 stream, logtag, logが抽出できています。
ちなみに logtag ってなんでしょう？っていうと
PとF があってそれぞれPartialとFull の2つです。
これはログが部分的かどうかを表すようです。
これでCRI形式のログのParseが行え、ログを読むのが楽になりました。
Kubernetes filterを使ってKubernetesの情報を付与してみる
今度は、Kubernetes filterを使って、ログにKubernetesの情報を付与してみます。 fluent-bitの設定に以下を追加します。
[FILTER]
Name kubernetes
Match kube.*
Kube_URL https://kubernetes.default.svc:443
Kube_CA_File /var/run/secrets/kubernetes.io/serviceaccount/ca.crt
Kube_Token_File /var/run/secrets/kubernetes.io/serviceaccount/token
Kube_Tag_Prefix kube.var.log.containers.
Merge_Log On
K8S-Logging.Parser On
K8S-Logging.Exclude Off
serviceaccountで付与されたトークンを使ってKubernetesのAPIサーバにアクセスしてデータを付与するようですね。 設定を反映後、ログを抜き出してみました。
kube.var.log.containers.kube-controller-manager-kind-control-plane_kube-system_kube-controller-manager-76d380c2aab265fb11b69254f06fc54afda39c7246d200900abee612ace006d9.log: [1650759836.854470325, {"stream":"stderr","logtag":"F","log":"I0424 00:23:56.854367 1 event.go:294] \"Event occurred\" object=\"default/fluent-bit\" kind=\"DaemonSet\" apiVersion=\"apps/v1\" type=\"Normal\" reason=\"SuccessfulCreate\" message=\"Created pod: fluent-bit-r9cbl\"","kubernetes":{"pod_name":"kube-controller-manager-kind-control-plane","namespace_name":"kube-system","pod_id":"d0bdfe53-aaec-4e8f-8904-494e44b56203","labels":{"component":"kube-controller-manager","tier":"control-plane"},"annotations":{"kubernetes.io/config.hash":"43e6406bdf14bdbcce659ef1cdcc1382","kubernetes.io/config.mirror":"43e6406bdf14bdbcce659ef1cdcc1382","kubernetes.io/config.seen":"2022-04-08T17:22:45.480326175Z","kubernetes.io/config.source":"file","seccomp.security.alpha.kubernetes.io/pod":"runtime/default"},"host":"kind-control-plane","container_name":"kube-controller-manager","docker_id":"76d380c2aab265fb11b69254f06fc54afda39c7246d200900abee612ace006d9","container_hash":"sha256:65dd3c630e90e08c9cdc5a7a46dcebd76791e46a784bcfb3de2511a8d5ff113d","container_image":"k8s.gcr.io/kube-controller-manager:v1.23.4"}}]
なんかいろいろ情報が付与されていますね。見づらいのでログに改行を入れてみます。 .kubernetes配下に、いろいろな情報が付与されています。
[
1650759836.854470325,
{
"stream": "stderr",
"logtag": "F",
"log": "I0424 00:23:56.854367 1 event.go:294] \"Event occurred\" object=\"default/fluent-bit\" kind=\"DaemonSet\" apiVersion=\"apps/v1\" type=\"Normal\" reason=\"SuccessfulCreate\" message=\"Created pod: fluent-bit-r9cbl\"",
"kubernetes": {
"pod_name": "kube-controller-manager-kind-control-plane",
"namespace_name": "kube-system",
"pod_id": "d0bdfe53-aaec-4e8f-8904-494e44b56203",
"labels": {
"component": "kube-controller-manager",
"tier": "control-plane"
},
"annotations": {
"kubernetes.io/config.hash": "43e6406bdf14bdbcce659ef1cdcc1382",
"kubernetes.io/config.mirror": "43e6406bdf14bdbcce659ef1cdcc1382",
"kubernetes.io/config.seen": "2022-04-08T17:22:45.480326175Z",
"kubernetes.io/config.source": "file",
"seccomp.security.alpha.kubernetes.io/pod": "runtime/default"
},
"host": "kind-control-plane",
"container_name": "kube-controller-manager",
"docker_id": "76d380c2aab265fb11b69254f06fc54afda39c7246d200900abee612ace006d9",
"container_hash": "sha256:65dd3c630e90e08c9cdc5a7a46dcebd76791e46a784bcfb3de2511a8d5ff113d",
"container_image": "k8s.gcr.io/kube-controller-manager:v1.23.4"
}
}
]
これで、ログにKubernetesの情報を紐付けることができました。
Kubernetes filterの機能を使ってPodのJSONログのparseをしてみる
ログにKubernetesの情報を付与することが出来ましたが、アプリケーションでログ出すときにJSONで出力したいですよね？ というわけで、以下のPodのyamlを使いながら試していきます。
apiVersion: v1 kind: Pod metadata: name: echo spec: containers: - name: echo image: bash:5 args: - echo - '{"message": "test"}'
Kubernetes filterのプラグインでは、log フィールドのParseを追加で行うことができます。
というわけで以下の設定を追加してみます。
[FILTER]
Name kubernetes
Match kube.*
Kube_URL https://kubernetes.default.svc:443
Kube_CA_File /var/run/secrets/kubernetes.io/serviceaccount/ca.crt
Kube_Token_File /var/run/secrets/kubernetes.io/serviceaccount/token
Kube_Tag_Prefix kube.var.log.containers.
Merge_Log On
+ Merge_Parser json
K8S-Logging.Parser On
K8S-Logging.Exclude Off
設定を反映後、最初に書いたPodを起動させたあと集約されたログをフォーマットしたものはこちらです。
[
1650760525.343619673,
{
"stream": "stdout",
"logtag": "F",
"log": "{\"message\": \"test\"}",
"message": "test",
"kubernetes": {
"pod_name": "echo",
"namespace_name": "default",
"pod_id": "1d76bd70-cda0-492b-8d99-821a5c45d41d",
"annotations": {
"kubectl.kubernetes.io/last-applied-configuration": "{\"apiVersion\":\"v1\",\"kind\":\"Pod\",\"metadata\":{\"annotations\":{},\"name\":\"echo\",\"namespace\":\"default\"},\"spec\":{\"containers\":[{\"args\":[\"echo\",\"{\\\"message\\\": \\\"test\\\"}\"],\"image\":\"bash:5\",\"name\":\"echo\"}]}}\n"
},
"host": "kind-control-plane",
"container_name": "echo",
"docker_id": "ed155f5a7ec02437c316d617b597167e8894f5b466019b3c6f0903b6d500b2d8",
"container_image": "bash:5"
}
}
]
log フィールドの内容をJSONとして構造化した上で、トップレベルに "message": "test" とデータが追加されていることがわかります。
しかし、今回書いた設定では問題があることがあります。
それは、log フィールドに入っている内容がJSONだと仮定してしまっている点にあります。
Merge_Parser の設定の説明でもその旨が書かれており、以下の記述があります。
Optional parser name to specify how to parse the data contained in the log key. Recommended use is for developers or testing only.
というわけで、この設定値を使わないようにしましょう。どうするのがいいでしょうか？
実は、デフォルトでJSONとして扱われるので、Merge_LogをOnにするだけで良かったのですが
JSON以外のフォーマットのログを吐きたい時もありますよね？
そういった場合のために、annotationでもparserを指定できるようです。
以下のようなイメージです。
apiVersion: v1 kind: Pod metadata: name: echo annotations: fluentbit.io/parser: json spec: containers: - name: echo image: bash:5 args: - echo - '{"message": "test"}'
これで、PodのJSON以外のログでも構造化して集約することが出来そうです。
/var/log/podsの下のログをtailしてみる
ところで、/var/log/containers 配下のログはsymlinkになっていることはお気づきでしょうか？
これは kindだからでしょうか？
これは古いログの配置場所だそうで、Kubernetesのコンテナを実行するランタイムがdockerの場合は/var/lib/docker配下にlinkが貼られているようです。
少し調べてみたところ、アーカイブされてるようですが、(ここに)https://github.com/kubernetes/community/blob/7cf09cbb4e73aed51a0e7eeba4420c7e0b5c7d8d/contributors/design-proposals/node/kubelet-cri-logging.md、のリンク先に記述があり、/var/log/pods が最新のログ出力先のようです。
$ ls /var/log/containers lrwxrwxrwx 1 root root 138 Apr 8 17:39 local-path-provisioner-64d5bc6b74-hjwbv_local-path-storage_local-path-provisioner-fda058a2e28bfa5b66686758a1656818a0832eca5e8bb0aa6de970f68e364239.log -> /var/log/pods/local-path-storage_local-path-provisioner-64d5bc6b74-hjwbv_8602ae83-b4ea-44f2-804b-ad06db0afb16/local-path-provisioner/0.log
では、/var/log/podsの下のログをtailするように以下のように変えてみましょう。
[SERVICE]
Flush 1
Daemon Off
Log_Level info
Parsers_File /fluent-bit/etc/parsers.conf
[INPUT]
Name tail
Tag kube.*
- Path /var/log/containers/*/*/*.log
+ Path /var/log/pods/*/*/*.log
Parser cri
DB /var/log/flb_kube.db
Refresh_Interval 1
[FILTER]
Name kubernetes
Match kube.*
Kube_URL https://kubernetes.default.svc:443
Kube_CA_File /var/run/secrets/kubernetes.io/serviceaccount/ca.crt
Kube_Token_File /var/run/secrets/kubernetes.io/serviceaccount/token
- Kube_Tag_Prefix kube.var.log.containers.
+ Kube_Tag_Prefix kube.var.log.pods.
Merge_Log On
K8S-Logging.Parser On
K8S-Logging.Exclude Off
[OUTPUT]
Name file
Match *
Path /var/log/
File test.log
設定変更後、集約されたログを見てみます。
kube.var.log.pods.kube-system_kube-controller-manager-kind-control-plane_43e6406bdf14bdbcce659ef1cdcc1382.kube-controller-manager.0.log: [1650762280.119423725, {"stream":"stderr","logtag":"F","log":"I0424 01:04:40.119335 1 event.go:294] \"Event occurred\" object=\"default/fluent-bit\" kind=\"DaemonSet\" apiVersion=\"apps/v1\" type=\"Normal\" reason=\"SuccessfulDelete\" message=\"Deleted pod: fluent-bit-m2s5k\""}]
あれ？kubernetesの情報が追加されていませんね・・・？
どういうことでしょう・・・？
調べてみたところ、Fluent BitのKubernetes filterプラグインはデフォルトでは、タグ名が /var/log/containers 配下の出力形式であることを仮定しているようで
Fluent Bitに正規表現が定義されています。正確には、Journalを使っていると指定した場合は違う正規表現が使われるようです。
とりあえず、tailは出来ましたが、Kubernetesの情報が付与できてないのはちょっと痛いですね。 次で直してみましょう。
/var/log/podsのログでもKubernetesの情報を付与できるようにする
さて、ここで付与できていないため、どうするのがいいでしょうか？ 今回は、tail inputプラグインでtagを付ける時にパスの形式をparseしてみましょう。 というわけで、inputの定義はこうなりました。
[INPUT]
Name tail
Tag kube.<pod_id>.<namespace_name>.<pod_name>.<container_name>
Tag_Regex /var/log/pods/(?<namespace_name>[^_/]+)_(?<pod_name>[^_/]+)_(?<pod_id>[^_/]+)/(?<container_name>[^/]+)/.*
Path /var/log/pods/*/*/*.log
Parser cri
DB /var/log/flb_kube.db
Refresh_Interval 1
また、Kubernetes filterプラグインのほうも弄りましょう。
[FILTER]
Name kubernetes
Match kube.*
Kube_URL https://kubernetes.default.svc:443
Kube_CA_File /var/run/secrets/kubernetes.io/serviceaccount/ca.crt
Kube_Token_File /var/run/secrets/kubernetes.io/serviceaccount/token
+ Kube_Tag_Prefix kube.
- Kube_Tag_Prefix kube.var.log.pods.
+ Regex_Parser kube-tag
Merge_Log On
K8S-Logging.Parser On
K8S-Logging.Exclude Off
Regex_Parser が追加されています。これは、タグからpod名などを取り出すときに使われるParserです。
つまり、新しくParserの定義が必要ですね。以下のような定義を追加しました。
...
[PARSER]
Name kube-tag
Format regex
Regex ^(?<pod_id>[^.]+)\.(?<namespace_name>[^.]+)\.(?<pod_name>[^.]+)\.(?<container_name>[^.]+)$
設定を反映後、ログにKubernetesの情報が付与されました。
[
1650762962.768338327,
{
"stream": "stderr",
"logtag": "F",
"log": "E0424 01:16:02.768152 1 reflector.go:138] k8s.io/client-go/metadata/metadatainformer/informer.go:90: Failed to watch *v1.PartialObjectMetadata: failed to list *v1.PartialObjectMetadata: the server could not find the requested resource",
"kubernetes": {
"pod_name": "kube-controller-manager-kind-control-plane",
"namespace_name": "kube-system",
"pod_id": "d0bdfe53-aaec-4e8f-8904-494e44b56203",
"labels": {
"component": "kube-controller-manager",
"tier": "control-plane"
},
"annotations": {
"kubernetes.io/config.hash": "43e6406bdf14bdbcce659ef1cdcc1382",
"kubernetes.io/config.mirror": "43e6406bdf14bdbcce659ef1cdcc1382",
"kubernetes.io/config.seen": "2022-04-08T17:22:45.480326175Z",
"kubernetes.io/config.source": "file",
"seccomp.security.alpha.kubernetes.io/pod": "runtime/default"
},
"host": "kind-control-plane",
"container_name": "kube-controller-manager",
"docker_id": "76d380c2aab265fb11b69254f06fc54afda39c7246d200900abee612ace006d9",
"container_hash": "sha256:65dd3c630e90e08c9cdc5a7a46dcebd76791e46a784bcfb3de2511a8d5ff113d",
"container_image": "k8s.gcr.io/kube-controller-manager:v1.23.4"
}
}
]
というわけで、/var/log/pods配下のログをtailしながら、Kubernetesの情報を付与しつつ ログの集約ができるようになりました。
終わりに
今回の記事では、Fluent Bitを使って、Kubernetesのログを集約するイメージで Kubernetes上のPodから吐き出されたログをファイルに集約してみました。
Kubernetesのログの出力先などを調べたり、右往左往した感じがありますが
最終的に、/var/log/pods 配下のログを集約することが出来ました。
ところで、これ、Kubernetesのコンテナの実行のランタイムをcontainerdとかに変更したら Fluent Bitの設定変更しないといけなさそうですね・・・。 Kubernetes 1.23以降にアップデートするときの課題になりそうです。
終わり。
