Nodeのマシンタイプをケチって覚えたdebugging kubernetes
GKE上に立ち上げている自前のkubernetesのClusterは、一番安いという理由だけでg1-small*1を使い続けていた。しかし、いざ複数のPodを追加したりし始めると、Nodeのリソース不足が原因で色々ハマったので、そこで覚えた細かいデバッグ手法を例のごとく逆引き辞書っぽくメモしていく。ついでにリソースとは無関係なkubernetesのネットワーク関連でハマったこともメモ。すでに使い込んでいる人にとって目新しいものはない気がする。
以下、例となっているPodのデプロイは、状況を再現しやすいという理由だけで手前味噌のprometheus実験レポジトリを元に行っているのでprometheusが云々と多少言っているが、基本的にPodの内容がなんであれ、リソースが足りなくなった場合に何が起こって、kubectl
で何を確かめれば良さそうか、という点を中心に書き下していく。
Check kubectl describe nodes
kubectl describe nodes
でNodeのリソース使用状況を見ることができる。g1-smallのNode一つだけでClusterを組んでいると、何もしていなくてもkube-system
にリソースの75%
を以上を食われていることがわかる。ここから自分のPodを適宜追加していくことになるので、早晩リソースが枯渇する。実に世知辛い。
$ kubectl describe nodes ...... Namespace Name CPU Requests CPU Limits Memory Requests Memory Limits --------- ---- ------------ ---------- --------------- ------------- kube-system event-exporter-v0.2.1-5f5b89fcc8-hzgtm 0 (0%) 0 (0%) 0 (0%) 0 (0%) kube-system fluentd-gcp-scaler-7c5db745fc-xdfw8 0 (0%) 0 (0%) 0 (0%) 0 (0%) kube-system fluentd-gcp-v3.0.0-nw4cz 100m (10%) 0 (0%) 200Mi (17%) 300Mi (25%) kube-system heapster-v1.5.3-f767c7cdc-7q82r 138m (14%) 138m (14%) 301456Ki (25%) 301456Ki (25%) kube-system kube-dns-788979dc8f-cf94z 260m (27%) 0 (0%) 110Mi (9%) 170Mi (14%) kube-system kube-dns-autoscaler-79b4b844b9-nzdm6 20m (2%) 0 (0%) 10Mi (0%) 0 (0%) kube-system kube-proxy-gke-hands-on-default-pool-d9f87312-9r5g 100m (10%) 0 (0%) 0 (0%) 0 (0%) kube-system kubernetes-dashboard-598d75cb96-j5dfd 50m (5%) 100m (10%) 100Mi (8%) 300Mi (25%) kube-system l7-default-backend-5d5b9874d5-bkz4g 10m (1%) 10m (1%) 20Mi (1%) 20Mi (1%) kube-system metrics-server-v0.2.1-7486f5bd67-bhjcx 53m (5%) 148m (15%) 154Mi (13%) 404Mi (34%) Allocated resources: (Total limits may be over 100 percent, i.e., overcommitted.) CPU Requests CPU Limits Memory Requests Memory Limits ------------ ---------- --------------- ------------- 731m (77%) 396m (42%) 909712Ki (76%) 1524112Ki (128%)
CPU Requests
/CPU Limits
/Memory Requests
/Memory Limits
例えば、Podを2つデプロイしてみる(ここではdevelopment-monitoring
というnamespaceにprometheus
とalertmanager
のPodを一つずつ追加している)。
$ kustomize build overlays/development | kubectl apply -f - ...... deployment "development-alertmanager" created deployment "development-prometheus" created
たった二つPodを追加しただけで、 CPU Requests
の合計が99%
、Memory Requests
が93%
になっていることがわかる。Nodeはもうすでに限界である。
$ kubectl describe nodes ...... Namespace Name CPU Requests CPU Limits Memory Requests Memory Limits --------- ---- ------------ ---------- --------------- ------------- development-monitoring development-alertmanager-6b46bd5bf9-xz2f7 100m (10%) 100m (10%) 100Mi (8%) 100Mi (8%) development-monitoring development-prometheus-859579ff98-2pf87 100m (10%) 100m (10%) 100Mi (8%) 150Mi (12%) kube-system event-exporter-v0.2.1-5f5b89fcc8-hzgtm 0 (0%) 0 (0%) 0 (0%) 0 (0%) kube-system fluentd-gcp-scaler-7c5db745fc-xdfw8 0 (0%) 0 (0%) 0 (0%) 0 (0%) kube-system fluentd-gcp-v3.0.0-nw4cz 100m (10%) 0 (0%) 200Mi (17%) 300Mi (25%) kube-system heapster-v1.5.3-f767c7cdc-7q82r 138m (14%) 138m (14%) 301456Ki (25%) 301456Ki (25%) kube-system kube-dns-788979dc8f-cf94z 260m (27%) 0 (0%) 110Mi (9%) 170Mi (14%) kube-system kube-dns-autoscaler-79b4b844b9-nzdm6 20m (2%) 0 (0%) 10Mi (0%) 0 (0%) kube-system kube-proxy-gke-hands-on-default-pool-d9f87312-9r5g 100m (10%) 0 (0%) 0 (0%) 0 (0%) kube-system kubernetes-dashboard-598d75cb96-j5dfd 50m (5%) 100m (10%) 100Mi (8%) 300Mi (25%) kube-system l7-default-backend-5d5b9874d5-bkz4g 10m (1%) 10m (1%) 20Mi (1%) 20Mi (1%) kube-system metrics-server-v0.2.1-7486f5bd67-bhjcx 53m (5%) 148m (15%) 154Mi (13%) 404Mi (34%) Allocated resources: (Total limits may be over 100 percent, i.e., overcommitted.) CPU Requests CPU Limits Memory Requests Memory Limits ------------ ---------- --------------- ------------- 931m (99%) 646m (68%) 1114512Ki (93%) 1780112Ki (149%)
kubectl describe nodes
の出力にあるように、各PodにはCPU Requests
/CPU Limits
/Memory Requests
/Memory Limits
の概念があり、Nodeのリソースをケチっている世界では、これらを気をつけて調整しないとあっという間にリソースが枯渇して、以下に示すような様々な問題にぶつかることになる。
Insufficient CPU/Memory
例えば、このリソースが逼迫した状態でPodを更に二つ追加してみる(staging-monitoring
というnamespaceに別のprometheus
とalertmanager
のPodを追加しようとしている)。
$ kustomize build overlays/staging | kubectl apply -f - ...... deployment "staging-alertmanager" created deployment "staging-prometheus" created
kubectl get pods
を見てみるとSTATUS
がPending
のままいつまで経ってもRunning
になってくれない。
$ kubectl get pods --namespace staging-monitoring NAME READY STATUS RESTARTS AGE staging-alertmanager-57d9466c59-g22n4 0/1 Pending 0 3m staging-prometheus-79cf6db666-9bhk9 0/1 Pending 0 3m
こういう時は、kubectl describe
で詳細を見る。0/1 nodes are available: 1 Insufficient cpu, 1 Insufficient memory.
とあるようにCPUもMemoryも足りねーよとスケジューラに怒られていることがわかる。
$ kubectl describe po/staging-prometheus-79cf6db666-9bhk9 --namespace staging-monitoring Events: Type Reason Age From Message ---- ------ ---- ---- ------- Warning FailedScheduling 59s (x8 over 2m) default-scheduler 0/1 nodes are available: 1 Insufficient cpu, 1 Insufficient memory.
個別のPodを見なくても、kubectl get events
を見れば、追加したPodが両方ともリソース不足で起動できないことがわかる。
$ kubectl get events --namespace staging-monitoring LAST SEEN FIRST SEEN COUNT NAME KIND SUBOBJECT TYPE REASON SOURCE MESSAGE 8s 4m 19 staging-alertmanager-57d9466c59-g22n4.154349c73c83d2db Pod Warning FailedScheduling default-scheduler 0/1 nodes are available: 1 Insufficient cpu, 1 Insufficient memory. 8s 4m 19 staging-prometheus-79cf6db666-9bhk9.154349c740986daf Pod Warning FailedScheduling default-scheduler 0/1 nodes are available: 1 Insufficient cpu, 1 Insufficient memory.
OOMKilled
due to Lack of Memory Limits
一旦、作ったPodは全部消して、改めてprometheusとalertmanagerのPodをデプロイする。ただし、ここではprometheusのMemory Limitsを150
(150Mi (12%)
)としていたところを...
$ kubectl describe nodes ...... Namespace Name CPU Requests CPU Limits Memory Requests Memory Limits --------- ---- ------------ ---------- --------------- ------------- development-monitoring development-alertmanager-6b46bd5bf9-xz2f7 100m (10%) 100m (10%) 100Mi (8%) 100Mi (8%) development-monitoring development-prometheus-859579ff98-2pf87 100m (10%) 100m (10%) 100Mi (8%) 150Mi (12%)
デフォルトの100Mi (8%)
に戻してデプロイを試みる。
Namespace Name CPU Requests CPU Limits Memory Requests Memory Limits --------- ---- ------------ ---------- --------------- ------------- development-monitoring development-alertmanager-6b46bd5bf9-fv66p 100m (10%) 100m (10%) 100Mi (8%) 100Mi (8%) development-monitoring development-prometheus-569c948c95-mhqv2 100m (10%) 100m (10%) 100Mi (8%) 100Mi (8%)
デプロイ直後は上手くいっているように見える。
$ kubectl get pods --namespace development-monitoring NAME READY STATUS RESTARTS AGE development-alertmanager-6b46bd5bf9-fv66p 1/1 Running 0 5m development-prometheus-569c948c95-mhqv2 1/1 Running 0 5m
が、prometheusを触ろうとするが何故かアクセスできない。もう一度Podの状態を確かめるとSTATUS
がCrashLoopBackOff
になって、RESTARTS
が延々とカウントアップしている。
$ kubectl get pods --namespace development-monitoring NAME READY STATUS RESTARTS AGE development-alertmanager-6b46bd5bf9-fv66p 1/1 Running 0 3m development-prometheus-569c948c95-mhqv2 0/1 CrashLoopBackOff 4 3m
この時、最初に疑ったのはアプリケーションの問題だったので、kubectl logs
でログを確認してみる*2。てっきり設定ファイルミスってprometheusが落ちているのかと思ったが、そういうわけでもなさそうに見える。
$ kubectl logs po/development-prometheus-569c948c95-mhqv2 --namespace development-monitoring ...... level=info ts=2018-07-21T05:58:44.467605798Z caller=main.go:629 msg="Completed loading of configuration file" filename=/etc/prometheus/prometheus.yaml level=info ts=2018-07-21T05:58:44.467707848Z caller=main.go:502 msg="Server is ready to receive web requests."
kubectl describe pod
で詳細を見てもBack-off restarting failed container
とあるだけでなんのこっちゃと思って、PodのSTATUSを観察していると、実はRunning
--> OOMKilled
--> CrashLoopBackOff
となっていることを発見*3。
$ watch `kubectl get pods --namespace development-monitoring` NAME READY STATUS RESTARTS AGE development-alertmanager-6b46bd5bf9-fv66p 1/1 Running 0 5m development-prometheus-569c948c95-mhqv2 0/1 OOMKilled 5 5m
kubectl describe pod
をよく見直すと、実は出力の中腹あたりにReason: OOMKilled
とはっきり理由が示されていた。
$ kubectl describe pod development-prometheus-569c948c95-mhqv2 --namespace development-monitoring ...... State: Waiting Reason: CrashLoopBackOff Last State: Terminated Reason: OOMKilled Exit Code: 137 Started: Sat, 21 Jul 2018 15:09:47 +0900 Finished: Sat, 21 Jul 2018 15:10:09 +0900 ...... Warning BackOff 2m (x33 over 12m) kubelet, gke-hands-on-default-pool-d9f87312-9r5g Back-off restarting failed container
Ref. Configure Out Of Resource Handling - Kubernetes
Memory limit requestを150
に戻して、prometheusの実際のメモリ使用量をkubectl top pod
で確認すると、確かに100
では足りないことがわかる。
$ kubectl top pod --namespace development-monitoring NAME CPU(cores) MEMORY(bytes) development-alertmanager-6b46bd5bf9-bsmzg 0m 6Mi development-prometheus-859579ff98-w29sn 9m 120Mi
ドキュメントをよく見ると、100m
/100Mi
等の意味とともに、Podが殺された理由を確かめる別の方法も載っていた。
$ kubectl get pod -o go-template='{{range.status.containerStatuses}}{{"Container Name: "}}{{.name}}{{"\r\nLastState: "}}{{.lastState}}{{end}}' development-prometheus-569c948c95-bzrwr --namespace development-monitoring Container Name: prometheus LastState: map[terminated:map[containerID:docker://388979adb46279753bb4a5a563cef22816f836beeed0f028762d3808c6327d38 exitCode:137 finishedAt:2018-07-21T06:52:16Z reason:OOMKilled startedAt:2018-07-21T06:52:00Z]]
- Ref. GKEのコスト節約を考える2 CPUリクエストを調整してリソースを有効活用する - GAミント至上主義
- Ref. Managing Compute Resources for Containers - Kubernetes
Debug Networking
CPU/Memoryリソース不足とは関係ないけど、ネットワーク関係でハマったこともついでにメモ。
Can not create a Load Balancer with the same name on GCP
kubernetes 1.10.5で、IngressでHTTP(S) load balancerをむやみに作ったり消したりを繰り返していたら、kubectl get services
でSTATUSがずっとPending
状態になる現象に出くわした。コンソール上でもDeleting load balancer
となっていて、消したはずのロードバランサを作り直そうとしているようなエラーメッセージが出ていた。
Error deleting load balancer (will retry): GCE 200 - RESOURCE_IN_USE_BY_ANOTHER_RESOURCE: The http_health_check resource 'projects/
/global/httpHealthChecks/k8s-a0515c281357a0b3-node' is already being used by 'projects// /regions/asia-northeast1/targetPools/a35aab2b3867711e8b08d42010a92015'
これは既知の問題でロードバランサの名前を変えてデプロイするのが(2018/07/21時点での)workaroundだと思っていたら、修正が入ったっぽい。自分で試してないけど クラスタを1.10.5-gke.3
にアップグレードしたら問題が解消されたと報告がある。
There is Endpoint
behind Service
問題の原因はServiceで定義するselector
にtypoがあっただけというしょうもないものだけど、修正の過程で知ったことをついでにメモ。
kubernetesは各Serviceに内部的なAレコードmy-svc.my-namespace.svc.cluster.localを発行してくれるので、これを使ってprometheusからalertmanagerへアラートを飛ばそうと試みたが、通信がタイムアウトをしてしまってアラートを飛ばせない。
development-prometheus-7d648b4bd8-fpgcg prometheus level=error ts=2018-07-19T10:28:52.666687678Z caller=notifier.go:473 component=notifier alertmanager=http://development-alertmanager.development-monitoring.svc.cluster.local:9093/api/v1/alerts count=1 msg="Error sending alert" err="context deadline exceeded"
kubectl run -it --rm --restart=Never busybox --image=busybox sh
からkubernetesの内部ネットワークにアクセスして、名前解決できているか確認して見るがちゃんとローカルIPが帰ってきている。
$ kubectl run -it --rm --restart=Never busybox --image=busybox sh --namespace development-monitoring If you don't see a command prompt, try pressing enter. / # nslookup development-alertmanager.development-monitoring.svc.cluster.local Server: 10.55.240.10 Address 1: 10.55.240.10 kube-dns.kube-system.svc.cluster.local Name: development-alertmanager.development-monitoring.svc.cluster.local Address 1: 10.55.253.170 development-alertmanager.development-monitoring.svc.cluster.local / #
Ref. Using Source IP - Kubernetes
ところでServiceは基本service.spec.selector
で対応するPodのLabelを指定する。正しく指定している場合、endpoint controllerが対応するEndpoints
を自動的に作成してくれる。
The Service’s selector will be evaluated continuously and the results will be POSTed to an Endpoints object also named “my-service”.
さもなければ自分でEndpointsを定義する必要がある。
Services without selectors Because this service has no selector, the corresponding Endpoints object will not be created. You can manually map the service to your own specific endpoints:
Services without selectors
このLabel指定にtypoがあると対応するPodが見つからないのでselectorの設定がないのと同じ扱いとなり、結果的に以下のような感じで必要なEndpoints
の値が尽く見当たらない状態になってしまう。
$ kubectl get endpoints --namespace development-monitoring NAME ENDPOINTS AGE development-alertmanager <none> 13m development-prometheus <none> 13m
$ kubectl describe endpoints development-alertmanager Name: development-alertmanager Namespace: development-monitoring Labels: app=monitoring name=alertmanager variant=development Annotations: <none> Subsets: Events: <none>
デバッグ中はEndpointsの存在を認識せずにprometheusやServiceのドキュメントなりissueを漁っていたので、今見ると如何にも怪しいEndpoints: <none>
も目に入ってこない。
$ kubectl describe service/development-alertmanager Name: development-alertmanager Namespace: development-monitoring Labels: app=monitoring name=alertmanager variant=development ...... Selector: app=monitoring,deployment=alertmanager,variant=development Type: ClusterIP IP: 10.55.246.213 Port: <unset> 9093/TCP TargetPort: 9093/TCP Endpoints: <none> Session Affinity: None Events: <none>
Services with selectors
正しく設定すると、clusterIPとは別にEndpointsのIPが現れる。
$ kubectl get endpoints --namespace development-monitoring NAME ENDPOINTS AGE development-alertmanager 10.52.0.150:9093 59m development-prometheus 10.52.0.151:9090 59m
$ kubectl describe endpoints development-alertmanager --namespace development-monitoring Name: development-alertmanager Namespace: development-monitoring Labels: app=monitoring name=alertmanager variant=development Annotations: <none> Subsets: Addresses: 10.52.0.150 NotReadyAddresses: <none> Ports: Name Port Protocol ---- ---- -------- <unset> 9093 TCP Events: <none>
$ kubectl describe service/development-alertmanager --namespace development-monitoring Name: development-alertmanager Namespace: development-monitoring Labels: app=monitoring name=alertmanager variant=development ...... Selector: app=monitoring,name=alertmanager,variant=development Type: ClusterIP IP: 10.55.253.170 Port: <unset> 9093/TCP TargetPort: 9093/TCP Endpoints: 10.52.0.150:9093 Session Affinity: None Events: <none>
知らないことは知るまで知らない。
etc...
その他、ハマる度に随時更新...