🐔

ConfigMap/Secret の修正が Pod に反映されるまでには 1 分以上かかる

2024/09/24に公開

はじめに

kubernetes の ConfigMap/SecretPod に Volume としてマウントしている場合、ConfigMap/Secret を修正すると Pod の Volume に自動的に反映される事は良く知られている。

しかし、その反映に 1 分以上かかる事はあまり知られていないのではないだろうか?[1]

すみません、ちょっとだけ(?)盛りました。必ず 1 分以上かかるわけでは無く、運が良ければ 1 分切る事もある。が、運が悪いと 1 分半かかることもある。

と言うわけで、まずは実際反映に 1 分以上かかったりすることを確認するちょっとした実験を行い、その後遅い理由を解説する。また、併せて簡単な対処方法も紹介したいと思う。

ホントにそんなに遅いの?

遅いことを確認するために以下のようなマニフェストを用意する。

pod.yaml
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 で調整できそうなんだけど…

さすがにこれはかかりすぎじゃね?と言う事でちょっと調べてみると、KubeletConfigurationconfigMapAndSecretChangeDetectionStrategy と言う設定がある。名前が「ConfigMapSecret の変更を検知する戦略」なので、これを弄ればなんとかなるんじゃないの?

で、説明を見てみると(テキトー訳)…

configMapAndSecretChangeDetectionStrategy は、ConfigMapSecret のマネージャの実行モードである。有効な値は:

  • Get: kubelet は API server から必要なオブジェクトを直接取得する
  • Cache: kubelet は API server から取得したオブジェクトに TTL キャッシュを使用する
  • Watch: kubeletは Watch を使用して、関心のあるオブジェクトの変更を監視する

デフォルト: "Watch"

何か思ってたのと違う…

そもそもデフォルトが Watch なら、ConfigMapSecret を修正したら 0 秒とまでは行かなくても速やかに反映されるんじゃないの?

てか、これ ChangeDetection じゃなくね?いや、Watch は確かに「変更検知」だけど、それ以外はそもそも「変更検知」じゃないよね?

どういうことなの?

種明かしをすると、そもそも ConfigMapSecret の変更が Pod に反映される流れは、我々が素朴に想像しているものとは異なるのだ。

反映の流れ

こんな風に考えていないだろうか?

  1. ConfigMapSecret が変更される。
  2. kubelet は何らかの方法で ConfigMapSecret が変更されたことを検知する。
  3. kubelet は変更を検知したことをトリガに、変更された ConfigMapSecret をマウントしている Pod のボリュームの内容を変更する。

残念、そうじゃないんだ。

  1. kubelet は突然、何らかの理由Pod の状態を最新化しなきゃいけないと言う強迫観念にかられる
  2. kubelet は Pod の状態を最新化する[2]。ついでに[3] ConfigMapSecret がマウントされていれば、ボリュームの内容を kubelet が最新だと思う内容で最新化する。

この流れで残念なところは「何らかの理由」の中に「マウントされている ConfigMapSecret が変更された」が入っていないと言う事だ。つまり、kubelet には ConfigMapSecret の変更をトリガに Pod のボリュームを変更する、と言う仕組みは存在しないのだ。

でもくっそ遅いとは言え、実際に Pod に反映されてるよね?なんでなん?

それは「何らかの理由」の中に「前回の、最新化しなきゃいけないと言う強迫観念にかられた時から、一定時間がたった」、と言うのがあるからだ。

つまり、ConfigMapSecret のボリュームは定期的に最新化されてるだけで、変更をトリガに反映されているわけではないのだ。

一定時間とは?

ここに出てきた一定時間というのは KubeletConfiguration に設定がある。syncFrequency というものだ。内容はこんな感じ(テキトー訳)

syncFrequency は実行中のコンテナと設定を同期する最大期間である。デフォルト: "1m"

はい、大嘘キタ━━━━(゚∀゚)━━━━!!

最大期間では無い。最大期間はこの 1.5 倍だ。syncFrequency で指定した値に対して、1~1.5 の乱数をかけた物を次の強迫観念にかられるまでの待ち時間に指定している[4]

じゃあこの syncFrequency を短くすればいんじゃね?と思うかもしれない。確かにそれで反映は速くなるだろうが、ノードに存在する全 Pod の最新化チェックの間隔を短くすることになり、結果としてムダにノードの負荷を上げてしまうことになるのでオススメしない。そもそも Pod のマニフェストに対する変更は上記の「何らかの理由」に含まれるので、この間隔を短くしなくても Pod の変更であれば速やかに反映されるのだ。

configMapAndSecretChangeDetectionStrategy とは何だったのか?

上で出てきた configMapAndSecretChangeDetectionStrategy は「kubelet が最新だと思う内容」の管理方法の設定だ。説明文中の「ConfigMapSecret のマネージャ」と言うのは「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 内にキャッシュさてれてる内容と比べる。対象の ConfigMapSecret は kubernetes API の Watch で監視されてるので必ずキャッシュされてるはず。
Watch の遅延分だけ古い可能性があるが大した時間じゃないはず。負荷は Get よりは低いと思うが Cache よりは高いのかな?[6]

謎は全て解けた!

と言う訳で、もう遅い理由は分かったのではないだろうか。

ConfigMapSecret の変更のタイミングが一定時間の中のどのタイミングで発生したかによって、

  • ホントに幸運であれば、ちょうど次の強迫観念にかられる時間だったので、ほぼ瞬時に反映された。
  • ホントに不運であれば、ちょうどチェックした直後で、かつ、次の強迫観念にかられるまでに待つ時間が 1.5 倍の 90 秒だったので、反映が 90 秒後になってしまった。

の間になる。

何とかならんもんかね?

反映が遅いとは言え、せいぜい 1 分半程度なので待ってればいんじゃね、と思わないでもないが、場合によってはせめて数秒で反映して欲しい、と言う事もあるだろう。何とかならん?

理由があればいい

状況次第では何とかならん事も無い。

上で、反映のタイミングは「何らかの理由」で kubelet が最新化の強迫観念にかられた場合、と説明した。つまり、この「何らかの理由」を起こしてやればよい。

上にちょろっと書いたように「何らかの理由」の一つに Pod のマニフェストの変更がある。kubelet ではマニフェストの変更を kubernetes API の Watch で監視しているので、ほぼリアルタイムに気付くことが出来る。

ではマニフェストの何を変更するのか?別にホントに Pod の内容を変更したいわけではないので、おいそれとやたらに変更するわけにはいかない。

と言う訳で、困った時のアノテーションである。

  1. アノテーションを変更すると Watch で kubelet に通知が行く。
  2. kubelet は通知が来たら Pod の状態を最新化しなきゃいけないと言う強迫観念にかられる。
  3. ついでに[7] ConfigMapSecret のボリュームの状態を確認する。
  4. 何か内容が新しくなってるので、ボリュームの状態を最新化する。
  5. Pod 状態を確認はするものの、特に Pod の状態を変更すべき内容は無い(所詮アノテーションしか変わってない)ので、Pod の更新は行われない。

完璧な作戦だ。

試してみる

では試してみよう。まず先程と同じく ConfigMapPod を作ってログを垂れ流す。

$ 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 を作ろう。マニフェストはこんな感じ。

deploy.yaml
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 つのループで成り立っている。

  1. kubelet/Kubelet.syncLoop
    ループ本体の主要処理は Kubelet.syncLoopIteration。各種チャネルから指示を待つ。
  2. kubelet/volumemanager/populator/desiredStateOfWorldPopulator.Run
    ループ本体の処理は desiredStateOfWorldPopulator.populatorLoop。100 ms に 1 回ループする。
  3. 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 番目の HandlePodUpdatesHandlePodSyncs は、Pod のマニフェストが更新された場合には HandlePodUpdates が、そうでなくて単に時間が経っただけであれば HandlePodSyncs が呼ばれる。

最後の markPodProcessingFaileddesiredStateOfWorldPopulator.pods.processedPodsfalse に設定される。これによって下の 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 が呼び出される。

最後の MarkRemountRequiredmountedPod.remountRequiredfalse に設定される。これによって下の 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 の呼び出しで errremountRequiredError になるので reconciler.mountAttachedVolumes が呼び出されて実際に Volume が処理される。

GeneratedOperations.Run は別の gorountine で起動される。そこから呼ばれる OperationFuncoperationGenerator.GenerateMountVolumeFunc で生成された関数(mountVolumeFunc)を格納している。

おわりに

ConfigMap/Secret の反映に 1 分以上かかったりすること、および、アノテーションを使用して反映を早める方法をおわかりいただけただろうか。

この記事によって、反映待ちのイライラが解消され、皆さんのディスプレイが叩き割られなくなれば幸いである。

それでは、良い kubernetes ライフを。

脚注
  1. オレの思い込みの可能性もある ↩︎

  2. この際、場合によって Pod が再起動されたりされなかったりする ↩︎

  3. 個人の感想です ↩︎

  4. ソースはここ ↩︎

  5. TTL 1 分だと毎サイクル毎に読む気がするが、複数 Pod が同一 ConfigMap をマウントしてる時とかには効果がありそう? ↩︎

  6. Watch の負荷がイマイチ分かってない ↩︎

  7. しつこいようだが個人の感想です ↩︎

Discussion