ConfigMap/Secret の修正が Pod に反映されるまでには 1 分以上かかる
はじめに
kubernetes の ConfigMap
/Secret
を Pod
に Volume としてマウントしている場合、ConfigMap
/Secret
を修正すると Pod
の Volume に自動的に反映される事は良く知られている。
しかし、その反映に 1 分以上かかる事はあまり知られていないのではないだろうか?[1]
すみません、ちょっとだけ(?)盛りました。必ず 1 分以上かかるわけでは無く、運が良ければ 1 分切る事もある。が、運が悪いと 1 分半かかることもある。
と言うわけで、まずは実際反映に 1 分以上かかったりすることを確認するちょっとした実験を行い、その後遅い理由を解説する。また、併せて簡単な対処方法も紹介したいと思う。
ホントにそんなに遅いの?
遅いことを確認するために以下のようなマニフェストを用意する。
apiVersion: v1
kind: ConfigMap
metadata:
name: cm
data:
time: "---"
---
apiVersion: v1
kind: Pod
metadata:
name: pod
spec:
containers:
- name: busybox
image: busybox
args:
- sleep
- "9999999"
volumeMounts:
- name: cm
mountPath: /cm
readOnly: true
terminationGracePeriodSeconds: 0
volumes:
- name: cm
configMap:
name: cm
見ての通り、cm
と言う名前の ConfigMap
をマウントした上で一生寝てるだけの pod
と言う名前の Pod
である。
これをデプロイして 1 秒に 1 回 ConfigMap
の中身を時刻と共に垂れ流す。
$ kubectl create -f pod.yaml
configmap/cm created
pod/pod created
$ kubectl exec -it pod -- sh -c 'while sleep 1; do echo "$(date) - $(cat /cm/time)"; done'
Thu Sep 12 18:45:22 UTC 2024 - ---
Thu Sep 12 18:45:23 UTC 2024 - ---
...
無事垂れ流され始めた。
ここで別のシェルから ConfigMap
の中身を変更する。
$ kubectl patch cm cm -p "{\"data\":{\"time\":\"$(date)\"}}"
configmap/cm patched
ちょいと読みづらいが、ConfigMap
の値を $(date)
で更新しているだけである。
で、垂れ流されているログに戻って見てみると…
...
Thu Sep 12 18:45:34 UTC 2024 - ---
Thu Sep 12 18:45:35 UTC 2024 - ---
Thu Sep 12 18:45:36 UTC 2024 - ---
Thu Sep 12 18:45:37 UTC 2024 - ---
...
やはり変わってないのだが、そのまま辛抱強く待ち続けていると…
...
Thu Sep 12 18:46:25 UTC 2024 - ---
Thu Sep 12 18:46:26 UTC 2024 - ---
Thu Sep 12 18:46:27 UTC 2024 - Thu Sep 12 18:45:26 UTC 2024
Thu Sep 12 18:46:28 UTC 2024 - Thu Sep 12 18:45:26 UTC 2024
...
変わった!
ConfigMap
の時刻が 18:45:26
で、ログの時刻が 18:46:27
なので、おおよそ 1 分 1 秒かかったということだ。これでも結構幸運な方な気がする。
ここから何回かやってみる。
...
Thu Sep 12 18:48:52 UTC 2024 - Thu Sep 12 18:45:26 UTC 2024
Thu Sep 12 18:48:53 UTC 2024 - Thu Sep 12 18:45:26 UTC 2024
Thu Sep 12 18:48:54 UTC 2024 - Thu Sep 12 18:48:11 UTC 2024
Thu Sep 12 18:48:55 UTC 2024 - Thu Sep 12 18:48:11 UTC 2024
...
今度は 43 秒しかかかってない。なかなか幸運だ。
...
Thu Sep 12 18:49:56 UTC 2024 - Thu Sep 12 18:48:11 UTC 2024
Thu Sep 12 18:49:57 UTC 2024 - Thu Sep 12 18:48:11 UTC 2024
Thu Sep 12 18:49:58 UTC 2024 - Thu Sep 12 18:49:47 UTC 2024
Thu Sep 12 18:49:59 UTC 2024 - Thu Sep 12 18:49:47 UTC 2024
...
11 秒。めっさ幸運だ。
...
Thu Sep 12 18:51:20 UTC 2024 - Thu Sep 12 18:49:47 UTC 2024
Thu Sep 12 18:51:21 UTC 2024 - Thu Sep 12 18:49:47 UTC 2024
Thu Sep 12 18:51:22 UTC 2024 - Thu Sep 12 18:50:02 UTC 2024
Thu Sep 12 18:51:23 UTC 2024 - Thu Sep 12 18:50:02 UTC 2024
...
1 分 20 秒。かなり不運だ。
まとめるとこんな感じ。
試行回数 |
ConfigMap を修正した時刻 |
Pod から見えた時刻 |
かかった時間 |
---|---|---|---|
1 回目 | 18:45:26 | 18:46:27 | 1 分 1 秒 |
2 回目 | 18:48:11 | 18:48:54 | 43 秒 |
3 回目 | 18:49:47 | 18:49:58 | 11 秒 |
4 回目 | 18:50:02 | 18:51:22 | 1 分 20 秒 |
と言う訳で、一番短かったのは 11 秒、一番長かったのは 1 分 20 秒だった。下手をすると 1 分半ぐらいは反映されない、と言う事だ。
一応最後に後始末をしておこう。
$ kubectl delete -f pod.yaml
configmap "cm" deleted
pod "pod" deleted
KubeletConfiguration で調整できそうなんだけど…
さすがにこれはかかりすぎじゃね?と言う事でちょっと調べてみると、KubeletConfiguration
に configMapAndSecretChangeDetectionStrategy
と言う設定がある。名前が「ConfigMap
や Secret
の変更を検知する戦略」なので、これを弄ればなんとかなるんじゃないの?
で、説明を見てみると(テキトー訳)…
configMapAndSecretChangeDetectionStrategy
は、ConfigMap
とSecret
のマネージャの実行モードである。有効な値は:
Get
: kubelet は API server から必要なオブジェクトを直接取得するCache
: kubelet は API server から取得したオブジェクトに TTL キャッシュを使用するWatch
: kubeletはWatch
を使用して、関心のあるオブジェクトの変更を監視するデフォルト: "
Watch
"
何か思ってたのと違う…
そもそもデフォルトが Watch
なら、ConfigMap
や Secret
を修正したら 0 秒とまでは行かなくても速やかに反映されるんじゃないの?
てか、これ ChangeDetection
じゃなくね?いや、Watch
は確かに「変更検知」だけど、それ以外はそもそも「変更検知」じゃないよね?
どういうことなの?
種明かしをすると、そもそも ConfigMap
や Secret
の変更が Pod
に反映される流れは、我々が素朴に想像しているものとは異なるのだ。
反映の流れ
こんな風に考えていないだろうか?
-
ConfigMap
やSecret
が変更される。 - kubelet は何らかの方法で
ConfigMap
やSecret
が変更されたことを検知する。 - kubelet は変更を検知したことをトリガに、変更された
ConfigMap
やSecret
をマウントしているPod
のボリュームの内容を変更する。
残念、そうじゃないんだ。
- kubelet は突然、何らかの理由で
Pod
の状態を最新化しなきゃいけないと言う強迫観念にかられる。 - kubelet は
Pod
の状態を最新化する[2]。ついでに[3]ConfigMap
やSecret
がマウントされていれば、ボリュームの内容を kubelet が最新だと思う内容で最新化する。
この流れで残念なところは「何らかの理由」の中に「マウントされている ConfigMap
や Secret
が変更された」が入っていないと言う事だ。つまり、kubelet には ConfigMap
や Secret
の変更をトリガに Pod
のボリュームを変更する、と言う仕組みは存在しないのだ。
でもくっそ遅いとは言え、実際に Pod
に反映されてるよね?なんでなん?
それは「何らかの理由」の中に「前回の、最新化しなきゃいけないと言う強迫観念にかられた時から、一定時間がたった」、と言うのがあるからだ。
つまり、ConfigMap
や Secret
のボリュームは定期的に最新化されてるだけで、変更をトリガに反映されているわけではないのだ。
一定時間とは?
ここに出てきた一定時間というのは KubeletConfiguration
に設定がある。syncFrequency
というものだ。内容はこんな感じ(テキトー訳)
syncFrequency
は実行中のコンテナと設定を同期する最大期間である。デフォルト: "1m
"
はい、大嘘キタ━━━━(゚∀゚)━━━━!!
最大期間では無い。最大期間はこの 1.5 倍だ。syncFrequency
で指定した値に対して、1~1.5 の乱数をかけた物を次の強迫観念にかられるまでの待ち時間に指定している[4]。
じゃあこの syncFrequency
を短くすればいんじゃね?と思うかもしれない。確かにそれで反映は速くなるだろうが、ノードに存在する全 Pod
の最新化チェックの間隔を短くすることになり、結果としてムダにノードの負荷を上げてしまうことになるのでオススメしない。そもそも Pod
のマニフェストに対する変更は上記の「何らかの理由」に含まれるので、この間隔を短くしなくても Pod
の変更であれば速やかに反映されるのだ。
configMapAndSecretChangeDetectionStrategy とは何だったのか?
上で出てきた configMapAndSecretChangeDetectionStrategy
は「kubelet が最新だと思う内容」の管理方法の設定だ。説明文中の「ConfigMap
と Secret
のマネージャ」と言うのは「kubelet が最新だと思う内容」を管理してるヤツの事を指している。
で、各設定の意味は以下のような感じ。
設定値 | 意味 |
---|---|
Get |
最新かどうかチェックする際に、いちいち kubernetes API の Get で取得して現在の内容と比べる。 絶対最新だけど負荷高い。 |
Cache |
最新かどうかチェックする際に、kubelet 内にキャッシュさてれてる内容と比べる。キャッシュに無い、あるいはキャッシュが古ければ kubernetes API の Get で取得する。 キャッシュの TTL(Time to Live:生存期間)は Node のアノテーション node.alpha.kubernetes.io/ttl の値(単位は秒)で、もしアノテーションが無ければデフォルト値 1 分である。TTL の時間分だけ古い可能性があるが負荷は Get よりは低いのかな?[5]
|
Watch |
最新かどうかチェックする際に、kubelet 内にキャッシュさてれてる内容と比べる。対象の ConfigMap や Secret は kubernetes API の Watch で監視されてるので必ずキャッシュされてるはず。Watch の遅延分だけ古い可能性があるが大した時間じゃないはず。負荷は Get よりは低いと思うが Cache よりは高いのかな?[6]
|
謎は全て解けた!
と言う訳で、もう遅い理由は分かったのではないだろうか。
ConfigMap
や Secret
の変更のタイミングが一定時間の中のどのタイミングで発生したかによって、
- ホントに幸運であれば、ちょうど次の強迫観念にかられる時間だったので、ほぼ瞬時に反映された。
- ホントに不運であれば、ちょうどチェックした直後で、かつ、次の強迫観念にかられるまでに待つ時間が 1.5 倍の 90 秒だったので、反映が 90 秒後になってしまった。
の間になる。
何とかならんもんかね?
反映が遅いとは言え、せいぜい 1 分半程度なので待ってればいんじゃね、と思わないでもないが、場合によってはせめて数秒で反映して欲しい、と言う事もあるだろう。何とかならん?
理由があればいい
状況次第では何とかならん事も無い。
上で、反映のタイミングは「何らかの理由」で kubelet が最新化の強迫観念にかられた場合、と説明した。つまり、この「何らかの理由」を起こしてやればよい。
上にちょろっと書いたように「何らかの理由」の一つに Pod
のマニフェストの変更がある。kubelet ではマニフェストの変更を kubernetes API の Watch で監視しているので、ほぼリアルタイムに気付くことが出来る。
ではマニフェストの何を変更するのか?別にホントに Pod
の内容を変更したいわけではないので、おいそれとやたらに変更するわけにはいかない。
と言う訳で、困った時のアノテーションである。
- アノテーションを変更すると Watch で kubelet に通知が行く。
- kubelet は通知が来たら
Pod
の状態を最新化しなきゃいけないと言う強迫観念にかられる。 - ついでに[7]
ConfigMap
やSecret
のボリュームの状態を確認する。 - 何か内容が新しくなってるので、ボリュームの状態を最新化する。
-
Pod
状態を確認はするものの、特にPod
の状態を変更すべき内容は無い(所詮アノテーションしか変わってない)ので、Pod
の更新は行われない。
完璧な作戦だ。
試してみる
では試してみよう。まず先程と同じく ConfigMap
と Pod
を作ってログを垂れ流す。
$ kubectl create -f pod.yaml
configmap/cm created
pod/pod created
$ kubectl exec -it pod -- sh -c 'while sleep 1; do echo "$(date) - $(cat /cm/time)"; done'
Fri Sep 13 08:26:16 UTC 2024 - ---
Fri Sep 13 08:26:17 UTC 2024 - ---
...
続いて、ここで別のシェルから ConfigMap
の中身を変更するが、今回はその後 Pod
のアノテーションも変更する。
$ kubectl patch cm cm -p "{\"data\":{\"time\":\"$(date)\"}}" && \
kubectl annotate --overwrite pod pod current="$(date)"
configmap/cm patched
pod/pod annotated
見ての通り kubectl annotate
コマンドで current
と言うアノテーションに現在日時を設定しているだけだ。
で、垂れ流されているログに戻って見てみると…
...
Fri Sep 13 08:26:35 UTC 2024 - ---
Fri Sep 13 08:26:36 UTC 2024 - ---
Fri Sep 13 08:26:37 UTC 2024 - Fri Sep 13 08:26:37 UTC 2024
Fri Sep 13 08:26:38 UTC 2024 - Fri Sep 13 08:26:37 UTC 2024
...
なんと一瞬だ。1 秒以内なので遅延が分からない。
もう一回。
...
Fri Sep 13 08:31:32 UTC 2024 - Fri Sep 13 08:26:37 UTC 2024
Fri Sep 13 08:31:33 UTC 2024 - Fri Sep 13 08:26:37 UTC 2024
Fri Sep 13 08:31:34 UTC 2024 - Fri Sep 13 08:31:33 UTC 2024
Fri Sep 13 08:31:35 UTC 2024 - Fri Sep 13 08:31:33 UTC 2024
...
辛うじて 1 秒だ。
圧倒的じゃないか、我が軍は。
ConfigMap
をマウントしている Pod
を把握している前提ではあるが、これなら反映が遅すぎてディスプレイを叩き割ることもないだろう。
今回も一応最後に後始末をしておこう。
$ kubectl delete -f pod.yaml
configmap "cm" deleted
pod "pod" deleted
Pod 直接起動なんて普通は無くね?
いやいや、Pod
を直接起動するなんてことはあんまり無くて、普通は Deployment
とかで勝手に起動されるモンじゃね?その場合はどうすんの?
その場合でも同じだ。同じだが、ちょっとだけ注意が必要だ。
Deployment のアノテーションを弄る
まずは Deployment
を作ろう。マニフェストはこんな感じ。
apiVersion: v1
kind: ConfigMap
metadata:
name: cm
data:
time: "---"
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: deploy
spec:
selector:
matchLabels:
app: busybox
template:
metadata:
labels:
app: busybox
spec:
containers:
- name: busybox
image: busybox
args:
- sleep
- "9999999"
volumeMounts:
- name: cm
mountPath: /cm
readOnly: true
terminationGracePeriodSeconds: 0
volumes:
- name: cm
configMap:
name: cm
何の捻りもないモノだ。これを環境に反映する。
$ kubectl create -f deploy.yaml
configmap/cm created
deployment.apps/deploy created
無事に Deployment
が作られた。Pod
の名前を確認してから前回と同様ログを垂れ流そう。
$ kubectl get pods
NAME READY STATUS RESTARTS AGE
deploy-6c7764d578-bvhk2 1/1 Running 0 48s
$ kubectl exec -it deploy-6c7764d578-bvhk2 -- sh -c 'while sleep 1; do echo "$(date) - $(cat /cm/time)"; done'
Sun Sep 22 07:34:17 UTC 2024 - ---
Sun Sep 22 07:34:18 UTC 2024 - ---
...
垂れ流された。
では、前回と同様別窓で ConfigMap
にパッチを当てた後で annotate
コマンドでアノテーションを付ける。
$ kubectl patch cm cm -p "{\"data\":{\"time\":\"$(date)\"}}" && \
kubectl annotate --overwrite deploy deploy current="$(date)"
configmap/cm patched
deployment.apps/deploy annotated
で、ログを見てみると…
...
Sun Sep 22 07:39:30 UTC 2024 - ---
Sun Sep 22 07:39:31 UTC 2024 - ---
Sun Sep 22 07:39:32 UTC 2024 - Sun Sep 22 07:38:43 UTC 2024
Sun Sep 22 07:39:33 UTC 2024 - Sun Sep 22 07:38:43 UTC 2024
...
残念、49 秒かかってる。
お分かりかと思うが、Deployment
にアノテーション付けただけなので Pod
としては何の変更も発生しておらず、前述の「何らかの理由」にならないのだ。
テンプレートのアノテーションを弄る
Pod
のアノテーションは spec.template.metadata.annotations
なので、ここにパッチを当ててみるか。
$ kubectl patch cm cm -p "{\"data\":{\"time\":\"$(date)\"}}" && \
kubectl patch deploy deploy -p '{"spec":{"template":{"metadata":{"annotations":{"current":"'"$(date)"'"}}}}}'
configmap/cm patched
deployment.apps/deploy patched
ちょっと見づらいが、ちゃんとパッチを当てられた。
そしてログを見てみると…
...
Sun Sep 22 07:51:10 UTC 2024 - Sun Sep 22 07:47:10 UTC 2024
Sun Sep 22 07:51:11 UTC 2024 - Sun Sep 22 07:47:10 UTC 2024
command terminated with exit code 137
おお Pod
!しんでしまうとは なにごとだ!
どうもアノテーションだけでもテンプレートが変わると Pod
を作り直すらしい…
Pod
が作り直されれば当然最新の ConfigMap
の内容が反映されるので目的を達成していると言えなくもないが、死んでしまうのはちょっと…
Pod のアノテーションを直接弄る。
なので、Pod
に直接アノテーションを付けてみる。
Pod
が死んでしまったので再度ログを垂れ流す。
$ kubectl get pods
NAME READY STATUS RESTARTS AGE
deploy-5b7cdfc85c-8dp9w 1/1 Running 0 3m14s
$ kubectl exec -it deploy-5b7cdfc85c-8dp9w -- sh -c 'while sleep 1; do echo "$(date) - $(cat /cm/time)"; done'
別窓でパッチを当ててみる。Pod
へのアノテーションをラベル指定でやるのがミソだ。
$ kubectl patch cm cm -p "{\"data\":{\"time\":\"$(date)\"}}" && \
kubectl annotate --overwrite pod -l app=busybox current="$(date)"
configmap/cm patched
pod/deploy-5b7cdfc85c-8dp9w annotated
そしてログを見てみると…
...
Sun Sep 22 07:56:07 UTC 2024 - Sun Sep 22 07:51:08 UTC 2024
Sun Sep 22 07:56:08 UTC 2024 - Sun Sep 22 07:51:08 UTC 2024
Sun Sep 22 07:56:09 UTC 2024 - Sun Sep 22 07:56:08 UTC 2024
Sun Sep 22 07:56:10 UTC 2024 - Sun Sep 22 07:56:08 UTC 2024
...
ちゃんと 1 秒で切り替わってる!
これで Deployment
も怖いことはない。
最後に忘れずに後始末をしておこう。
$ kubectl delete -f deploy.yaml
configmap "cm" deleted
deployment.apps "deploy" deleted
おまけ(更新の流れ)
念のため Volume 更新の流れをソースで追いかけたので、ここに記録しておく。なお、パッケージ名は鬱陶しいので k8s.io/kubernetes/pkg/
を省略している。
全体の流れ
Pod
の Volume を更新する流れは、以下の 3 つのループで成り立っている。
-
kubelet/Kubelet.syncLoop
ループ本体の主要処理はKubelet.syncLoopIteration
。各種チャネルから指示を待つ。 -
kubelet/volumemanager/populator/desiredStateOfWorldPopulator.Run
ループ本体の処理はdesiredStateOfWorldPopulator.populatorLoop
。100 ms に 1 回ループする。 -
kubelet/volumemanager/reconciler/reconciler.Run
ループ本体の処理はreconciler.reconcileNew
。100 ms に 1 回ループする。
これらはそれぞれ別の goroutine で独立してループしている。
Kubelet.syncLoopIteration
以下のような流れで呼び出されている。
kubelet/Kubelet.syncLoopIteration
-> kubelet/Kubelet.HandlePodUpdates or HandlePodSyncs
-> kubelet/podWorkers.UpdatePod
-> kubelet/podWorkers.podWorkerLoop
-> kubelet/Kubelet.SyncPod
-> kubelet/volumemanager/volumeManager.WaitForAttachAndMount
-> kubelet/volumemanager/populator/desiredStateOfWorldPopulator.ReprocessPod
-> kubelet/volumemanager/populator/desiredStateOfWorldPopulator.markPodProcessingFailed
2 番目の HandlePodUpdates
と HandlePodSyncs
は、Pod
のマニフェストが更新された場合には HandlePodUpdates
が、そうでなくて単に時間が経っただけであれば HandlePodSyncs
が呼ばれる。
最後の markPodProcessingFailed
で desiredStateOfWorldPopulator.pods.processedPods
が false
に設定される。これによって下の desiredStateOfWorldPopulator.populatorLoop
で処理対象として拾われるようになる。
ちなみに、Pod
自体の更新が必要な場合は Kubelet.SyncPod
から volumemanager/volumeManager.WaitForAttachAndMount
の後で呼ばれる kuberuntime/kubeGenericRuntimeManager.SyncPod
で処理される。(多分…)
desiredStateOfWorldPopulator.populatorLoop
以下のような流れで呼び出されている。
kubelet/volumemanager/populator/desiredStateOfWorldPopulator.populatorLoop
-> kubelet/volumemanager/populator/desiredStateOfWorldPopulator.findAndAddNewPods
-> kubelet/volumemanager/populator/desiredStateOfWorldPopulator.processPodVolumes
-> kubelet/volumemanager/populator/desiredStateOfWorldPopulator.podPreviouslyProcessed
-> kubelet/volumemanager/cache/desiredStateOfWorld.AddPodToVolume
-> kubelet/volumemanager/cache/actualStateOfWorld.MarkRemountRequired
desiredStateOfWorldPopulator.podPreviouslyProcessed
の呼び出しで false
が返って来るので desiredStateOfWorld.AddPodToVolume
が呼び出される。
最後の MarkRemountRequired
で mountedPod.remountRequired
が false
に設定される。これによって下の reconciler.reconcileNew
で処理対象として拾われるようになる。
reconciler.reconcileNew
以下のような流れで呼び出されている。
kubelet/volumemanager/reconciler/reconciler.reconcileNew
-> kubelet/volumemanager/reconciler/reconciler.mountOrAttachVolumes
-> kubelet/volumemanager/cache/actualStateOfWorld.PodExistsInVolume
-> kubelet/volumemanager/reconciler/reconciler.mountAttachedVolumes
-> volume/util/operationexecutor/operationExecutor.MountVolume
-> volume/util/operationexecutor/operationGenerator.GenerateMountVolumeFunc
-> volume/util/nestedpendingoperations/nestedPendingOperations.Run
-> volume/util/types/GeneratedOperations.Run
-> volume/util/types/GeneratedOperations.OperationFunc
-> volume/configmap/configMapVolumeMounter.SetUp
-> volume/configmap/configMapVolumeMounter.SetUpAt
-> volume/util/AtomicWriter.Write
actualStateOfWorld.PodExistsInVolume
の呼び出しで err
が remountRequiredError
になるので reconciler.mountAttachedVolumes
が呼び出されて実際に Volume が処理される。
GeneratedOperations.Run
は別の gorountine で起動される。そこから呼ばれる OperationFunc
は operationGenerator.GenerateMountVolumeFunc
で生成された関数(mountVolumeFunc
)を格納している。
おわりに
ConfigMap
/Secret
の反映に 1 分以上かかったりすること、および、アノテーションを使用して反映を早める方法をおわかりいただけただろうか。
この記事によって、反映待ちのイライラが解消され、皆さんのディスプレイが叩き割られなくなれば幸いである。
それでは、良い kubernetes ライフを。
Discussion