preStop をログ出力させる方法

この記事は ZOZO Advent Calendar 2024 シリーズ7の12日目の記事です。

はじめに

こんにちは、計測プラットフォーム開発本部 SRE ブロックの yamagai です。

今回は、チームで運用している EKS クラスタ(Fargate)上に載った Pod の preStop での処理内容をログ出力するように設定したので、その方法や関連情報を記事にしました。

背景

preStop の処理をログに出力させたくなった経緯は以下の通りです。

• 本番でのデプロイ時に 503 が発生した
• 調査してみると、Pod のロールアウト時に preStop で実行している処理(ヒープダンプの S3 への送信)が異常終了しており preStop が効いていないことが原因だった
  • Pod がサービスアウトされる前に Pod が終了してしまい、流れてきたトラフィックが 503 になっていた
• preStop の失敗が非常に検知しづらいことがわかったので検知できるようにしたい

preStop でサービスアウトを待つ設定は注意深く行なっていたので、503 が発生した際は preStop の処理が失敗していることに気付くまでに時間がかかりました。

そういった経緯から、preStop でのエラーを検知しようというモチベーションが生まれました。

余談ですが、preStop がデバッグしづらい点は kubernetes/kubernetes でも指摘されており、コンテナログに出力させる方は検討されているものの、まだ実現はされていないようです。

• https://github.com/kubernetes/kubernetes/issues/16412
• https://github.com/kubernetes/kubernetes/issues/25766

実現方法の調査

/proc/1/fd/1 に書き込む方法

これは PID 1 で実行されるメインプロセスの標準出力/エラー出力のみがコンテナのロギングドライバにリダイレクトされる仕組みを利用した方法で、kubernetes/kubernetes の issue コメントでもワークアラウンドとして紹介されています。

ただし、/proc/1/fd/1 に書き込みが許可されていないケースなどはこの方法は利用できません。
我々のチームでもこの方法では Permission denied のエラーが発生し、書き込みに失敗してしまいました。

sh-4.2$ ls -l /proc/1
...
dr-x------  2 root root 0 Dec 11 05:47 fd
...

これを回避するには、

1. /proc/1/fd/1 自体を実行ユーザー権限で作るようにする
2. /proc/1/fd/1 へ書き込める権限をコンテナに与える

といった方法が考えられます。

1 の方法については、shareProcessNamespace: true により /pause プロセスが root で実行されている(参考記事: https://text.superbrothers.dev/200328-how-to-avoid-pid-1-problem-in-kubernetes/) のか、Fargate 側で制御されているのかがブラックボックスになっているのもあり、root 以外で PID 1 を実行させる方法が思い当たらず断念しました。

2 の方法については、ドキュメントに記載の通り Capabilities を設定すれば実現できそうだったので試してみました。
ほぼ権限の強さとしては root に近くなってしまいますが、

securityContext:
    capabilities:
        add: [ "SYS_ADMIN" ]

上記のように SYS_ADMIN を追加してみたところ、

Pod not supported on Fargate: invalid SecurityContext fields: Capabilities added: SYS_ADMIN,Capabilities added: SYS_ADMIN

Fargate ではサポートされていないということでこの方法も断念しました。

preStop を設定したコンテナと共有ボリュームを持った新コンテナを用意する方法

/proc/1/fd/1 に書き込む方法を取れないことがわかったので、代案として、ボリュームを共有したサイドカーを立てその共有ボリュームにログを書き込む方式を試してみました。

具体的な実装は以下の通りで、

apiVersion: apps/v1
kind: Deployment
metadata:
  name: api-server-deployment
  labels:
    app: api-server
spec:
  selector:
    matchLabels:
      app: api-server
  template:
    metadata:
      labels:
        app: api-server
    spec:
      shareProcessNamespace: true
      containers:
        - name: api-server
          image: ...
          env:
            ...
          lifecycle:
            preStop:
              exec:
                command:
                  - /bin/sh
                  - "-c"
                  - >-
                    echo "{\"pod_name\":\"${POD_NAME}\",\"container_name\":\"api-server\",\"message\":\"PreStop hook started. Send heapdump to S3, and Sleep 50s...\"}" >> /shared-logs/prestop.log 2>&1;
                    // ヒープダンプを S3 に送信するスクリプトの実行
                    sh /opt/docker/upload-heapdump.sh /dump/heapdump.hprof ${S3_BUCKET_HEAP_DUMP} >> /shared-logs/prestop.log 2>&1;
                    sleep 50 >> /shared-logs/prestop.log 2>&1;
                    echo "{\"pod_name\":\"${POD_NAME}\",\"container_name\":\"api-server\",\"message\":\"PreStop hook finished.\"}" >> /shared-logs/prestop.log 2>&1;
          volumeMounts:
            ...
            - mountPath: /shared-logs
              name: shared-logs
        // preStop ログの出力用新コンテナ
        - name: log-forwarder
          image: busybox:1.37
          command: [ "/bin/sh", "-c" ]
          args:
            - |
              touch /shared-logs/prestop.log
              chmod 666 /shared-logs/prestop.log
              tail -F /shared-logs/prestop.log
          lifecycle:
            preStop:
              exec:
                command:
                  - /bin/sh
                  - "-c"
                  - >-
                    echo "{\"pod_name\":\"${POD_NAME}\",\"container_name\":\"prestop-log-forwarder\",\"message\":\"PreStop hook started. Sleep 55s...\"}" >> /shared-logs/prestop.log 2>&1;
                    sleep 55 >> /shared-logs/prestop.log 2>&1;
                    echo "{\"pod_name\":\"${POD_NAME}\",\"container_name\":\"prestop-log-forwarder\",\"message\":\"PreStop hook finished.\"}" >> /shared-logs/prestop.log 2>&1;
          env:
            ...
          volumeMounts:
            - name: shared-logs
              mountPath: /shared-logs
        // 他コンテナも同様に設定する
        - name: envoy
          ...
      volumes:
        ...
        - name: shared-logs
          emptyDir: {}

• log-forwarder コンテナがログを残すためのコンテナで、ログファイルを Pod 内の各コンテナと共有している
• log-forwarder コンテナでは常にログファイルを tail しておき、各コンテナの preStop で共有しているログファイルにログを書き込むことで、log-forwarder コンテナのログに書き込まれたログが残る
• Fargate の設定上、log-forwarder コンテナのログは CloudWatch に書き込まれ保存される
  • https://aws.amazon.com/blogs/containers/fluent-bit-for-amazon-eks-on-aws-fargate-is-here/

というようになっています。

/proc/1/fd/1 に書き込む方式だと Pod 内の各コンテナのログに preStop のログが混じってしまうのに対して、この方法だと log-forwarder コンテナにログが集約されるので検索効率が高いという点が地味に良いポイントかなと思います。

実際に動かしてみると

以下の通り、preStop のログが CloudWatch に保存されるようになりました。

最後に

以上が preStop をログ出力させるために行なった内容です。

サイドカーコンテナを新規に増設するのは少し仰々しい気もしますが、やりたいことは実現出来たかなと思います。

/proc/1/fd の実行ユーザーが root であったためにアプリケーションの実行ユーザーからは /proc/1/fd/1 にアクセスできず /proc/1/fd/1 へ書き込む方式が使えませんでしたが、この原因が EKS Fargate ゆえなのか、他の原因なのかは深掘り出来ていないので、今後どこかで回避方法と共に深掘りしたいと思います。
(もし詳しい方がいらっしゃったらぜひコメントで教えていただけますと助かります。)

紹介した内容が少しでもお役に立てば幸いです。