runc の不具合で Kubelet が暴れた話

2023/12/12に公開

はじめに

この記事は、 Kubernetes Advent Calendar 2023 の12日目の記事です。
業務内で発生した Kubelet の CPU/Memory 過剰消費による Node 障害に関して、問題発生から解決まで時系列に沿って、紹介していきます。

この記事では cgroup に関する内容が大きく関わりますが、 cgroup 自体に関する説明を1からしていません。
既に web 上に素晴らしい記事などがあるので、 cgroup ってなんぞやという方はそちらを参照されると良いかなと思います。
以下が非常に参考になりました。

TL;DR

最初にざっくり 事象/原因/解決法 を記載するので、お忙しい方はこちらだけでも。

関連 Issue
https://github.com/opencontainers/runc/issues/3849

  • 事象
    • Kubelet の Memory 過剰消費によって、 Node 再起動が頻発
  • 原因
    • cgroup v1 利用時における runc の cgroup misc コントローラーの clean up 処理の失敗
  • 解決法 (以下のいずれか)
    • runc/libcontainer がバージョンアップされた k8s パッチバージョンの利用
      • > 1.28.0
      • > 1.27.2
      • > 1.26.5
    • cgroup v2 の利用

問題発生

所属チームでは KaaS (Kubernetes as a Service) を開発しているのですが、 ある日特定のユーザさんの Node が何度も再起動が発生し、 Prometheus の監視で Kubelet is Down のアラートが何度も起きていました。

実際に Node のメモリ使用率を見てみると、定期的に メモリ逼迫が起きており、 Node が死んでいることが確認されました。。。

memory リソースの limit を設定していなくて何か暴れ倒している Pod がいるのかなと思い、 対象 Node で調べてみると...

ps aux --sort=-%mem | head
USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root     2983590  168 87.0 17037364 12469776 ?   Ssl  01:23  57:34 /usr/bin/kubelet --bootstrap-kubeconfig=/etc/kubernetes/bootstrap-kubelet.conf --kubeconfig=/etc/kubernetes/kubelet.conf --config=/var/lib/kubelet/config.yaml // omit
root         269  1.0  2.0 491288 294656 ?       S<s  Nov06  31:39 /lib/systemd/systemd-journald
root     2984292  4.5  0.9 1758836 130788 ?      Ssl  01:23   1:33 agent run
// omit

まさかの Kubelet がほとんどのメモリを消費してしまっていることが分かりました。
ここから、 Kubelet のデバッグの闘いが始まります。

デバッグ

利用環境は以下です。

  • OS : Ubuntu 20.04.6 LTS
  • Linux Kernel : 5.15.0-71-generic
  • Kubernetes : 1.27.1
  • CRI : containerd 1.7.1
  • OCI Runtime : runc 1.1.7

チームの開発者でデバッグ祭りが始まりました、まずジャーナルログを見てみることにしました。
すると、なにやら Kubelet が Pod の cgroup を削除しようとしていて失敗しているエラーが多発していました。

journalctl -u kubelet
-- Logs begin at Wed 2023-11-08 00:20:27 UTC, end at Wed 2023-11-08 01:59:15 UTC. --
Nov 08 00:20:27 dev-cluster kubelet[2907284]: I1108 00:20:27.240296 2907284 pod_container_manager_linux.go:210] "Failed to delete cgroup paths" cgroupName=[kubepods burstable pod1495abbc->
Nov 08 00:20:27 dev-cluster kubelet[2907284]: I1108 00:20:27.240943 2907284 pod_container_manager_linux.go:210] "Failed to delete cgroup paths" cgroupName=[kubepods podbff40d3b-2852-41fa->
Nov 08 00:20:27 dev-cluster kubelet[2907284]: I1108 00:20:27.241207 2907284 pod_container_manager_linux.go:210] "Failed to delete cgroup paths" cgroupName=[kubepods podeb98897f-ce7f-4fba->
Nov 08 00:20:27 dev-cluster kubelet[2907284]: I1108 00:20:27.242681 2907284 pod_container_manager_linux.go:210] "Failed to delete cgroup paths" cgroupName=[kubepods podda588b94-30dc-4678->
Nov 08 00:20:27 dev-cluster kubelet[2907284]: I1108 00:20:27.243546 2907284 pod_container_manager_linux.go:210] "Failed to delete cgroup paths" cgroupName=[kubepods podd743ac06-407e-4760->
Nov 08 00:20:27 dev-cluster kubelet[2907284]: I1108 00:20:27.246251 2907284 pod_container_manager_linux.go:210] "Failed to delete cgroup paths" cgroupName=[kubepods podd4422099-7f87-4693->
Nov 08 00:20:27 dev-cluster kubelet[2907284]: I1108 00:20:27.247927 2907284 pod_container_manager_linux.go:210] "Failed to delete cgroup paths" cgroupName=[kubepods podf816fe49-769c-4c40->
Nov 08 00:20:27 dev-cluster kubelet[2907284]: I1108 00:20:27.250900 2907284 pod_container_manager_linux.go:210] "Failed to delete cgroup paths" cgroupName=[kubepods pod6aac1da8-c1f7-4015->

そのため、 systemd-cgls コマンドで cgroups の階層を表示し、該当の Pod が存在するか探してみましたが、ログに該当する Pod の cgroup は既に存在しないといった状態でした。
(この時点でとても絶望していました)
後述しますが、この時に systemd-cgls memory として、メモリのコントローラーで確認していたので存在していなかったことがわかりました。
以下は、コマンド表示例です。 ※ 実際のプロセス名は伏せた状態です

systemd-cgls memory
Controller memory; Control group /:
└─kubepods.slice
  ├─kubepods-pod71d1febb_b6ca_491d_97cb_4340a4e7ca51.slice
  │ ├─cri-containerd-156fa789e2773919c353c9d92199e3d4649f8a173f1041e8d534211fc7725d6c.scope
  │ ├─cri-containerd-e2c1ff44e50abe1b03f90186fec5fbd63904dd2056d2413db72916c2cbb2f851.scope
  │ ├─cri-containerd-fd1798f09401c00a044353f04b67c8b86349b4a64df3209d288a745762134213.scope
  │ └─cri-containerd-aded3f852faa31cf3dc19d61806bd22a595f4526b85926dfd255bd0f4e7a561a.scope
  └─kubepods-burstable.slice
    ├─kubepods-burstable-podba758fe9_e5df_4f21_822d_82dd8e69d490.slice
    │ ├─cri-containerd-759b532fbbbc505f0a4b8087189a417bfba132ba0fd980376513b95362279962.scope
    │ ├─cri-containerd-b631e07d61e1bcc4a0c48fccf24ed119364dd3ca65d8d0d8c3fa3bfc1e3c8bb0.scope
    │ └─cri-containerd-396f42d93f69e67cabb85082eb7cb6a168819005c49f293e8cd209bd7604b738.scope
    ├─kubepods-burstable-pode95be299b415ebcd7a94d4301040f429.slice
    │ ├─cri-containerd-db8fe54f168ea02764ae48c6083a713ebfd643f8a53136834996c6540df9bb38.scope
    │ └─cri-containerd-5cb34f00d28e465c98de6332de4db71e6ceff3319355571b3180373b290258bc.scope
    ├─kubepods-burstable-podf0a82a340a7886f682b8a95f0135e11c.slice
    │ ├─cri-containerd-905f9ea46ea994ffc94c3e306e3112984e221a60fae892aa2e0da8413ee569c6.scope
    │ └─cri-containerd-c1c29715932d8e4e51501dcca91c9a45d9d4f1a6f2c0256b793a4ae34489380c.scope
    ├─kubepods-burstable-podf26d1464_bc0d_43c8_aad9_664504951095.slice
    │ ├─cri-containerd-d9bd512ff1851174e93a0cd1ef3d2deef7f52fa4f1f8f7ac89e4cc89afc884c5.scope
    │ └─cri-containerd-4bbb4928e47b1bc074566e26efcc9940da825f6491461028d40e986ab933cdae.scope
    ├─kubepods-burstable-pod39eb450f575ebf1ca6dff5b53bacca00.slice
    │ ├─cri-containerd-4a790c7f3594e78df87e1be55b5dcc2b30b57fecffc0ac333a62c9da16e5d764.scope
    │ └─cri-containerd-185a10c5b3cb25cbdf9265e9f80b06f959ec1c2717257c29ba7f6c004a8ac94a.scope
    └─kubepods-burstable-pod5bb51662384d78ca722fef44e0cf31df.slice

また、ログからおそらく以下の Kubelet の処理でコケているが、その関数の呼び出し元が Kubernets のコードが膨大なため、なかなか見つけられずといった状態でした。

https://github.com/kubernetes/kubernetes/blob/master/pkg/kubelet/cm/pod_container_manager_linux.go#L197-L214

このままでは解決の糸口がなかったため、 Kubelet の デバッグレベルを変更し、より詳細なログを取得してみることにしました。その結果以下のログが確認され、

Orphaned pod found, removing pod cgroups

以下の Kubelet の cleanupOrphanedPodCgroups の呼び出しで処理が失敗していることがわかりました。

https://github.com/kubernetes/kubernetes/blob/v1.27.1/pkg/kubelet/kubelet_pods.go#L2141-L2168

さらにこの関数で処理する削除対象となる Pod の cgroup は以下の関数で、抽出していることがわかりました。
その結果、削除対象は以下に基づいて抽出していることを確認しました。
cgroup の全てのサブシステムマウントをスキャンし、全てのサブシステムマウントの各 QoS cgroup ディレクトリをスキャンする。1つのサブシステムでも存在すると削除対象とする。

https://github.com/kubernetes/kubernetes/blob/v1.27.1/pkg/kubelet/cm/pod_container_manager_linux.go#L248-L298

またそれと同タイミングで、 Kubelet のログで表示されていた Pod の cgroup は misc コントローラー配下のディレクトリで発見することができました。
なぜ misc コントローラーのみ残っているのか? という疑問がありましたが、 misc コントローラーサブシステムが存在しているため、 Orphaned Pod と扱われているのではないかという推測が立ちました。

この情報を基に再度 Kubernetes や runc、 containerd の Issue などを探していると、以下の Issue を発見することができました。
発生しているログや、事象がかなり類似していることから、この Issue の問題がほぼ原因であるだろうと断定をし、 Issue の内容の理解のフェーズに入りました。

https://github.com/opencontainers/runc/issues/3849

原因分析

原因分析の前に、 少しだけ cgroup の話をしましょう。

cgroup はプロセスをグループ化して、グループ内のプロセスに対して共通の管理を行うことができます。たとえば、ホストOSが持つCPUやメモリなどのリソースに対して、グループごとに制限をかけることができます。
cgroup への操作は cgroup ファイルシステム (cgroupfs) を介して行います。
cgroup には v1, v2 があり、ファイルシステムの階層構造が異なります。

cgroup v1 では cgroup で管理する各リソース (cgroup ではこれをコントローラあるいはサブシステムと呼びます) 毎に cgroupfs をマウントします。 /sys/fs/cgroup 配下に、 /sys/fs/cgroup/cpu/sys/fs/cgroup/memory のように複数のマウントポイントがあります。
その一方で cgroup v2 では、コントローラーごとに階層は分かれず、 /sys/fs/cgroup の1つの階層を持ち、 /sys/fs/cgroup/cgroup.controllerscpu memory io などいったサポートするコントローラーを設定するようになっています。

Issue を読む上である程度必要な前提を整理できたところで、実際に Issue の中身を見ましょう。
Issue を確認すると、問題の事象が発生した経緯は以下の Issue の修正内容を取り込んだことによるものと書かれていました。
https://github.com/kubernetes/kubernetes/issues/112124

そのため、まずは kubernetes 112124 の Issue 内容から確認してみましょう。
この Issue では、 Kubelet で以下のログが大量に発生しているといったものでした。

kubelet_getters.go:300] "Path does not exist" path="/var/lib/kubelet/pods/86cba354-348c-4826-9837-df9c616a8862/volumes"

様々な議論がされていましたが、重要な情報が2点ありました。

  1. cgroup v1 がデフォルトの ubuntu 20.04 では発生するが、 cgroup v2 の ubuntu 22.04 では発生していない
  2. カーネル 5.13 より、 misc コントローラーという新規の cgroup コントローラーが追加された

先ほど記載した PodsFromCgroups の削除対象のロジックにより、 misc コントローラーも削除対象となります。さらに runc v1.1.5 までは、 misc コントローラーの Clean Up 処理が実装されていなかったため、エラーログが発生している状態という見解でした。
そのため v1.1.6 では misc コントローラーの Clean Up する実装を追加されました。

https://github.com/opencontainers/runc/pull/3823

この修正が入ったことで、 cgroup 絡みの問題は解決したように思えますが、 runc / containerd / kubernetes のリリースプロセスによって、 runc Issue 3849 の事象が発生していたので、最後に確認しましょう。

I suspect that runc 1.1.6 binary creates misc cgroup, and then kubelet uses runc's libcontainer (of an older version) to remove it. That older libcontainer version doesn't know about misc (and systemd doesn't know about it either), so it's not removed.

上の記載の通りですが、低レベルランタイムとしての runc と kubelet 内で Pod の管理で利用される libcontainer にバージョン差分があると、 認識できない cgroup コントローラーの削除に失敗してしまうとのことです。 (今回の場合は、 misc コントローラー)

なぜこのようなバージョン差分が生まれるかというと、 kubernetes では以下のリリースプロセスで runc 等のバージョン管理をしています。

  1. runc の新バージョンリリース
  2. 利用する runc バージョンの更新した containerd の新バージョンリリース
  3. 2 の containerd で安定性が確認できたら、 k8s (kubelet等) の runc バージョンの更新

実際に利用していた環境を確認すると、 runc 1.1.7 に対し、 k8s 1.27.1 では 1.1.4 が利用されていました。
(containerd のバージョンを上げすぎたことが悪かったみたいです)
https://github.com/kubernetes/kubernetes/blob/v1.27.1/go.mod#L55

修正対応

現在では、 k8s 1.27.2 以上で runc のアップグレードがされているため、そちらのパッチバージョンを使用するのが良いでしょう。
https://github.com/kubernetes/kubernetes/blob/master/CHANGELOG/CHANGELOG-1.27.md#dependencies-6

また cgroup v1 はいずれ非推奨になる予定なので、 この機会に cgroup v2 の移行を進めるといった方針も考えられます。
実際に所属チームでも ubuntu 22.04 対応の検証を進め、 cgroup v2 での運用を開始しています。

まとめ

kubelet の メモリ高負荷の原因は、 cgroup の新規コントローラーが追加されたことや、 runc/libcontainer 間のバージョン差分によるものでした。
自前で k8s イメージを作成する場合は、使用する k8s version の依存コンポーネントのバージョンをしっかり確認して、先行して利用しないように留意すべしと教訓になりました。

長々と書いてきましたが、同様の事象が起きた場合の参考になれば幸いです!!

Discussion