GKEで動かしているコンテナから任意のログを吐き出させる方法

この記事は ZOZO Advent Calendar 2024 カレンダー Vol.11 の 21日目の記事です。

kubectl debugコマンドを利用してGKE上で動いているコンテナにアクセスして、任意のログを吐き出させる方法について紹介します。

背景

私たちの環境では、kube-state-metricsとCloud MonitoringのPodのPending状態が15分以上継続するとアラートが飛ぶようにしています。

GKE Cluster上で動くアプリケーションの数が増えるにつれて、メトリクスの送信量も増えてCloud Monitoringのクォータに引っ掛かり429エラーでメトリクスが送信できずアラートも正常に機能しない状態になっていました。

またkube-state-metricsとその周辺のコンポーネントは管理用ということもあって、監視もしっかりとしているわけではありませんでした。
結果として、429エラーは継続して出ていたにも関わらず気がつくのが遅れてしまいました。

そこで、以下2つの対応をすることで上記の問題を解決することを目指しました。

1. 利用していないメトリクスの送信をやめることで、そもそもクォータに引っ掛からないようにする
2. 429エラーが再発したとしてもすぐに気がつくことができるように、エラーログの監視を追加する

この記事では、特に2つ目の対策を行った際に直面した課題とその解決方法について紹介します。

課題

1つ目の対策を行い、Cloud Monitoringへ送信するメトリクスの数を絞ったことで429エラーを出なくすることには成功しました。

しかし、2つ目のログ監視を実装しその動作確認をしようとした時に問題に気が付きました...

「あれ、429エラーもう出ないのにどうやってアラートが正常に動作することを確認するんだ??」

もし実装にミスがあり、アラートが正常に動作しないのであればアラートを追加した意味が全くなくなってしまいます。
そのためにも動作確認は必須ですが、そのやり方に困ってしまいました。

要するに過去に発生したログを再度発生させればよいのですが、これが意外と難しかったです。
なので、同じ問題に当たった人が困らないようにこの記事を書きました。

方針

アラートに利用したフィルター条件は以下のとおりです。

フィルター条件

resource.type="k8s_container"
resource.labels.namespace_name="kube-support"
severity=ERROR
jsonPayload.message=~"^Error while sending request to Stackdriver googleapi: Error 429.*"

上記のフィルターを満たすようなログを再度発生させるにあたって、検討した方針は大きく以下の3つでした

1. メトリクスを絞る前に戻して、429エラーを再発させる
2. Cloud Loggingのログエントリを手動で作成する
3. 実際に動いているコンテナにアクセスして、手動でログを作り出す

1のやり方は、戻してもクォータに引っ掛かるまで時間が掛かるかつ開発環境ではそもそもメトリクスの数も多くないためクォータに引っ掛かる状態にする方が難しいという判断で諦めました。

2のやり方は、Cloud Loggingの公式ドキュメントでも紹介されているやり方でかなり有力に見えました。
しかし、実際に試してみるとresource.typeがglobalになってしまいフィルター条件に合わなかったり、その他のフィールドも実際のログと異なるため今回のタスクの動作確認としては使えませんでした。

実際に試したコマンド

$ gcloud logging write --payload-type json 'projects/zozo-mlops-dev/logs/stderr' '

2のやり方では、GKEのロギングエージェントを通さないためGKEのログを完全に再現できないという課題がありました。

うまくいったやり方

最終的には、3のコンテナのにアクセスして手動でログを作り出すやり方でうまく動作確認することができました。
その中でも、工夫した点を紹介します

GKEのログ収集の仕組み

Kubernetesでは通常コンテナ化されたアプリケーションのstdoutとstderrがログとして処理されて、/var/logディレクトリに保存されます。
https://kubernetes.io/docs/concepts/cluster-administration/logging/#how-nodes-handle-container-logs

これはGKEでも同様で、ロギングエージェントとして使われているfluentbitも以下のように設定されており、fluentbitが/var/log/containers/*.logを監視して、Cloud Logging経由でログを送信していることがわかります。

fluentbit-gke-config-v1.4.0

[INPUT]
    Name             tail
    Alias            kube_containers
    Tag              kube_<namespace_name>_<pod_name>_<container_name>
    Tag_Regex        (?<pod_name>[a-z0-9]([-a-z0-9]*[a-z0-9])?(\.[a-z0-9]([-a-z0-9]*[a-z0-9])?)*)_(?<namespace_name>[^_]+)_(?<container_name>.+)-
    Path             /var/log/containers/*.log
    Exclude_Path     /var/log/containers/*_kube-system_*.log,/var/log/containers/*_istio-system_*.log,/var/log/containers/*_knative-serving_*.log,/var/log/containers/*_gke-system_*.log,/var/log/containers/*_config-management-system_*.log,/var/log/containers/*_gmp-system_*.log,/var/log/containers/*_gke-managed-cim_*.log
    DB               /var/lib/google-fluentbit/pos-files/flb_kube.db
    Buffer_Max_Size  20MB
    Mem_Buf_Limit    100MB
    Skip_Long_Lines  On
    Refresh_Interval 1
    Read_from_Head   True

これはkube-systemネームスペースのfluentbit-gke-config-v1.4.0というConfigMapで設定されています。

この結果から、対象のコンテナの標準出力/エラーにメッセージを差し込む or Nodeの/var/log/containers配下にログファイルを追加することで任意のログが再現できそうだと分かりました。

今回は、より既存の仕組みを活用することができる「対象のコンテナの標準出力/エラーにメッセージを差し込む」やり方を選択しました。

しかしPodログやNodeログの再現がしたい場合など、別のケースではNodeの/var/log配下にログファイルを追加するやり方を使う必要があります。

アクセス先がdistrolessイメージを使っており、シェルが使えない問題

ここまで来れば、後はコンテナの中に入って、該当のプロセスの標準出力/エラーに再現したいメッセージを入れれば動作確認できるはずだと考えていました。
そう思って、kubectl execしようとしてみるとシェルに入れませんでした。

429エラーを出していたコンテナでは、prometheusu-to-sdというGoogleが管理しているイメージを使っていました。
これがベースイメージとして、distrolessを使っていたためシェルが内蔵されていないことが原因でした。

そこでエフェメラルコンテナによるデバッグを利用しました。
以下のようにすることで、デバッグ用のエフェメラルコンテナ(busybox)が立ち上がり、対象のcontainerとプロセス名前空間が共有されます。

$ kubectl debug -it <対象のpod> --target=<対象のcontainer> --image=busybox:1.28 -- sh

https://kubernetes.io/ja/docs/tasks/debug/debug-application/debug-running-pod/#ephemeral-container

# エフェメラルコンテナの中で実行
$ echo '{"message": "Error while sending request to Stackdriver googleapi: Error 429: One or more TimeSeries could not be written: ~~~長いので省略~~~ rateLimitExceeded"' >> /proc/1/fd/2  # PID1に標準エラー出力にJSON形式のテキストを追記

後は、ログを出力させたいプロセス(大抵の場合PID=1)の標準出力(エラー)に対して、目的のメッセージを送ることで任意のログを出力することができました。

jsonPayloadがmessageフィールドだけの場合、textPayloadに変換されてしまう問題

「めでたしめでたし」と思ったのですが、いつまで経ってもアラートが鳴りませんでした...

なぜかと思って、自然に出力されたログと今回生み出したログを見比べてみると..
よく見ると、生み出したログはjsonPayloadではなくtextPayloadとしてメッセージが出力されていました。

標準エラーにはJSON形式で出力したのになぜ??と思って調べていると、どうやらCloud Loggingのmessageフィールドの仕様は少し特殊なようで、jsonPayloadにmessageフィールドしかない場合はtextPayloadに変換されてしまうようでした。

Cloud Logging 構造化ログの特別な JSON フィールドまとめ

よく見ると、元のログには"pid": "1"というフィールドも含まれていました。
そこで改めて、以下のようにフィールドを追加するとうまくいきました!!

# エフェメラルコンテナの中で実行
$ echo '{"message": "Error while sending request to Stackdriver googleapi: Error 429: One or more TimeSeries could not be written: ~~~長いので省略~~~ rateLimitExceeded", "pid": "1"}' >> /proc/1/fd/2  # PID1に標準エラー出力にJSON形式のテキストを追記

無事意図通りにエラーログの監視が実装できていることを確認することができました。

まとめ

GKEとCloud Monitoringにおけるログ監視アラートの動作確認方法について説明しました。

コンテナの標準出力(エラー)にメッセージを送ることでログを再現することができます
kubectl debugを使うことで、シェルが含まれないコンテナでも中に入ることができます
Cloud Loggingのmessageフィールドは仕様が特殊なので気をつけましょう

感想

フィルター条件に過去のログが引っ掛かるから大丈夫だろうということで、動作確認をせずに済ませることもできたタスクでしたが、妥協せずに深く調べることで様々な学びがありました。