年間600時間を節約したKubernetesの一行修正
Cloudflareは、Kubernetesの安全なデフォルト設定がAtlantisの再起動時に30分の遅延を引き起こしていた問題を、永続ボリュームのinode問題を特定し、1行の変更で年間600時間のエンジニアリング時間を節約する解決策を発見した。
キーポイント
問題の発見と影響
Atlantisの再起動時に30分の遅延が発生し、月間100回の再起動で50時間以上のエンジニアリング時間がブロックされ、オンフォールエンジニアが毎回呼び出されていた。
根本原因の特定
Kubernetesの安全なデフォルト設定が、数百万ファイルを含む永続ボリュームの成長に伴ってボトルネックとなり、inode不足による再起動遅延を引き起こしていた。
解決策と効果
1行の変更で問題を解決し、年間600時間のエンジニアリング時間を節約し、運用効率を大幅に向上させた。
調査アプローチ
アラート期間の延長ではなく根本原因の調査を選択し、initコンテナの待機状態から問題を追跡した。
Kubeletログ分析による問題特定
Kubernetesのkubeletログを分析した結果、ボリュームマウント後にコンテキストデッドライン超過エラーが発生し、ポッドの起動が遅延していることが判明した。
システムログの重要性
Kubernetes自体のイベントだけでは問題の根本原因を特定できず、kubeletのシステムログ(Kibana経由)を調査することで詳細な情報が得られた。
fsGroupChangePolicyによる起動時間の大幅短縮
Kubernetes 1.20で導入されたfsGroupChangePolicyをOnRootMismatchに設定することで、PVマウント時の再帰的な権限変更を回避し、Atlantisの再起動時間を30分から30秒に短縮した。
影響分析・編集コメントを表示
影響分析
この記事は、Kubernetes環境での大規模運用における微妙な設定問題が重大なパフォーマンス低下を引き起こす実例を示しており、DevOpsエンジニアにとって実用的な教訓を提供している。特に、安全なデフォルト設定がスケールに伴ってボトルネックとなる可能性を認識させることで、類似環境での問題予防に貢献する。
編集コメント
技術的な深掘りと実用的な解決策が明確に示されており、DevOps実務者にとって即座に参考になる内容。大規模運用環境での微妙な設定問題の重要性を具体的な数値で示している点が説得力がある。
Atlantis(Terraform の変更を計画・適用するために使用するツール)を再起動するたびに、起動するまで 30 分間も待たされ、その間は計画も実行もできず、Atlantis が管理するすべてのリポジトリに対するインフラの変更が停止していました。認証情報のローテーションやオンボーディング解除のために月間約 100 回の再起動が必要となるため、毎月 50 時間以上ものエンジニアの作業時間がブロックされ、そのたびにオンコール担当者にアラートが送信されていました。
これは最終的に、Atlantis が使用する永続ボリューム(Persistent Volume)が数百万ファイルに成長するにつれて、安全なデフォルト設定が静かにボトルネック化してしまったことが原因でした。以下に、その問題を特定し、1 行の変更でどのように解決したかを示します。
謎の再起動遅延
私たちは Atlantis を使用して GitLab のマージリクエスト(MR)を通じて数十の Terraform プロジェクトを管理しており、Atlantis が計画と適用を担当しています。これにより、同時にプロジェクトを変更できる MR は 1 つだけというロックが強制されます。
これは Kubernetes 上でシングルトンの StatefulSet として実行され、ディスク上のリポジトリの状態を追跡するために Kubernetes の永続ボリューム(Persistent Volume)に依存しています。Terraform プロジェクトのオンボーディングやオフボーディングが必要になった場合、または Terraform が使用する認証情報が更新された場合は、これらの変更を反映させるために Atlantis を再起動する必要があり、このプロセスには 30 分かかることがあります。
Atlantis が使用する永続ストレージのインデックスノード(inodes)が枯渇し、ボリュームのサイズ変更のために再起動を余儀なくされた際、低速な再起動は明確に確認されました。インデックスノードはディスク上の各ファイルおよびディレクトリエントリによって消費され、ファイルシステムで利用可能な数は作成時に渡されるパラメータによって決定されます。Kubernetes プラットフォームが提供する Ceph 永続ストレージ実装では、mkfs にフラグを渡す方法が公開されていないため、デフォルト値に頼らざるを得ません。つまり、利用可能なインデックスノードを増やすにはファイルシステムを拡張するしかなく、PV(永続ボリューム)の再起動にはポッドの再起動が必要です。
アラートウィンドウを延長することについて議論しましたが、それは問題を隠蔽し、実際の事象への対応を遅らせるだけだと判断しました。代わりに、なぜこれほど時間がかかるのかを正確に調査することに決めました。
悪い振る舞い
Atlantis が使用するシークレットの変更を取り込むためにローリング再起動を行うよう求められた際、kubectl rollout restart statefulset atlantis を実行し、新しいポッドを起動する前に既存の Atlantis ポッドを正常に終了させていました。新しいポッドはほぼ即座に表示されますが、確認すると以下のような状態でした:
$ kubectl get pod atlantis-0
atlantis-0 0/1
Init:0/1 0 30m
...では、何が起きているのでしょうか?当然のことながら、最初に確認すべきはそのポッドのイベントです。初期化コンテナの実行を待機しているため、ポッドのイベントにその理由が明かされているかもしれません。
$ kubectl events --for=pod/atlantis-0
LAST SEEN TYPE REASON OBJECT MESSAGE
30m Normal Killing Pod/atlantis-0 Stopping container atlantis-server
30m Normal Scheduled Pod/atlantis-0 Successfully assigned atlantis/atlantis-0 to 36com1167.cfops.net
22s Normal Pulling Pod/atlantis-0 Pulling image "oci.example.com/git-sync/master:v4.1.0"
22s Normal Pulled Pod/atlantis-0 Successfully pulled image "oci.example.com/git-sync/master:v4.1.0" in 632ms (632ms including waiting). Image size: 58518579 bytes.
これはほぼ正常に見えますが、ポッドのスケジューリングから初期化コンテナのイメージをプルし始めるまでの間に、なぜこれほど時間がかかっているのでしょうか?残念ながら、Kubernetes 自体からはこれ以上のデータは得られませんでした。しかし、実際にポッドの実行を開始するのにこれほど時間がかかる理由を説明する何かが必ずあるはずです。
さらに深く掘り下げる
Kubernetes において、各ノード上で実行される kubelet というコンポーネントは、ポッドの作成や永続ボリュームのマウントなど、数多くのタスクを調整する責任を負っています。私が Kubernetes チームに在籍していた経験から、kubelet は systemd サービスとして動作しており、そのログは Kibana で確認できることを知っています。すでにポッドがスケジュールされているため、関心のあるホスト名は特定でき、kubelet のログメッセージには関連するオブジェクト情報も含まれているため、"atlantis" でフィルタリングして興味深いログメッセージを絞り込むことができました。
私たちは、ポッドのスケジューリング直後に Atlantis の PV がマウントされるのを確認できました。また、すべてのシークレットボリュームが問題なくマウントされることも観察しました。しかし、依然としてログには説明できない大きなギャップが存在していました。私たちが目にしたのは次の通りです:
[operation_generator.go:664] "MountVolume.MountDevice succeeded for volume \"pvc-94b75052-8d70-4c67-993a-9238613f3b99\" (UniqueName: \"kubernetes.io/csi/rook-ceph-nvme.rbd.csi.ceph.com^0001-000e-rook-ceph-nvme-0000000000000002-a6163184-670f-422b-a135-a1246dba4695\") pod \"atlantis-0\" (UID: \"83089f13-2d9b-46ed-a4d3-cba885f9f48a\") device mount path \"/state/var/lib/kubelet/plugins/kubernetes.io/csi/rook-ceph-nvme.rbd.csi.ceph.com/d42dcb508f87fa241a49c4f589c03d80de2f720a87e36932aedc4c07840e2dfc/globalmount\"" pod="atlantis/atlantis-0"
[pod_workers.go:1298] "Error syncing pod, skipping" err="unmounted volumes=[atlantis-storage], unattached volumes=[], failed to process volumes=[]: context deadline exceeded" pod="atlantis/atlantis-0" podUID="83089f13-2d9b-46ed-a4d3-cba885f9f48a"
[util.go:30] "No sandbox for pod can be found. Need to start a new one" pod="atlantis/atlantis-0"
The last two messages looped several times until eventually we observed the pod actually start up properly.
So kubelet thinks that the pod is otherwise ready to go, but it's not starting it and something's timing out.
The missing piece
Pod に設定していた最下位レベルのログでは、何が起きているのか分かりませんでした。他に確認すべきことは何でしょうか?実は、ハングする直前の最後のメッセージは、PV がノードにマウントされているというものでした。通常、PV のマウントに問題がある場合(例えば、他のノードでまだマウントされたままになっているなど)、それはイベントとして表面化します。しかしここでは何か別のことが起きているようで、私たちがさらに掘り下げるために残っているのは PV 自体だけです。そこで PV 名が検索用語として十分にユニークなので Kibana に投入すると、すぐに目立つものが見つかりました:
[volume_linux.go:49] Setting volume ownership for /state/var/lib/kubelet/pods/83089f13-2d9b-46ed-a4d3-cba885f9f48a/volumes/kubernetes.io~csi/pvc-94b75052-8d70-4c67-993a-9238613f3b99/mount and fsGroup set. If the volume has a lot of files then setting volume ownership could be slow, see https://github.com/kubernetes/kubernetes/issues/69699
Remember how I said at the beginning we'd just run out of inodes? In other words, we have a lot of files on this PV. When the PV is mounted, kubelet is running chgrp -R to recursively change the group on every file and folder across this filesystem. No wonder it was taking so long — that's a ton of entries to traverse even on fast flash storage!
[volume_linux.go:49] Setting volume ownership for /state/var/lib/kubelet/pods/83089f13-2d9b-46ed-a4d3-cba885f9f48a/volumes/kubernetes.io~csi/pvc-94b75052-8d70-4c67-993a-9238613f3b99/mount and fsGroup set. If the volume has a lot of files then setting volume ownership could be slow, see https://github.com/kubernetes/kubernetes/issues/69699
Remember how I said at the beginning we'd just run out of inodes? In other words, we have a lot of files on this PV. When the PV is mounted, kubelet is running chgrp -R to recursively change the group on every file and folder across this filesystem. No wonder it was taking so long — that's a ton of entries to traverse even on fast flash storage!
Pod の spec.securityContext に fsGroup: 1 が含まれており、これにより GID 1 で実行されるプロセスがボリューム上のファイルにアクセスできるようになります。Atlantis は非ルートユーザーとして実行されるため、この設定がないと PV(永続ボリューム)への読み書き権限がありません。Kubernetes はこれを強制するために、PV をマウントするたびに PV 全体の所有権を再帰的に更新します。
Fixing this was heroically...boring.
この修正は英雄的に…退屈なものでした。バージョン 1.20 以降、Kubernetes では pod.spec.securityContext に fsGroupChangePolicy という追加フィールドがサポートされるようになりました。このフィールドのデフォルト値は Always で、これがまさに今回見られる動作を引き起こします。もう一つのオプションとして OnRootMismatch があり、これは PV のルートディレクトリに適切な権限がない場合のみ権限を変更するものです。PV 上でファイルがどのように作成されているかを正確に知らない場合は、fsGroupChangePolicy: OnRootMismatch を設定しないでください。私たちは、PV 内の何らかのものがグループ変更を引き起こす可能性がないことを確認した上で、このフィールドを設定しました:
spec:
template:
spec:
securityContext:
fsGroupChangePolicy: OnRootMismatch
これで、Atlantis の再起動に要する時間は約 30 秒となり、開始時の 30 分から大幅に短縮されました。
デフォルトの Kubernetes セッティングは小規模なデータ量では合理的ですが、データが増大するにつれてボトルネックになる可能性があります。私たちの場合、この fsGroupChangePolicy に関する一行の変更により、毎月約 50 時間のエンジニアリング時間がブロックされるのを回避できました。これは、インフラストラクチャの変更が承認されるまでチームが待たされていた時間であり、オンコール担当のエンジニアが誤報に対応するために費やしていた時間です。つまり、デプロイよりも診断に時間を要したこの修正によって、年間約 600 時間が生産的な業務に戻されたことになります。
Kubernetes の安全なデフォルト設定は、小規模で単純なワークロードを対象に設計されています。しかし、スケールするにつれて、徐々にボトルネックとなる可能性があります。大規模な永続ボリュームを扱うワークロードを実行している場合は、このような再帰的な権限変更が起動時間を静かに消費していないか確認する価値があります。securityContext セッティング、特に fsGroup と fsGroupChangePolicy を監査してください。OnRootMismatch は v1.20 から利用可能です。
すべての修正が英雄的または複雑である必要はなく、「なぜシステムはこのように動作するのか?」と問うことは通常、価値のあることです。
大規模なインフラストラクチャの問題のデバッグに興味がある場合、私たちは採用中です。Cloudflare Community または Discord に参加して、業界の話について語り合いましょう。
原文を表示
Every time we restarted Atlantis, the tool we use to plan and apply Terraform changes, we’d be stuck for 30 minutes waiting for it to come back up. No plans, no applies, no infrastructure changes for any repository managed by Atlantis. With roughly 100 restarts a month for credential rotations and unboarding, that added up to over 50 hours of blocked engineering time every month, and paged the on-call engineer every time.
This was ultimately caused by a safe default in Kubernetes that had silently become a bottleneck as the persistent volume used by Atlantis grew to millions of files. Here’s how we tracked it down and fixed it with a one-line change.
Mysteriously slow restarts
We manage dozens of Terraform projects with GitLab merge requests (MRs) using Atlantis, which handles planning and applying. It enforces locking to ensure that only one MR can modify a project at a time.
It runs on Kubernetes as a singleton StatefulSet and relies on a Kubernetes PersistentVolume (PV) to keep track of repository state on disk. Whenever a Terraform project needs to be onboarded or offboarded, or credentials used by Terraform are updated, we have to restart Atlantis to pick up those changes — a process that can take 30 minutes.
The slow restart was apparent when we recently ran out of inodes on the persistent storage used by Atlantis, forcing us to restart it to resize the volume. Inodes are consumed by each file and directory entry on disk, and the number available to a filesystem is determined by parameters passed when creating it. The Ceph persistent storage implementation provided by our Kubernetes platform does not expose a way to pass flags to mkfs, so we’re at the mercy of default values: growing the filesystem is the only way to grow available inodes, and restarting a PV requires a pod restart.
We talked about extending the alert window, but that would just mask the problem and delay our response to actual issues. Instead, we decided to investigate exactly why it was taking so long.
Bad behavior
When we were asked to do a rolling restart of Atlantis to pick up a change to the secrets it uses, we would run kubectl rollout restart statefulset atlantis, which would gracefully terminate the existing Atlantis pod before spinning up a new one. The new pod would appear almost immediately, but looking at it would show:
$ kubectl get pod atlantis-0
atlantis-0 0/1
Init:0/1 0 30m
...so what gives? Naturally, the first thing to check would be events for that pod. It's waiting around for an init container to run, so maybe the pod events would illuminate why?
$ kubectl events --for=pod/atlantis-0
LAST SEEN TYPE REASON OBJECT MESSAGE
30m Normal Killing Pod/atlantis-0 Stopping container atlantis-server
30m Normal Scheduled Pod/atlantis-0 Successfully assigned atlantis/atlantis-0 to 36com1167.cfops.net
22s Normal Pulling Pod/atlantis-0 Pulling image "oci.example.com/git-sync/master:v4.1.0"
22s Normal Pulled Pod/atlantis-0 Successfully pulled image "oci.example.com/git-sync/master:v4.1.0" in 632ms (632ms including waiting). Image size: 58518579 bytes.
That looks almost normal... but what's taking so long between scheduling the pod and actually starting to pull the image for the init container? Unfortunately that was all the data we had to go on from Kubernetes itself. But surely there had to be something more that can tell us why it's taking so long to actually start running the pod.
Going deeper
In Kubernetes, a component called kubelet that runs on each node is responsible for coordinating pod creation, mounting persistent volumes, and many other things. From my time on our Kubernetes team, I know that kubelet runs as a systemd service and so its logs should be available to us in Kibana. Since the pod has been scheduled, we know the host name we're interested in, and the log messages from kubelet include the associated object, so we could filter for atlantis to narrow down the log messages to anything we found interesting.
We were able to observe the Atlantis PV being mounted shortly after the pod was scheduled. We also observed all the secret volumes mount without issue. However, there was still a big unexplained gap in the logs. We saw:
[operation_generator.go:664] "MountVolume.MountDevice succeeded for volume \"pvc-94b75052-8d70-4c67-993a-9238613f3b99\" (UniqueName: \"kubernetes.io/csi/rook-ceph-nvme.rbd.csi.ceph.com^0001-000e-rook-ceph-nvme-0000000000000002-a6163184-670f-422b-a135-a1246dba4695\") pod \"atlantis-0\" (UID: \"83089f13-2d9b-46ed-a4d3-cba885f9f48a\") device mount path \"/state/var/lib/kubelet/plugins/kubernetes.io/csi/rook-ceph-nvme.rbd.csi.ceph.com/d42dcb508f87fa241a49c4f589c03d80de2f720a87e36932aedc4c07840e2dfc/globalmount\"" pod="atlantis/atlantis-0"
[pod_workers.go:1298] "Error syncing pod, skipping" err="unmounted volumes=[atlantis-storage], unattached volumes=[], failed to process volumes=[]: context deadline exceeded" pod="atlantis/atlantis-0" podUID="83089f13-2d9b-46ed-a4d3-cba885f9f48a"
[util.go:30] "No sandbox for pod can be found. Need to start a new one" pod="atlantis/atlantis-0"
The last two messages looped several times until eventually we observed the pod actually start up properly.
So kubelet thinks that the pod is otherwise ready to go, but it's not starting it and something's timing out.
The missing piece
The lowest-level logs we had on the pod didn't show us what's going on. What else do we have to look at? Well, the last message before it hangs is the PV being mounted onto the node. Ordinarily, if the PV has issues mounting (e.g. due to still being stuck mounted on another node), that will bubble up as an event. But something's still going on here, and the only thing we have left to drill down on is the PV itself. So I plug that into Kibana, since the PV name is unique enough to make a good search term... and immediately something jumps out:
[volume_linux.go:49] Setting volume ownership for /state/var/lib/kubelet/pods/83089f13-2d9b-46ed-a4d3-cba885f9f48a/volumes/kubernetes.io~csi/pvc-94b75052-8d70-4c67-993a-9238613f3b99/mount and fsGroup set. If the volume has a lot of files then setting volume ownership could be slow, see https://github.com/kubernetes/kubernetes/issues/69699
Remember how I said at the beginning we'd just run out of inodes? In other words, we have a lot of files on this PV. When the PV is mounted, kubelet is running chgrp -R to recursively change the group on every file and folder across this filesystem. No wonder it was taking so long — that's a ton of entries to traverse even on fast flash storage!
The pod's spec.securityContext included fsGroup: 1, which ensures that processes running under GID 1 can access files on the volume. Atlantis runs as a non-root user, so without this setting it wouldn’t have permission to read or write to the PV. The way Kubernetes enforces this is by recursively updating ownership on the entire PV every time it's mounted.
The fix
Fixing this was heroically...boring. Since version 1.20, Kubernetes has supported an additional field on pod.spec.securityContext called fsGroupChangePolicy. This field defaults to Always, which leads to the exact behavior we see here. It has another option, OnRootMismatch, to only change permissions if the root directory of the PV doesn't have the right permissions. If you don’t know exactly how files are created on your PV, do not set fsGroupChangePolicy: OnRootMismatch. We checked to make sure that nothing should be changing the group on anything in the PV, and then set that field:
spec:
template:
spec:
securityContext:
fsGroupChangePolicy: OnRootMismatch
Now, it takes about 30 seconds to restart Atlantis, down from the 30 minutes it was when we started.
Default Kubernetes settings are sensible for small volumes, but they can become bottlenecks as data grows. For us, this one-line change to fsGroupChangePolicy reclaimed nearly 50 hours of blocked engineering time per month. This was time our teams had been spending waiting for infrastructure changes to go through, and time that our on-call engineers had been spending responding to false alarms. That’s roughly 600 hours a year returned to productive work, from a fix that took longer to diagnose than deploy.
Safe defaults in Kubernetes are designed for small, simple workloads. But as you scale, they can slowly become bottlenecks. If you’re running workloads with large persistent volumes, it’s worth checking whether recursive permission changes like this are silently eating your restart time. Audit your securityContext settings, especially fsGroup and fsGroupChangePolicy. OnRootMismatch has been available since v1.20.
Not every fix is heroic or complex, and it’s usually worth asking “why does the system behave this way?”
If debugging infrastructure problems at scale sounds interesting, we’re hiring. Come join us on the Cloudflare Community or our Discord to talk shop.
関連記事
今日のまとめ
AI日報で今日の重要ニュースをまとめ読み