はじめに(What’s New の内容含む)
ここでは、Kubernetes 1.19 の CHANGELOG から Metrics の変更と SIG Instrumentation の取り組みについてまとめています。
Kubernetes v1.19 では SIG Instrumentation の大きなテーマとして、構造化ロギング(Structured logging)が導入されました。
構造化ロギングは KEP の1602-structured-logging kubernetes/enhancements で提案されています。
原文の What's New では次のように紹介されています。
ログメッセージの構造と Kubernetes オブジェクトへの参照を標準化しました。
構造化されたログにより、ログのパース、処理、保存、検索、そして分析が簡単になりました。klog ライブラリの新しいメソッドを利用することでログメッセージの構造化を強制できます。
この KEP により klog には 構造化されたログを出力するInfoS や ErrorS、Kubernetes オブジェクトを展開する KObj、KRef などのメソッドが追加され、ライブラリは v2 に更新されました。
そしてこちらの移行計画をもとに、ログ出力の割合が多い重要なログに焦点を絞りメソッドの置き換えが進められています。Tracking Issue はこちらです。
これらのメソッドを使った出力イメージは次の通りとなり、これだけでは ndjson のような json 形式で出力されません。
> klog.V(2).InfoS("Pod status updated", "pod", klog.KObj(p), "status", status.Phase)
# key=value の形式で出力される
I0903 23:43:18.302818 3894 kubelet_getters.go:176] "Pod status updated" pod="kube-system/etcd-minikube" status=Running
ndjson の形式で出力するには component-base に実装された --logging-format
のオプションを使用し、json
を指定します。
実際にどのようなログが出力されるか minikube を使って確認してみます。
2020-09-03 時点でリリースされている minikube v1.12.3 では extra-config の内容が反映されなかったため、master ブランチの minikube をビルドし利用します。
kube-controller-manager と kube-scheduler の引数に --logging-format
オプションを追加するため、次のような extra-config を付けて minikube を起動します。
# macOS で実行しています
$ minikube start \
--kubernetes-version 1.19.0 \
--vm-driver hyperkit \
--extra-config 'controller-manager.logging-format=json' \
--extra-config 'scheduler.logging-format=json'
--extra-config 'kubelet.logging-format=json'
--extra-config 'controller-manager.v=6' \
--extra-config 'scheduler.v=6'
--extra-config 'kubelet.v=6'
😄 minikube v1.12.3 on Darwin 10.15.6
✨ Using the hyperkit driver based on user configuration
👍 Starting control plane node minikube in cluster minikube
🔥 Creating hyperkit VM (CPUs=2, Memory=4000MB, Disk=20000MB) ...
🎉 minikube 1.13.0 is available! Download it: https://github.com/kubernetes/minikube/releases/tag/v1.13.0
💡 To disable this notice, run: 'minikube config set WantUpdateNotification false'
🐳 Preparing Kubernetes v1.19.0 on Docker 19.03.12 ...
▪ controller-manager.logging-format=json
▪ scheduler.logging-format=json
▪ kubelet.logging-format=json
▪ controller-manager.v=6
▪ scheduler.v=6
▪ kubelet.v=6
🔎 Verifying Kubernetes components...
🌟 Enabled addons: default-storageclass, storage-provisioner
🏄 Done! kubectl is now configured to use "minikube"
このオプションで minikube の起動に成功すると次のようなフォーマットでログが出力されます。
kubelet のログ(一部抜粋)
$ minikube ssh 'sudo journalctl -xu kubelet'
...
I0904 00:17:45.010069 2773 flags.go:59] FLAG: --add-dir-header="false"
I0904 00:17:45.010111 2773 flags.go:59] FLAG: --address="0.0.0.0"
I0904 00:17:45.010117 2773 flags.go:59] FLAG: --allowed-unsafe-sysctls="[]"
I0904 00:17:45.010124 2773 flags.go:59] FLAG: --alsologtostderr="false"
I0904 00:17:45.010127 2773 flags.go:59] FLAG: --anonymous-auth="true"
I0904 00:17:45.010132 2773 flags.go:59] FLAG: --application-metrics-count-limit="100"
...
{"ts":1599178665518.6204,"msg":"Version: v1.19.0\n","v":0}
{"ts":1599178665518.9753,"msg":"feature gates: &{map[]}\n","v":1}
{"ts":1599178665521.7664,"msg":"feature gates: &{map[]}\n","v":1}
{"ts":1599178665521.9856,"msg":"Client rotation is on, will bootstrap in background\n","v":0}
{"ts":1599178665523.6094,"msg":"Config loaded from file: /etc/kubernetes/kubelet.conf\n","v":6}
{"ts":1599178665525.3655,"msg":"Config loaded from file: /etc/kubernetes/kubelet.conf\n","v":6}
{"ts":1599178665525.5464,"msg":"Current kubeconfig file contents are still valid, no bootstrap necessary\n","v":2}
# このログだと pod や status のキーが指定されているがまだ含まれてない?
# > klog.V(2).InfoS("Pod status updated", "pod", klog.KObj(p), "status", status.Phase)
{"ts":1599178743113.197,"msg":"Pod status updated","v":2}
{"ts":1599178743113.3542,"msg":"Pod status updated","v":2}
...
kube-controller-manager のログ(一部抜粋)
$ kubectl logs kube-scheduler-minikube
I0902 07:48:26.091216 1 registry.go:173] Registering SelectorSpread plugin
I0902 07:48:26.091310 1 registry.go:173] Registering SelectorSpread plugin
I0902 07:48:26.689893 1 serving.go:331] Generated self-signed cert in-memory
{"ts":1599032912174.6284,"msg":"Registering SelectorSpread plugin\n","v":0}
{"ts":1599032912174.6775,"msg":"Registering SelectorSpread plugin\n","v":0}
{"ts":1599032912177.0889,"msg":"Authorization is disabled\n","v":0}
{"ts":1599032912177.1306,"msg":"Authentication is disabled\n","v":0}
{"ts":1599032912177.163,"msg":"Serving healthz insecurely on [::]:10251\n","v":0}
{"ts":1599032912180.8513,"msg":"Starting client-ca::kube-system::extension-apiserver-authentication::client-ca-file\n","v":0}
{"ts":1599032912181.0864,"msg":"Waiting for caches to sync for client-ca::kube-system::extension-apiserver-authentication::client-ca-file\n","v":0}
{"ts":1599032912181.209,"msg":"Serving securely on [::]:10259\n","v":0}
kube-scheduler のログ(一部抜粋)
$ kubectl logs kube-controller-manager-minikube
I0902 07:48:26.685344 1 serving.go:331] Generated self-signed cert in-memory
{"ts":1599032906964.9773,"msg":"Version: v1.19.0\n","v":0}
{"ts":1599032906966.5215,"msg":"Serving securely on [::]:10257\n","v":0}
{"ts":1599032906967.1287,"msg":"Serving insecurely on [::]:10252\n","v":0}
{"ts":1599032906967.9482,"msg":"Starting request-header::/var/lib/minikube/certs/front-proxy-ca.crt\n","v":0}
{"ts":1599032906968.5168,"msg":"Starting DynamicServingCertificateController\n","v":0}
{"ts":1599032906968.684,"msg":"Starting client-ca-bundle::/var/lib/minikube/certs/ca.crt\n","v":0}
{"ts":1599032914511.9033,"msg":"Waiting for caches to sync for tokens\n","v":0}
出力されたログは KEP にて定義された次のキーが含まれた構造体になっており、キーの追加もできるようになっています。
- ts: タイムスタンプ as UNIX time (required, float)
- v: verbosity (required, int, default 0)
- err: error string (optional, string)
- msg: message (required, string)
{
"ts": 1580306777.04728,
"v": 4,
"msg": "Pod status updated",
"pod":{
"name": "nginx-1",
"namespace": "default"
},
"status": "ready"
}
現状では全てのコンポーネントやログが構造化されているわけではありませんが、フィードバックを反映しながら性能やスキームの改善がされていく見込みです。
この取り組みにより、今まで Fluentd などの正規表現でパースしていた処理がシンプルになり、分析したかったことに注力できそうです。
それでは恒例の Metrics Changes
について説明していきます。
ただし今回の ChangeLog から Metrics Changes
の項目は削除されたため、私の方で Changes by Kind
からメトリクスの変更に関連するものを抜粋した内容を Metrics Changes
としてまとめました。
メトリクスの変更(Metrics Changes)
変更
kube-scheduler
-
profile
ラベルが追加されました(#92268, @alculquicondor)scheduler_framework_extension_point_duration_seconds
-
profile
ラベルが追加され、scheduler ごとにメトリクスが記録されるようになりました(#92202, @alculquicondor)scheduler_schedule_attempts_total
-
result
とprofile
ラベルが追加され、スケジュールできなかった試行回数とエラー試行の時間が記録されるようになりました(#92202, @alculquicondor)。scheduler_e2e_scheduling_duration_seconds
- 次のメトリクスがリネームされました(#91448, @RainbowMango)
-
scheduler_total_preemption_attempts
->scheduler_preemption_attempts_total
-
kubelet
- 次のメトリクスがリネームされました(#92407, @RainbowMango)
-
kubelet_running_container_count
->kubelet_running_containers
-
kubelet_running_pod_count
->kubelet_running_pods
-
-
/metrics/resource
エンドポイントから取得できる次のメトリクスがリネームされました(#89540, @dashpole)-
node_cpu_usage_seconds
->node_cpu_usage_seconds_total
-
container_cpu_usage_seconds
->container_cpu_usage_seconds_total
-
kube-aggregator
- 次のメトリクスがリネームされました(#88156, @p0lyn0mial)
-
aggregator_unavailable_apiservice_count
->aggregator_unavailable_apiservice_total
-
- レート制限のメトリス Prometheus のベストプラクティスに従いリネームしました(#77979, @s-urbaniak)
-
APIServiceOpenAPIAggregationControllerQueue1
->open_api_aggregation_controller
-
その他
-
CoreDNS v1.17 へのアップグレードに伴い、メトリクス名を Prometheus のベストプラクティスに合わせるため、次のメトリクスがリネームされました。この変更は下位互換がないためアップグレードする前に利用箇所の修正が必要です(#92651, @rajansandeep)。
-
coredns_request_block_count_total
->coredns_dns_blocked_requests_total
-
coredns_request_allow_count_total
->coredns_dns_allowed_requests_total
-
coredns_dns_acl_request_block_count_total
->coredns_acl_blocked_requests_total
-
coredns_dns_acl_request_allow_count_total
->coredns_acl_allowed_requests_total
-
coredns_autopath_success_count_total
->coredns_autopath_success_total
-
coredns_forward_request_count_total
->coredns_forward_requests_total
-
coredns_forward_response_rcode_count_total
->coredns_forward_responses_total
-
coredns_forward_healthcheck_failure_count_total
->coredns_forward_healthcheck_failures_total
-
coredns_forward_healthcheck_broken_count_total
->coredns_forward_healthcheck_broken_total
-
coredns_forward_max_concurrent_reject_count_total
->coredns_forward_max_concurrent_rejects_total
-
coredns_grpc_request_count_total
->coredns_grpc_requests_total
-
coredns_grpc_response_rcode_count_total
->coredns_grpc_responses_total
-
coredns_panic_count_total
->coredns_panics_total
-
coredns_dns_request_count_total
->coredns_dns_requests_total
-
coredns_dns_request_do_count_total
->coredns_dns_do_requests_total
-
coredns_dns_response_rcode_count_total
->coredns_dns_responses_total
-
coredns_reload_failed_count_total
->coredns_reload_failed_total
-
coredns_cache_size
->coredns_cache_entries
-
coredns_dns_request_type_count_total
- このメトリクスは削除され、既存のメトリクスである
coredns_dns_requests_total
に統合されました
- このメトリクスは削除され、既存のメトリクスである
-
-
kubernetes_build_info
メトリクスのラベル名がcamelCase
からsnake_case
になりました。この変更は kube-apiserver、kube-scheduler、kube-proxy、kube-controller-manager のコンポーネントに適用されています(#91805, @RainbowMango)。-
gitVersion
->git_version
-
gitCommit
->git_commit
-
gitTreeState
->git_tree_state
-
buildDate
->build_date
-
goVersion
->go_version
-
追加
kube-apiserver
-
非推奨バージョンの API にリクエストすると、API レスポンスに警告ヘッダーが含まれ、非推奨 API の利用がわかるメトリクスへ記録されるようになりました。このメトリクスは Gauge となっており、非推奨 API が利用されると値として 1 が記録されます(#73032, @liggitt)
apiserver_requested_deprecated_apis
- クラスタ運用者としては便利な機能ですね!
# HELP apiserver_requested_deprecated_apis [ALPHA] Gauge of deprecated APIs that have been requested, broken out by API group, version, resource, subresource, and removed_release. # TYPE apiserver_requested_deprecated_apis gauge apiserver_requested_deprecated_apis{group="extensions",removed_release="1.22",resource="ingresses",subresource="",version="v1beta1"} 1
- api-server でキューに入ってるリクエスト数を記録するメトリクスが追加されました(#91177, @MikeSpreitzer)
apiserver_current_inqueue_requests
- FeatureGate=APIPriorityAndFairness とした際に役立つメトリクスが追加されました。詳細はこちらのドキュメントを参照してください(#91177, @MikeSpreitzer)。
apiserver_flowcontrol_priority_level_request_count_samples
apiserver_flowcontrol_priority_level_request_count_watermarks
apiserver_flowcontrol_read_vs_write_request_count_samples
apiserver_flowcontrol_read_vs_write_request_count_watermarks
kubelet
- クライアント証明書をローテーションするように設定された kubelet が、証明書の有効期限までの残りの秒数を記録するメトリクスが追加されました(#91148, @liggitt)。
kubelet_certificate_manager_client_ttl_seconds
kube-proxy
- kube-proxy の変更を適用するため、キューに入れられた最後の時間を記録するメトリクスが追加されました(#90175, @squeed)
kubeproxy_sync_proxy_rules_last_queued_timestamp_seconds
kube-controller-manager
- ローカル nodeipam のレンジアロケーターをリファクタリングし、割り当てられた CIDR を格納するために使用する cidrset を次のメトリクスで記録するようになりました(#90288, @aojea)
node_ipam_controller_cidrset_cidrs_allocations_total
node_ipam_controller_cidrset_cidrs_releases_total
node_ipam_controller_cidrset_usage_cidrs
node_ipam_controller_cidrset_allocation_tries_per_request
削除
kubelet
-
#91148 の対応により、
kubelet_certificate_manager_client_ttl_seconds
が追加されたので次のメトリクスは削除されましたkubelet_certificate_manager_client_expiration_seconds
種類別の変更点(Changes by Kind)
機能追加(Feature)
component-base
-
--logging-format
オプションが追加されました。デフォルト値はtext
となり以前と同じフォーマットになります。json
を指定すると ndjson のようなフォーマットでログが出力されます(#89683, @yuzhiquan)。
kubelet
- 構造化ロギングをサポートするために
--logging-format
オプションが追加されました(#91532, @afrouzMashaykhi)
kube-controller-manager
kube-scheduler
api-server
- 非推奨の API バージョンへリクエストされると監査イベント に
"k8s.io/deprecated": "true"
の監査アノテーションが含まれるようになりました。削除対象となるリリースが特定された場合、監査イベントには"k8s.io/removal-release": "<majorVersion>.<minorVersion>"
の監査アノテーションも追加されます(#92842, @liggitt)。
-
api-server のログのトレース出力がより整理され、包括的になりました。トレースはネストされ長時間実行されていない全てのリクエストエンドポイントについて、フィルターチェイン全体が計測されます。 例では認証チェックが含まれています(#88936, @jpbetz)。
Trace[1374095871]: "HTTP Request" method:GET,url:/api/v1/namespaces/kube-system/resourcequotas,user-agent:kube-apiserver/v1.19.0 (linux/amd64) kubernetes/482c37a,client:::1 (02-Jun-2020 10:38:00.615) (total time: 3201ms): Trace[1374095871]: ---"Authenticate check done" 1000ms (10:38:00.615) Trace[1374095871]: ---"Authorize check done" 1000ms (10:38:00.616) Trace[1374095871]: ["List" url:/api/v1/namespaces/kube-system/resourcequotas,user-agent:kube-apiserver/v1.19.0 (linux/amd64) kubernetes/482c37a,client:::1 1200ms (10:38:00.616) Trace[1374095871]: ["List etcd3" key:/resourcequotas/kube-system,resourceVersion:,limit:0,continue: 1200ms (10:38:00.616)]] Trace[1374095871]: [3.201532894s] [3.201532894s] END
将来的にはこのようなログも構造化される予定です。
不具合の修正(Bug or Regression)
- cadvisor を v0.37.0 にアップグレードし、次の内容を修正しました(#92919, @dashpole)
- コンテナイメージのファイルシステムの検出を修正
- devicemapper デバイスのディスクメトリクスを修正
- Linux カーネル 5.0 以上 で発生する OOM Kill の検出を修正
所感
今回も Stability Level が ALPHA なメトリクスですが、ガンガンリネームされてます!
特に CoreDNS を監視されている Application Developer はご注意ください。
構造化ロギングは Fluentd の設定がシンプルになり、負荷の軽減にも繋がるので導入の検討をしていきたいです。
ただ今までログに出力されていたソースコードのファイル名と行数は調査時に助かっていたので、復活してもらえると嬉しいです。ログの容量のことを考えるとオプションの扱いが妥当でしょうか。