Kubernetesの主要コンポーネントのログレベルを動的に変更する

TL; DR

Kubernetesの下記の主要コンポーネントは各コンポーネントのendpointの/debug/flags/vにPUTすることで、ログレベルを動的に更新できます。つまり、稼働中のKubernetesのコンポーネントのログレベルが再起動/Manifestの変更なしで動的にログレベルが変更できます！ただし、各コンポーネントともにprofilingもしくはdebugging-handlersを有効にしている必要があります。

# loglevelを N に変更 ※別途認証は必要です。下記参照。
$ curl -XPUT -d 'N' <endpoint>/debug/flags/v 

• kube-apiserver
• kube-scheduler
• kubelet
• kube-proxy
• kube-controller-manager (v1.23で対応予定。#104571)

各コンポーネントの対応状況 (v1.22時点)

|コンポーネント|デフォルトポート|認証認可|/debug/flags/vを有効にするために必要な設定|
|---|---|---|---|---|
|kube-apiserver|6443|あり|--profiling (Default:true)|
|kube-scheduler|10259|あり|enableProfiling: true (Default: true)|
|kubelet| 10250 |あり|enableDebuggingHandlers: true (Default: true)|
|kube-proxy|10249|なし|enableProfiling: true (Default: false)
default無効なので有効にしてデプロイしておく必要あり|
|kube-controller-manager
v1.23で対応予定
(see #104571)|10257|あり|--profiling　(Default: true)|

使い所

• プロダクション環境での解析等で稼働中(再起動したくない)のプロセスのログレベルを上げたい
• 開発や検証時にログレベルを変えながらログ出力の挙動をチェックしたいけど、ログレベルのオプション変更してre-applyめんどくさい
• etc.

やってみる

準備

kindでやります。 v1.22.0でclusterを作成します。

$ kind create cluster --image kindest/node:v1.22.0
Creating cluster "kind" ...
 ✓ Ensuring node image (kindest/node:v1.22.0) 🖼
...
Thanks for using kind! 😊

必要な権限

認証認可ありのエンドポイントにアクセスするためには権限の付与が必要です。

基本的には nonResourceURLs を使って put /debug/flags/v の権限を与えればよいのですが、kubeletだけなぜかresource=nodes/proxy, verb=updateの権限チェックになってしまうのでそれも与えておきます。

ここでは便宜的に default/default Service Accountに権限を与えています。

$ cat << EOT | kubectl apply -f -
apiVersion: rbac.authorization.k8s.io/v1
kind: ClusterRole
metadata:
  name: edit-debug-flags-v
rules:
  # kubeletだけこの権限が必要
- apiGroups:
  - ""
  resources:
  - nodes/proxy
  verbs:
  - update
  # 他のcomponentはこれでOK
- nonResourceURLs:
  - /debug/flags/v
  verbs:
  - put
---
apiVersion: rbac.authorization.k8s.io/v1
kind: ClusterRoleBinding
metadata:
  name: edit-debug-flags-v
roleRef:
  apiGroup: rbac.authorization.k8s.io
  kind: ClusterRole
  name: edit-debug-flags-v
subjects:
- kind: ServiceAccount
  name: default
  namespace: default
EOT
clusterrole.rbac.authorization.k8s.io/edit-debug-flags-v created
clusterrolebinding.rbac.authorization.k8s.io/edit-debug-flags-v created

default/default Service Account権限でアクセスするためにTOKENを取得しておきます。

$ TOKEN=$(kubectl get secrets -o jsonpath="{.items[?(@.metadata.annotations['kubernetes\.io/service-account\.name']=='default')].data.token}"|base64 --decode)

kube-apiserver

さて準備完了です。まずはkube-apiserverから試してみましょう。apiserverは普通にクラスタのエンドポイントにアクセスすれば良いですね。

$ APISERVER=$(kubectl config view -o jsonpath="{.clusters[?(@.name==\"kind-kind\")].cluster.server}")
$ curl -s -X PUT -d '5' $APISERVER/debug/flags/v --header "Authorization: Bearer $TOKEN"  -k
successfully set klog.logging.verbosity to 5

kube-scheduler

schedulerはpodとして動いているのでport-forwardして試します。

$ kubectl -n kube-system port-forward kube-scheduler-kind-control-plane 10259:10259
Forwarding from 127.0.0.1:10259 -> 10259
Forwarding from [::1]:10259 -> 10259

$ curl -s -X PUT -d '5' https://localhost:10259/debug/flags/v --header "Authorization: Bearer $TOKEN"  -k
successfully set klog.logging.verbosity to 5

kubelet

kubeletはpodで動いていないので、直接nodeのdocker containerに入ってアクセスしてみます。

$ docker exec kind-control-plane \
  curl -s -X PUT -d '5' https://localhost:10250/debug/flags/v --header "Authorization: Bearer $TOKEN"  -k
successfully set klog.logging.verbosity to 5

kube-proxy

kube-proxyはdefaultではprofilingが有効ではないので、有効にしておく必要があります。

$ kubectl -n kube-system get configmap kube-proxy -o yaml  | \
  sed -e 's/enableProfiling: false/enableProfiling: true/' | kubectl apply -f -
configmap/kube-proxy configured
$ kubectl -n kube-system rollout restart daemonset/kube-proxy
daemonset.apps/kube-proxy restarted

schedulerと同様port-forwardして試します。

$ kubectl port-forward -n kube-system $(k get pod -n kube-system -l k8s-app=kube-proxy -o jsonpath='{.items[0].metadata.name}') 10249:10249
Forwarding from 127.0.0.1:10249 -> 10249
Forwarding from [::1]:10249 -> 10249

# 認証なし
$ curl -s -XPUT -d '5' http://localhost:10249/debug/flags/v
successfully set klog.logging.verbosity to 5

どう実装されているか？

ここではkube-apiserverの場合を見てみましょう。該当部分はstaging/src/k8s.io/apiserver/pkg/server/config.goです。

import(
...
    "k8s.io/apiserver/pkg/server/routes"
    "k8s.io/component-base/logs"
...
    if c.EnableProfiling {
...
        routes.DebugFlags{}.Install(                       // "/debug/flags"というbasepathにhandlerをinstallするヘルパ
            s.Handler.NonGoRestfulMux, 
            "v",                                           // "/debug/flags/v" にinstall
            routes.StringFlagPutHandler(logs.GlogSetter),  // PUTのbodyをlogs.GlogSetterに渡すhandler
                                                           //   logs.GlogSetterはglogのloglevelを更新する関数
                                                           //   この関数は -v flagで指定する値を書き換えます
        )
    }

各コンポーネントの実装はこちらをご覧ください

FAQ

Structured Loggingの対応が進んでいるけど対応に違いはあるのか？

現在、Kubernetes upstreamではStructured Loggingへの対応が絶賛進行中です。KEPにかかれている通り、以前のklogからの移行容易性にも配慮された設計になっているため、以前のlogも、Structured Logも同じklog.V(n)というインターフェースでロギングが行われるため、 PUT /debug/flags/v によるログレベルの動的変更は有効です。 --logging-format=text,json も影響は受けません(どちらでもOK)。

// Classic Logging (non-structured)
klog.V(n).Infof("msg: %d", i)
// Structured Logging
klog.V(n).InfoS("msg", "i", i)

ログレベルっていくつにするとどういうログがでるのかイマイチよくわからない

Kubernetesのコンポーネントのログ規約は kubernetes/community repositoryにまとめられています。Kubernetesの主要コンポーネントはこの規約に沿って実装されていることが期待されます。

• klog.V(0): Generally useful for this to ALWAYS be visible to an operation
• klog.V(1): A reasonable default log level if you don't want verbosity
• klog.V(2): Useful steady state information about the service and important log messages that may correlate to significant changes in the system. This is the recommended default log level for most systems
• klog.V(3): Extended information about changes
• klog.V(4): Debug level verbosity
• klog.V(5): Trace level verbosity

As per the comments, the practical default level is V(2). Developers and QE environments may wish to run at V(3) or V(4)

最後に

lwkd.info経由で#98306のPRを見た時に初めて知ったのですがこんな機能があったんですね。驚きました。めちゃくちゃ便利だと思います。

-vが動的に変更できるとなると、自然と欲が出て-vmoduleも変更したくなっちゃいますね。ただ、現時点で#99270にあるようにJson Loggingで -vmodule がサポートされていない(その他のオプションもまだ諸々サポートが足りていない模様)ため、もう少し先になるかもしれませんね。

debug機能とはいえ全くのundocumentedな機能っぽいのでもっと多くの人に周知されると良いと思います。どこかにdocumentされていたら是非教えて下さい🙇‍♂️

また、この手法自体とても有用なので、自分で開発するcontrollerとかでも参考にするととても便利になりそうですね！ 🎉