search

rancher / rke2

https://docs.rke2.io/
Apache License 2.0
1.57k stars 268 forks source link

multipass vm - Waiting for API server to become available #5570

Closed JCzz closed 8 months ago

JCzz commented 8 months ago

Environmental Info: RKE2 Version: https://docs.rke2.io/install/quickstart

Node(s) CPU architecture, OS, and Version: multipass launch --name rke2-vm --mem 8192MB --disk 20G -c 4

Describe the bug: "journalctl -u rke2-server -f" shows the following log

Additional context / logs:

journalctl -u rke2-server -f
Mar 06 22:54:31 rke2-vm rke2[1924]: time="2024-03-06T22:54:31+01:00" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_established' to 86400"
Mar 06 22:54:31 rke2-vm rke2[1924]: time="2024-03-06T22:54:31+01:00" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_close_wait' to 3600"
Mar 06 22:54:31 rke2-vm rke2[1924]: time="2024-03-06T22:54:31+01:00" level=info msg="Set sysctl 'net/ipv4/conf/all/forwarding' to 1"
Mar 06 22:54:31 rke2-vm rke2[1924]: time="2024-03-06T22:54:31+01:00" level=info msg="Checking local image archives in /var/lib/rancher/rke2/agent/images for index.docker.io/rancher/rke2-runtime:v1.27.11-rke2r1"
Mar 06 22:54:31 rke2-vm rke2[1924]: time="2024-03-06T22:54:31+01:00" level=warning msg="Failed to load runtime image index.docker.io/rancher/rke2-runtime:v1.27.11-rke2r1 from tarball: no local image available for index.docker.io/rancher/rke2-runtime:v1.27.11-rke2r1: not found in any file in /var/lib/rancher/rke2/agent/images: image not found"
Mar 06 22:54:31 rke2-vm rke2[1924]: time="2024-03-06T22:54:31+01:00" level=info msg="Checking local image archives in /var/lib/rancher/rke2/agent/images for index.docker.io/rancher/rke2-runtime:v1.27.11-rke2r1"
Mar 06 22:54:31 rke2-vm rke2[1924]: time="2024-03-06T22:54:31+01:00" level=warning msg="Failed to load runtime image index.docker.io/rancher/rke2-runtime:v1.27.11-rke2r1 from tarball: no local image available for index.docker.io/rancher/rke2-runtime:v1.27.11-rke2r1: not found in any file in /var/lib/rancher/rke2/agent/images: image not found"
Mar 06 22:54:31 rke2-vm rke2[1924]: time="2024-03-06T22:54:31+01:00" level=info msg="Pulling runtime image index.docker.io/rancher/rke2-runtime:v1.27.11-rke2r1"
Mar 06 22:54:34 rke2-vm rke2[1924]: time="2024-03-06T22:54:34+01:00" level=info msg="Creating directory /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/bin"
Mar 06 22:54:34 rke2-vm rke2[1924]: time="2024-03-06T22:54:34+01:00" level=info msg="Extracting file bin/containerd to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/bin/containerd"
Mar 06 22:54:43 rke2-vm rke2[1924]: time="2024-03-06T22:54:43+01:00" level=info msg="Extracting file bin/containerd-shim to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/bin/containerd-shim"
Mar 06 22:54:44 rke2-vm rke2[1924]: time="2024-03-06T22:54:44+01:00" level=info msg="Extracting file bin/containerd-shim-runc-v1 to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/bin/containerd-shim-runc-v1"
Mar 06 22:54:45 rke2-vm rke2[1924]: {"level":"warn","ts":"2024-03-06T22:54:45.996143+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0x4000c06540/127.0.0.1:2379","attempt":0,"error":"rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:2379: connect: connection refused\""}
Mar 06 22:54:45 rke2-vm rke2[1924]: {"level":"info","ts":"2024-03-06T22:54:45.99638+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/client.go:210","msg":"Auto sync endpoints failed.","error":"context deadline exceeded"}
Mar 06 22:54:46 rke2-vm rke2[1924]: time="2024-03-06T22:54:46+01:00" level=info msg="Extracting file bin/containerd-shim-runc-v2 to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/bin/containerd-shim-runc-v2"
Mar 06 22:54:48 rke2-vm rke2[1924]: time="2024-03-06T22:54:48+01:00" level=info msg="Extracting file bin/crictl to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/bin/crictl"
Mar 06 22:54:51 rke2-vm rke2[1924]: time="2024-03-06T22:54:51+01:00" level=info msg="Waiting for cri connection: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing: dial unix /run/k3s/containerd/containerd.sock: connect: no such file or directory\""
Mar 06 22:54:53 rke2-vm rke2[1924]: time="2024-03-06T22:54:53+01:00" level=info msg="Extracting file bin/ctr to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/bin/ctr"
Mar 06 22:54:56 rke2-vm rke2[1924]: time="2024-03-06T22:54:56+01:00" level=info msg="Extracting file bin/kubectl to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/bin/kubectl"
Mar 06 22:55:00 rke2-vm rke2[1924]: {"level":"warn","ts":"2024-03-06T22:55:00.99728+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0x4000c06540/127.0.0.1:2379","attempt":0,"error":"rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:2379: connect: connection refused\""}
Mar 06 22:55:00 rke2-vm rke2[1924]: {"level":"info","ts":"2024-03-06T22:55:00.997326+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/client.go:210","msg":"Auto sync endpoints failed.","error":"context deadline exceeded"}
Mar 06 22:55:00 rke2-vm rke2[1924]: {"level":"warn","ts":"2024-03-06T22:55:00.998419+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0x4000c06540/127.0.0.1:2379","attempt":0,"error":"rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:2379: connect: connection refused\""}
Mar 06 22:55:00 rke2-vm rke2[1924]: time="2024-03-06T22:55:00+01:00" level=info msg="Failed to test data store connection: context deadline exceeded"
Mar 06 22:55:01 rke2-vm rke2[1924]: time="2024-03-06T22:55:01+01:00" level=info msg="Waiting for etcd server to become available"
Mar 06 22:55:01 rke2-vm rke2[1924]: time="2024-03-06T22:55:01+01:00" level=info msg="Waiting for API server to become available"
Mar 06 22:55:02 rke2-vm rke2[1924]: time="2024-03-06T22:55:02+01:00" level=info msg="Extracting file bin/kubelet to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/bin/kubelet"
Mar 06 22:55:11 rke2-vm rke2[1924]: time="2024-03-06T22:55:11+01:00" level=info msg="Waiting for cri connection: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing: dial unix /run/k3s/containerd/containerd.sock: connect: no such file or directory\""
Mar 06 22:55:15 rke2-vm rke2[1924]: {"level":"warn","ts":"2024-03-06T22:55:15.997948+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0x4000c06540/127.0.0.1:2379","attempt":0,"error":"rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:2379: connect: connection refused\""}
Mar 06 22:55:15 rke2-vm rke2[1924]: {"level":"info","ts":"2024-03-06T22:55:15.998004+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/client.go:210","msg":"Auto sync endpoints failed.","error":"context deadline exceeded"}
Mar 06 22:55:17 rke2-vm rke2[1924]: time="2024-03-06T22:55:17+01:00" level=info msg="Extracting file bin/runc to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/bin/runc"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Creating directory /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/harvester-cloud-provider.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/harvester-cloud-provider.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/harvester-csi-driver.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/harvester-csi-driver.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rancher-vsphere-cpi.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rancher-vsphere-cpi.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rancher-vsphere-csi.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rancher-vsphere-csi.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rke2-calico-crd.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rke2-calico-crd.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rke2-calico.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rke2-calico.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rke2-canal.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rke2-canal.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rke2-cilium.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rke2-cilium.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rke2-coredns.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rke2-coredns.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rke2-flannel.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rke2-flannel.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rke2-ingress-nginx.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rke2-ingress-nginx.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rke2-metrics-server.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rke2-metrics-server.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rke2-multus.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rke2-multus.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rke2-snapshot-controller-crd.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rke2-snapshot-controller-crd.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rke2-snapshot-controller.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rke2-snapshot-controller.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Extracting file charts/rke2-snapshot-validation-webhook.yaml to /var/lib/rancher/rke2/data/v1.27.11-rke2r1-e5ed44ee32a0/charts/rke2-snapshot-validation-webhook.yaml"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/harvester-csi-driver.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-snapshot-controller.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-snapshot-validation-webhook.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/harvester-cloud-provider.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-canal.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-cilium.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-metrics-server.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rancher-vsphere-cpi.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rancher-vsphere-csi.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-calico-crd.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-calico.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-multus.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-coredns.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-flannel.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-ingress-nginx.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-snapshot-controller-crd.yaml to set cluster configuration values"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Logging containerd to /var/lib/rancher/rke2/agent/containerd/containerd.log"
Mar 06 22:55:19 rke2-vm rke2[1924]: time="2024-03-06T22:55:19+01:00" level=info msg="Running containerd -c /var/lib/rancher/rke2/agent/etc/containerd/config.toml -a /run/k3s/containerd/containerd.sock --state /run/k3s/containerd --root /var/lib/rancher/rke2/agent/containerd"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="containerd is now running"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Pulling images from /var/lib/rancher/rke2/agent/images/cloud-controller-manager-image.txt"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Image index.docker.io/rancher/rke2-cloud-provider:v1.28.2-build20231016 has already been pulled"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=error msg="Error encountered while importing /var/lib/rancher/rke2/agent/images/cloud-controller-manager-image.txt: failed to pull images from /var/lib/rancher/rke2/agent/images/cloud-controller-manager-image.txt: image \"index.docker.io/rancher/rke2-cloud-provider:v1.28.2-build20231016\": not found"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Pulling images from /var/lib/rancher/rke2/agent/images/etcd-image.txt"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Image index.docker.io/rancher/hardened-etcd:v3.5.9-k3s1-build20230802 has already been pulled"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=error msg="Error encountered while importing /var/lib/rancher/rke2/agent/images/etcd-image.txt: failed to pull images from /var/lib/rancher/rke2/agent/images/etcd-image.txt: image \"index.docker.io/rancher/hardened-etcd:v3.5.9-k3s1-build20230802\": not found"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Pulling images from /var/lib/rancher/rke2/agent/images/kube-apiserver-image.txt"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Image index.docker.io/rancher/hardened-kubernetes:v1.27.11-rke2r1-build20240214 has already been pulled"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=error msg="Error encountered while importing /var/lib/rancher/rke2/agent/images/kube-apiserver-image.txt: failed to pull images from /var/lib/rancher/rke2/agent/images/kube-apiserver-image.txt: image \"index.docker.io/rancher/hardened-kubernetes:v1.27.11-rke2r1-build20240214\": not found"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Pulling images from /var/lib/rancher/rke2/agent/images/kube-controller-manager-image.txt"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Image index.docker.io/rancher/hardened-kubernetes:v1.27.11-rke2r1-build20240214 has already been pulled"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=error msg="Error encountered while importing /var/lib/rancher/rke2/agent/images/kube-controller-manager-image.txt: failed to pull images from /var/lib/rancher/rke2/agent/images/kube-controller-manager-image.txt: image \"index.docker.io/rancher/hardened-kubernetes:v1.27.11-rke2r1-build20240214\": not found"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Pulling images from /var/lib/rancher/rke2/agent/images/kube-scheduler-image.txt"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Image index.docker.io/rancher/hardened-kubernetes:v1.27.11-rke2r1-build20240214 has already been pulled"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=error msg="Error encountered while importing /var/lib/rancher/rke2/agent/images/kube-scheduler-image.txt: failed to pull images from /var/lib/rancher/rke2/agent/images/kube-scheduler-image.txt: image \"index.docker.io/rancher/hardened-kubernetes:v1.27.11-rke2r1-build20240214\": not found"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Pulling images from /var/lib/rancher/rke2/agent/images/runtime-image.txt"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Image index.docker.io/rancher/rke2-runtime:v1.27.11-rke2r1 has already been pulled"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=error msg="Error encountered while importing /var/lib/rancher/rke2/agent/images/runtime-image.txt: failed to pull images from /var/lib/rancher/rke2/agent/images/runtime-image.txt: image \"index.docker.io/rancher/rke2-runtime:v1.27.11-rke2r1\": not found"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Connecting to proxy" url="wss://127.0.0.1:9345/v1-rke2/connect"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Running kubelet --address=0.0.0.0 --alsologtostderr=false --anonymous-auth=false --authentication-token-webhook=true --authorization-mode=Webhook --cgroup-driver=systemd --client-ca-file=/var/lib/rancher/rke2/agent/client-ca.crt --cloud-provider=external --cluster-dns=10.43.0.10 --cluster-domain=cluster.local --container-runtime-endpoint=unix:///run/k3s/containerd/containerd.sock --containerd=/run/k3s/containerd/containerd.sock --eviction-hard=imagefs.available<5%,nodefs.available<5% --eviction-minimum-reclaim=imagefs.available=10%,nodefs.available=10% --fail-swap-on=false --feature-gates=CloudDualStackNodeIPs=true --healthz-bind-address=127.0.0.1 --hostname-override=rke2-vm --kubeconfig=/var/lib/rancher/rke2/agent/kubelet.kubeconfig --log-file=/var/lib/rancher/rke2/agent/logs/kubelet.log --log-file-max-size=50 --logtostderr=false --node-ip=192.168.105.74 --node-labels= --pod-infra-container-image=index.docker.io/rancher/mirrored-pause:3.6 --pod-manifest-path=/var/lib/rancher/rke2/agent/pod-manifests --read-only-port=0 --resolv-conf=/var/lib/rancher/rke2/agent/etc/resolv.conf --serialize-image-pulls=false --stderrthreshold=FATAL --tls-cert-file=/var/lib/rancher/rke2/agent/serving-kubelet.crt --tls-private-key-file=/var/lib/rancher/rke2/agent/serving-kubelet.key"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Handling backend connection request [rke2-vm]"
Mar 06 22:55:20 rke2-vm rke2[1924]: time="2024-03-06T22:55:20+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:55:25 rke2-vm rke2[1924]: time="2024-03-06T22:55:25+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:55:31 rke2-vm rke2[1924]: {"level":"warn","ts":"2024-03-06T22:55:31.002724+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0x4000c06540/127.0.0.1:2379","attempt":0,"error":"rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:2379: connect: connection refused\""}
Mar 06 22:55:31 rke2-vm rke2[1924]: {"level":"info","ts":"2024-03-06T22:55:31.002794+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/client.go:210","msg":"Auto sync endpoints failed.","error":"context deadline exceeded"}
Mar 06 22:55:31 rke2-vm rke2[1924]: time="2024-03-06T22:55:31+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:55:31 rke2-vm rke2[1924]: time="2024-03-06T22:55:31+01:00" level=info msg="Waiting for etcd server to become available"
Mar 06 22:55:31 rke2-vm rke2[1924]: time="2024-03-06T22:55:31+01:00" level=info msg="Waiting for API server to become available"
Mar 06 22:55:31 rke2-vm rke2[1924]: time="2024-03-06T22:55:31+01:00" level=info msg="Pod for etcd is synced"
Mar 06 22:55:35 rke2-vm rke2[1924]: time="2024-03-06T22:55:35+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:55:36 rke2-vm rke2[1924]: {"level":"warn","ts":"2024-03-06T22:55:36.004464+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0x4000c06540/127.0.0.1:2379","attempt":0,"error":"rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:2379: connect: connection refused\""}
Mar 06 22:55:36 rke2-vm rke2[1924]: time="2024-03-06T22:55:36+01:00" level=info msg="Failed to test data store connection: context deadline exceeded"
Mar 06 22:55:40 rke2-vm rke2[1924]: time="2024-03-06T22:55:40+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:55:45 rke2-vm rke2[1924]: time="2024-03-06T22:55:45+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:55:46 rke2-vm rke2[1924]: {"level":"warn","ts":"2024-03-06T22:55:46.003539+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0x4000c06540/127.0.0.1:2379","attempt":0,"error":"rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:2379: connect: connection refused\""}
Mar 06 22:55:46 rke2-vm rke2[1924]: {"level":"info","ts":"2024-03-06T22:55:46.00358+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/client.go:210","msg":"Auto sync endpoints failed.","error":"context deadline exceeded"}
Mar 06 22:55:50 rke2-vm rke2[1924]: {"level":"warn","ts":"2024-03-06T22:55:50.84795+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0x4000c06540/127.0.0.1:2379","attempt":0,"error":"rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:2379: connect: connection refused\""}
Mar 06 22:55:50 rke2-vm rke2[1924]: time="2024-03-06T22:55:50+01:00" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Mar 06 22:55:50 rke2-vm rke2[1924]: time="2024-03-06T22:55:50+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:55:55 rke2-vm rke2[1924]: time="2024-03-06T22:55:55+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:56:00 rke2-vm rke2[1924]: time="2024-03-06T22:56:00+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:56:01 rke2-vm rke2[1924]: {"level":"warn","ts":"2024-03-06T22:56:01.005386+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0x4000c06540/127.0.0.1:2379","attempt":0,"error":"rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:2379: connect: connection refused\""}
Mar 06 22:56:01 rke2-vm rke2[1924]: {"level":"info","ts":"2024-03-06T22:56:01.005427+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/client.go:210","msg":"Auto sync endpoints failed.","error":"context deadline exceeded"}
Mar 06 22:56:01 rke2-vm rke2[1924]: time="2024-03-06T22:56:01+01:00" level=info msg="Waiting for etcd server to become available"
Mar 06 22:56:01 rke2-vm rke2[1924]: time="2024-03-06T22:56:01+01:00" level=info msg="Waiting for API server to become available"
Mar 06 22:56:05 rke2-vm rke2[1924]: {"level":"warn","ts":"2024-03-06T22:56:05.849921+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0x4000c06540/127.0.0.1:2379","attempt":0,"error":"rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:2379: connect: connection refused\""}
Mar 06 22:56:05 rke2-vm rke2[1924]: time="2024-03-06T22:56:05+01:00" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Mar 06 22:56:05 rke2-vm rke2[1924]: time="2024-03-06T22:56:05+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:56:09 rke2-vm rke2[1924]: time="2024-03-06T22:56:09+01:00" level=info msg="Defragmenting etcd database"
Mar 06 22:56:10 rke2-vm rke2[1924]: time="2024-03-06T22:56:10+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:56:11 rke2-vm rke2[1924]: {"level":"warn","ts":"2024-03-06T22:56:11.005532+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0x4000c06540/127.0.0.1:2379","attempt":0,"error":"rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:2379: connect: connection refused\""}
Mar 06 22:56:11 rke2-vm rke2[1924]: time="2024-03-06T22:56:11+01:00" level=info msg="Failed to test data store connection: failed to report and disarm etcd alarms: etcd alarm list failed: context deadline exceeded"
Mar 06 22:56:15 rke2-vm rke2[1924]: time="2024-03-06T22:56:15+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:56:16 rke2-vm rke2[1924]: {"level":"warn","ts":"2024-03-06T22:56:16.005469+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0x4000c06540/127.0.0.1:2379","attempt":0,"error":"rpc error: code = DeadlineExceeded desc = latest balancer error: last connection error: connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:2379: connect: connection refused\""}
Mar 06 22:56:16 rke2-vm rke2[1924]: {"level":"info","ts":"2024-03-06T22:56:16.005519+0100","logger":"etcd-client","caller":"v3@v3.5.9-k3s1/client.go:210","msg":"Auto sync endpoints failed.","error":"context deadline exceeded"}
Mar 06 22:56:16 rke2-vm rke2[1924]: time="2024-03-06T22:56:16+01:00" level=info msg="Defragmenting etcd database"
Mar 06 22:56:16 rke2-vm rke2[1924]: time="2024-03-06T22:56:16+01:00" level=warning msg="Failed to list nodes with etcd role: runtime core not ready"
Mar 06 22:56:16 rke2-vm rke2[1924]: time="2024-03-06T22:56:16+01:00" level=info msg="etcd data store connection OK"
Mar 06 22:56:16 rke2-vm rke2[1924]: time="2024-03-06T22:56:16+01:00" level=info msg="Saving cluster bootstrap data to datastore"
Mar 06 22:56:16 rke2-vm rke2[1924]: time="2024-03-06T22:56:16+01:00" level=info msg="Waiting for API server to become available"
Mar 06 22:56:20 rke2-vm rke2[1924]: time="2024-03-06T22:56:20+01:00" level=info msg="Removed kube-proxy static pod manifest"
Mar 06 22:56:20 rke2-vm rke2[1924]: time="2024-03-06T22:56:20+01:00" level=warning msg="Failed to list nodes with etcd role: runtime core not ready"
Mar 06 22:56:20 rke2-vm rke2[1924]: time="2024-03-06T22:56:20+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:56:25 rke2-vm rke2[1924]: time="2024-03-06T22:56:25+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:56:30 rke2-vm rke2[1924]: time="2024-03-06T22:56:30+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
Mar 06 22:56:31 rke2-vm rke2[1924]: time="2024-03-06T22:56:31+01:00" level=info msg="Waiting for API server to become available"
Mar 06 22:56:35 rke2-vm rke2[1924]: time="2024-03-06T22:56:35+01:00" level=warning msg="Failed to list nodes with etcd role: runtime core not ready"
Mar 06 22:56:35 rke2-vm rke2[1924]: time="2024-03-06T22:56:35+01:00" level=info msg="Waiting to retrieve kube-proxy configuration; server is not ready: https://127.0.0.1:9345/v1-rke2/readyz: 500 Internal Server Error"
brandond commented 8 months ago

It looks like the apiserver isn't coming up. Have you checked the apiserver pod logs under /var/log/pods to see why?

JCzz commented 8 months ago

Thanks @brandond

In /var/log/pods I have:

sudo cat /var/log/pods/kube-system_kube-apiserver-rke2-vm_8b2ec5d2d3e3126dd75d63a7376 452a4/kube-apiserver/0.log 

2024-03-07T09:25:51.182412871+01:00 stderr F I0307 08:25:51.181891       1 server.go:554] external host was not specified, using 192.168.105.75
2024-03-07T09:25:51.182991518+01:00 stderr F I0307 08:25:51.182918       1 server.go:166] Version: v1.27.11+rke2r1
2024-03-07T09:25:51.182999685+01:00 stderr F I0307 08:25:51.182935       1 server.go:168] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
2024-03-07T09:25:51.36987555+01:00 stderr F I0307 08:25:51.369744       1 shared_informer.go:311] Waiting for caches to sync for node_authorizer
2024-03-07T09:25:51.377618223+01:00 stderr F I0307 08:25:51.377493       1 plugins.go:158] Loaded 12 mutating admission controller(s) successfully in the following order: NamespaceLifecycle,LimitRanger,ServiceAccount,NodeRestriction,TaintNodesByCondition,Priority,DefaultTolerationSeconds,DefaultStorageClass,StorageObjectInUseProtection,RuntimeClass,DefaultIngressClass,MutatingAdmissionWebhook.
2024-03-07T09:25:51.377629599+01:00 stderr F I0307 08:25:51.377530       1 plugins.go:161] Loaded 13 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,ClusterTrustBundleAttest,CertificateSubjectRestriction,ValidatingAdmissionPolicy,ValidatingAdmissionWebhook,ResourceQuota.
2024-03-07T09:25:51.392353499+01:00 stderr F I0307 08:25:51.392282       1 handler.go:275] Adding GroupVersion apiextensions.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.39236625+01:00 stderr F W0307 08:25:51.392298       1 genericapiserver.go:744] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.393100611+01:00 stderr F I0307 08:25:51.393052       1 instance.go:282] Using reconciler: lease
2024-03-07T09:25:51.469547431+01:00 stderr F I0307 08:25:51.469471       1 handler.go:275] Adding GroupVersion  v1 to ResourceManager
2024-03-07T09:25:51.469864735+01:00 stderr F I0307 08:25:51.469789       1 instance.go:651] API group "internal.apiserver.k8s.io" is not enabled, skipping.
2024-03-07T09:25:51.59545453+01:00 stderr F I0307 08:25:51.595343       1 instance.go:651] API group "resource.k8s.io" is not enabled, skipping.
2024-03-07T09:25:51.604002068+01:00 stderr F I0307 08:25:51.603924       1 handler.go:275] Adding GroupVersion authentication.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.604016693+01:00 stderr F W0307 08:25:51.603944       1 genericapiserver.go:744] Skipping API authentication.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.604017735+01:00 stderr F W0307 08:25:51.603948       1 genericapiserver.go:744] Skipping API authentication.k8s.io/v1alpha1 because it has no resources.
2024-03-07T09:25:51.604293621+01:00 stderr F I0307 08:25:51.604263       1 handler.go:275] Adding GroupVersion authorization.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.604296787+01:00 stderr F W0307 08:25:51.604273       1 genericapiserver.go:744] Skipping API authorization.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.605039483+01:00 stderr F I0307 08:25:51.605007       1 handler.go:275] Adding GroupVersion autoscaling v2 to ResourceManager
2024-03-07T09:25:51.605640214+01:00 stderr F I0307 08:25:51.605607       1 handler.go:275] Adding GroupVersion autoscaling v1 to ResourceManager
2024-03-07T09:25:51.605644423+01:00 stderr F W0307 08:25:51.605619       1 genericapiserver.go:744] Skipping API autoscaling/v2beta1 because it has no resources.
2024-03-07T09:25:51.605645589+01:00 stderr F W0307 08:25:51.605622       1 genericapiserver.go:744] Skipping API autoscaling/v2beta2 because it has no resources.
2024-03-07T09:25:51.607184815+01:00 stderr F I0307 08:25:51.607132       1 handler.go:275] Adding GroupVersion batch v1 to ResourceManager
2024-03-07T09:25:51.607192399+01:00 stderr F W0307 08:25:51.607155       1 genericapiserver.go:744] Skipping API batch/v1beta1 because it has no resources.
2024-03-07T09:25:51.607949803+01:00 stderr F I0307 08:25:51.607916       1 handler.go:275] Adding GroupVersion certificates.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.607972429+01:00 stderr F W0307 08:25:51.607926       1 genericapiserver.go:744] Skipping API certificates.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.607973679+01:00 stderr F W0307 08:25:51.607928       1 genericapiserver.go:744] Skipping API certificates.k8s.io/v1alpha1 because it has no resources.
2024-03-07T09:25:51.608436864+01:00 stderr F I0307 08:25:51.608352       1 handler.go:275] Adding GroupVersion coordination.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.608450406+01:00 stderr F W0307 08:25:51.608365       1 genericapiserver.go:744] Skipping API coordination.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.608451614+01:00 stderr F W0307 08:25:51.608387       1 genericapiserver.go:744] Skipping API discovery.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.608889589+01:00 stderr F I0307 08:25:51.608840       1 handler.go:275] Adding GroupVersion discovery.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.6104754+01:00 stderr F I0307 08:25:51.610414       1 handler.go:275] Adding GroupVersion networking.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.610481151+01:00 stderr F W0307 08:25:51.610426       1 genericapiserver.go:744] Skipping API networking.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.610482442+01:00 stderr F W0307 08:25:51.610428       1 genericapiserver.go:744] Skipping API networking.k8s.io/v1alpha1 because it has no resources.
2024-03-07T09:25:51.610848081+01:00 stderr F I0307 08:25:51.610732       1 handler.go:275] Adding GroupVersion node.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.610853957+01:00 stderr F W0307 08:25:51.610746       1 genericapiserver.go:744] Skipping API node.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.610855207+01:00 stderr F W0307 08:25:51.610748       1 genericapiserver.go:744] Skipping API node.k8s.io/v1alpha1 because it has no resources.
2024-03-07T09:25:51.611425937+01:00 stderr F I0307 08:25:51.611390       1 handler.go:275] Adding GroupVersion policy v1 to ResourceManager
2024-03-07T09:25:51.611430562+01:00 stderr F W0307 08:25:51.611402       1 genericapiserver.go:744] Skipping API policy/v1beta1 because it has no resources.
2024-03-07T09:25:51.612970996+01:00 stderr F I0307 08:25:51.612939       1 handler.go:275] Adding GroupVersion rbac.authorization.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.612975288+01:00 stderr F W0307 08:25:51.612953       1 genericapiserver.go:744] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.612976622+01:00 stderr F W0307 08:25:51.612956       1 genericapiserver.go:744] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.
2024-03-07T09:25:51.613368303+01:00 stderr F I0307 08:25:51.613282       1 handler.go:275] Adding GroupVersion scheduling.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.613372345+01:00 stderr F W0307 08:25:51.613299       1 genericapiserver.go:744] Skipping API scheduling.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.613373554+01:00 stderr F W0307 08:25:51.613303       1 genericapiserver.go:744] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources.
2024-03-07T09:25:51.615524553+01:00 stderr F I0307 08:25:51.615460       1 handler.go:275] Adding GroupVersion storage.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.615528553+01:00 stderr F W0307 08:25:51.615470       1 genericapiserver.go:744] Skipping API storage.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.615529637+01:00 stderr F W0307 08:25:51.615473       1 genericapiserver.go:744] Skipping API storage.k8s.io/v1alpha1 because it has no resources.
2024-03-07T09:25:51.616078991+01:00 stderr F I0307 08:25:51.616021       1 handler.go:275] Adding GroupVersion flowcontrol.apiserver.k8s.io v1beta3 to ResourceManager
2024-03-07T09:25:51.616665014+01:00 stderr F I0307 08:25:51.616581       1 handler.go:275] Adding GroupVersion flowcontrol.apiserver.k8s.io v1beta2 to ResourceManager
2024-03-07T09:25:51.616670264+01:00 stderr F W0307 08:25:51.616596       1 genericapiserver.go:744] Skipping API flowcontrol.apiserver.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.616682014+01:00 stderr F W0307 08:25:51.616599       1 genericapiserver.go:744] Skipping API flowcontrol.apiserver.k8s.io/v1alpha1 because it has no resources.
2024-03-07T09:25:51.618313827+01:00 stderr F I0307 08:25:51.618277       1 handler.go:275] Adding GroupVersion apps v1 to ResourceManager
2024-03-07T09:25:51.618319453+01:00 stderr F W0307 08:25:51.618292       1 genericapiserver.go:744] Skipping API apps/v1beta2 because it has no resources.
2024-03-07T09:25:51.618323244+01:00 stderr F W0307 08:25:51.618294       1 genericapiserver.go:744] Skipping API apps/v1beta1 because it has no resources.
2024-03-07T09:25:51.618844514+01:00 stderr F I0307 08:25:51.618804       1 handler.go:275] Adding GroupVersion admissionregistration.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.618848181+01:00 stderr F W0307 08:25:51.618824       1 genericapiserver.go:744] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.618849348+01:00 stderr F W0307 08:25:51.618828       1 genericapiserver.go:744] Skipping API admissionregistration.k8s.io/v1alpha1 because it has no resources.
2024-03-07T09:25:51.619148609+01:00 stderr F I0307 08:25:51.619103       1 handler.go:275] Adding GroupVersion events.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.619152068+01:00 stderr F W0307 08:25:51.619129       1 genericapiserver.go:744] Skipping API events.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:51.623033926+01:00 stderr F I0307 08:25:51.622961       1 handler.go:275] Adding GroupVersion apiregistration.k8s.io v1 to ResourceManager
2024-03-07T09:25:51.623040884+01:00 stderr F W0307 08:25:51.622973       1 genericapiserver.go:744] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources.
2024-03-07T09:25:52.008977458+01:00 stderr F I0307 08:25:52.008670       1 dynamic_cafile_content.go:157] "Starting controller" name="request-header::/var/lib/rancher/rke2/server/tls/request-header-ca.crt"
2024-03-07T09:25:52.009007792+01:00 stderr F I0307 08:25:52.008741       1 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/var/lib/rancher/rke2/server/tls/client-ca.crt"
2024-03-07T09:25:52.009012251+01:00 stderr F I0307 08:25:52.008803       1 dynamic_serving_content.go:132] "Starting controller" name="serving-cert::/var/lib/rancher/rke2/server/tls/serving-kube-apiserver.crt::/var/lib/rancher/rke2/server/tls/serving-kube-apiserver.key"
2024-03-07T09:25:52.009014376+01:00 stderr F I0307 08:25:52.008903       1 secure_serving.go:213] Serving securely on [::]:6443
2024-03-07T09:25:52.009119922+01:00 stderr F I0307 08:25:52.009055       1 tlsconfig.go:240] "Starting DynamicServingCertificateController"
2024-03-07T09:25:52.027583551+01:00 stderr F I0307 08:25:52.027113       1 cluster_authentication_trust_controller.go:440] Starting cluster_authentication_trust_controller controller
2024-03-07T09:25:52.027604885+01:00 stderr F I0307 08:25:52.027121       1 shared_informer.go:311] Waiting for caches to sync for cluster_authentication_trust_controller
2024-03-07T09:25:52.027610969+01:00 stderr F I0307 08:25:52.027207       1 gc_controller.go:78] Starting apiserver lease garbage collector
2024-03-07T09:25:52.027640303+01:00 stderr F I0307 08:25:52.027219       1 apf_controller.go:379] Starting API Priority and Fairness config controller
2024-03-07T09:25:52.027644887+01:00 stderr F I0307 08:25:52.027306       1 controller.go:80] Starting OpenAPI V3 AggregationController
2024-03-07T09:25:52.027646012+01:00 stderr F I0307 08:25:52.027320       1 available_controller.go:423] Starting AvailableConditionController
2024-03-07T09:25:52.027647095+01:00 stderr F I0307 08:25:52.027323       1 cache.go:32] Waiting for caches to sync for AvailableConditionController controller
2024-03-07T09:25:52.027648553+01:00 stderr F I0307 08:25:52.027359       1 controller.go:83] Starting OpenAPI AggregationController
2024-03-07T09:25:52.02765697+01:00 stderr F I0307 08:25:52.027407       1 handler_discovery.go:412] Starting ResourceDiscoveryManager
2024-03-07T09:25:52.027658137+01:00 stderr F I0307 08:25:52.027432       1 gc_controller.go:78] Starting apiserver lease garbage collector
2024-03-07T09:25:52.027659304+01:00 stderr F I0307 08:25:52.027496       1 customresource_discovery_controller.go:289] Starting DiscoveryController
2024-03-07T09:25:52.027755182+01:00 stderr F I0307 08:25:52.027714       1 apiservice_controller.go:97] Starting APIServiceRegistrationController
2024-03-07T09:25:52.027855478+01:00 stderr F I0307 08:25:52.027832       1 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller
2024-03-07T09:25:52.027869479+01:00 stderr F I0307 08:25:52.027862       1 system_namespaces_controller.go:67] Starting system namespaces controller
2024-03-07T09:25:52.028792764+01:00 stderr F I0307 08:25:52.027878       1 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/var/lib/rancher/rke2/server/tls/client-ca.crt"
2024-03-07T09:25:52.028799098+01:00 stderr F I0307 08:25:52.027893       1 dynamic_serving_content.go:132] "Starting controller" name="aggregator-proxy-cert::/var/lib/rancher/rke2/server/tls/client-auth-proxy.crt::/var/lib/rancher/rke2/server/tls/client-auth-proxy.key"
2024-03-07T09:25:52.028800431+01:00 stderr F I0307 08:25:52.027961       1 dynamic_cafile_content.go:157] "Starting controller" name="request-header::/var/lib/rancher/rke2/server/tls/request-header-ca.crt"
2024-03-07T09:25:52.028801431+01:00 stderr F I0307 08:25:52.028043       1 controller.go:121] Starting legacy_token_tracking_controller
2024-03-07T09:25:52.028802473+01:00 stderr F I0307 08:25:52.028050       1 shared_informer.go:311] Waiting for caches to sync for configmaps
2024-03-07T09:25:52.02880389+01:00 stderr F I0307 08:25:52.028062       1 aggregator.go:150] waiting for initial CRD sync...
2024-03-07T09:25:52.028805015+01:00 stderr F I0307 08:25:52.028470       1 controller.go:85] Starting OpenAPI controller
2024-03-07T09:25:52.028805973+01:00 stderr F I0307 08:25:52.028482       1 controller.go:85] Starting OpenAPI V3 controller
2024-03-07T09:25:52.028807473+01:00 stderr F I0307 08:25:52.028506       1 crdregistration_controller.go:111] Starting crd-autoregister controller
2024-03-07T09:25:52.028808806+01:00 stderr F I0307 08:25:52.028510       1 shared_informer.go:311] Waiting for caches to sync for crd-autoregister
2024-03-07T09:25:52.028809932+01:00 stderr F I0307 08:25:52.028541       1 crd_finalizer.go:266] Starting CRDFinalizer
2024-03-07T09:25:52.028811057+01:00 stderr F I0307 08:25:52.028560       1 naming_controller.go:291] Starting NamingConditionController
2024-03-07T09:25:52.028812182+01:00 stderr F I0307 08:25:52.028568       1 establishing_controller.go:76] Starting EstablishingController
2024-03-07T09:25:52.028813723+01:00 stderr F I0307 08:25:52.028574       1 nonstructuralschema_controller.go:192] Starting NonStructuralSchemaConditionController
2024-03-07T09:25:52.028814765+01:00 stderr F I0307 08:25:52.028579       1 apiapproval_controller.go:186] Starting KubernetesAPIApprovalPolicyConformantConditionController
2024-03-07T09:25:52.081119117+01:00 stderr F I0307 08:25:52.081063       1 shared_informer.go:318] Caches are synced for node_authorizer
2024-03-07T09:25:52.1182578+01:00 stderr F E0307 08:25:52.118197       1 controller.go:146] "Failed to ensure lease exists, will retry" err="namespaces \"kube-system\" not found" interval="200ms"
2024-03-07T09:25:52.143077716+01:00 stderr F I0307 08:25:52.142883       1 cache.go:39] Caches are synced for APIServiceRegistrationController controller
2024-03-07T09:25:52.143746867+01:00 stderr F I0307 08:25:52.143701       1 shared_informer.go:318] Caches are synced for configmaps
2024-03-07T09:25:52.143893831+01:00 stderr F I0307 08:25:52.143792       1 controller.go:624] quota admission added evaluator for: namespaces
2024-03-07T09:25:52.143962583+01:00 stderr F I0307 08:25:52.143931       1 shared_informer.go:318] Caches are synced for cluster_authentication_trust_controller
2024-03-07T09:25:52.143991751+01:00 stderr F I0307 08:25:52.143957       1 apf_controller.go:384] Running API Priority and Fairness config worker
2024-03-07T09:25:52.143993751+01:00 stderr F I0307 08:25:52.143961       1 apf_controller.go:387] Running API Priority and Fairness periodic rebalancing process
2024-03-07T09:25:52.144004418+01:00 stderr F I0307 08:25:52.143989       1 cache.go:39] Caches are synced for AvailableConditionController controller
2024-03-07T09:25:52.14401496+01:00 stderr F I0307 08:25:52.144001       1 shared_informer.go:318] Caches are synced for crd-autoregister
2024-03-07T09:25:52.144072754+01:00 stderr F I0307 08:25:52.144041       1 aggregator.go:152] initial CRD sync complete...
2024-03-07T09:25:52.144076546+01:00 stderr F I0307 08:25:52.144053       1 autoregister_controller.go:141] Starting autoregister controller
2024-03-07T09:25:52.144077879+01:00 stderr F I0307 08:25:52.144056       1 cache.go:32] Waiting for caches to sync for autoregister controller
2024-03-07T09:25:52.144079004+01:00 stderr F I0307 08:25:52.144058       1 cache.go:39] Caches are synced for autoregister controller
2024-03-07T09:25:52.323455593+01:00 stderr F I0307 08:25:52.323194       1 controller.go:624] quota admission added evaluator for: leases.coordination.k8s.io
2024-03-07T09:25:52.590182676+01:00 stderr F E0307 08:25:52.590024       1 fieldmanager.go:152] "[SHOULD NOT HAPPEN] failed to update managedFields" err="failed to convert new object (/rke2-vm; /v1, Kind=Node) to smd typed: .status.addresses: duplicate entries for key [type=\"InternalIP\"]" versionKind="/, Kind=" namespace="" name="rke2-vm"
2024-03-07T09:25:52.842452911+01:00 stderr F I0307 08:25:52.842374       1 controller.go:132] OpenAPI AggregationController: action for item k8s_internal_local_delegation_chain_0000000000: Nothing (removed from the queue).
2024-03-07T09:25:53.02951313+01:00 stderr F I0307 08:25:53.029401       1 storage_scheduling.go:95] created PriorityClass system-node-critical with value 2000001000
2024-03-07T09:25:53.032289238+01:00 stderr F I0307 08:25:53.032249       1 storage_scheduling.go:95] created PriorityClass system-cluster-critical with value 2000000000
2024-03-07T09:25:53.032295946+01:00 stderr F I0307 08:25:53.032257       1 storage_scheduling.go:111] all system priority classes are created successfully or already exist.
2024-03-07T09:25:53.257305394+01:00 stderr F I0307 08:25:53.257238       1 controller.go:624] quota admission added evaluator for: roles.rbac.authorization.k8s.io
2024-03-07T09:25:53.271701576+01:00 stderr F I0307 08:25:53.271642       1 controller.go:624] quota admission added evaluator for: rolebindings.rbac.authorization.k8s.io
2024-03-07T09:25:53.35506759+01:00 stderr F I0307 08:25:53.354888       1 alloc.go:330] "allocated clusterIPs" service="default/kubernetes" clusterIPs=map[IPv4:10.43.0.1]
2024-03-07T09:25:53.358183294+01:00 stderr F W0307 08:25:53.358083       1 lease.go:251] Resetting endpoints for master service "kubernetes" to [192.168.105.75]
2024-03-07T09:25:53.358636603+01:00 stderr F I0307 08:25:53.358581       1 controller.go:624] quota admission added evaluator for: endpoints
2024-03-07T09:25:53.360936942+01:00 stderr F I0307 08:25:53.360745       1 controller.go:624] quota admission added evaluator for: endpointslices.discovery.k8s.io
2024-03-07T09:25:53.442907402+01:00 stderr F I0307 08:25:53.442680       1 handler.go:275] Adding GroupVersion k3s.cattle.io v1 to ResourceManager
2024-03-07T09:25:53.453072837+01:00 stderr F I0307 08:25:53.452990       1 handler.go:275] Adding GroupVersion k3s.cattle.io v1 to ResourceManager
2024-03-07T09:25:53.471136535+01:00 stderr F I0307 08:25:53.471052       1 handler.go:275] Adding GroupVersion helm.cattle.io v1 to ResourceManager
2024-03-07T09:25:53.491584992+01:00 stderr F I0307 08:25:53.490235       1 handler.go:275] Adding GroupVersion helm.cattle.io v1 to ResourceManager
2024-03-07T09:25:54.573287679+01:00 stderr F I0307 08:25:54.573210       1 controller.go:624] quota admission added evaluator for: serviceaccounts
2024-03-07T09:25:56.581441253+01:00 stderr F I0307 08:25:56.581262       1 controller.go:624] quota admission added evaluator for: addons.k3s.cattle.io
2024-03-07T09:25:56.58947519+01:00 stderr F I0307 08:25:56.589351       1 controller.go:624] quota admission added evaluator for: helmcharts.helm.cattle.io
2024-03-07T09:25:58.290295711+01:00 stderr F I0307 08:25:58.290052       1 controller.go:624] quota admission added evaluator for: jobs.batch
2024-03-07T09:26:15.977653062+01:00 stderr F I0307 08:26:15.977558       1 alloc.go:330] "allocated clusterIPs" service="kube-system/rke2-coredns-rke2-coredns" clusterIPs=map[IPv4:10.43.0.10]
2024-03-07T09:26:15.979706811+01:00 stderr F I0307 08:26:15.979651       1 controller.go:624] quota admission added evaluator for: deployments.apps
2024-03-07T09:26:15.995175553+01:00 stderr F I0307 08:26:15.994335       1 controller.go:624] quota admission added evaluator for: replicasets.apps
2024-03-07T09:26:16.067754121+01:00 stderr F I0307 08:26:16.065260       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.073111794+01:00 stderr F I0307 08:26:16.072965       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.101193041+01:00 stderr F I0307 08:26:16.100230       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.445228837+01:00 stderr F I0307 08:26:16.440873       1 controller.go:624] quota admission added evaluator for: daemonsets.apps
2024-03-07T09:26:16.445266172+01:00 stderr F I0307 08:26:16.444422       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.511348814+01:00 stderr F I0307 08:26:16.511257       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.520021078+01:00 stderr F I0307 08:26:16.519496       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.805486699+01:00 stderr F I0307 08:26:16.805404       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.812682528+01:00 stderr F I0307 08:26:16.812195       1 controller.go:624] quota admission added evaluator for: controllerrevisions.apps
2024-03-07T09:26:16.818768146+01:00 stderr F I0307 08:26:16.814473       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.822198575+01:00 stderr F I0307 08:26:16.820751       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.831470029+01:00 stderr F I0307 08:26:16.831380       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.852213192+01:00 stderr F I0307 08:26:16.852109       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.864594937+01:00 stderr F I0307 08:26:16.862033       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.880357984+01:00 stderr F I0307 08:26:16.879269       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.886546356+01:00 stderr F I0307 08:26:16.885803       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.898314826+01:00 stderr F I0307 08:26:16.898206       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.90240099+01:00 stderr F I0307 08:26:16.902149       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:16.924713257+01:00 stderr F I0307 08:26:16.924549       1 handler.go:275] Adding GroupVersion crd.projectcalico.org v1 to ResourceManager
2024-03-07T09:26:47.854944905+01:00 stderr F I0307 08:26:47.854871       1 handler.go:275] Adding GroupVersion snapshot.storage.k8s.io v1 to ResourceManager
2024-03-07T09:26:47.855078577+01:00 stderr F I0307 08:26:47.855059       1 handler.go:275] Adding GroupVersion snapshot.storage.k8s.io v1beta1 to ResourceManager
2024-03-07T09:26:47.864387877+01:00 stderr F I0307 08:26:47.863334       1 handler.go:275] Adding GroupVersion snapshot.storage.k8s.io v1 to ResourceManager
2024-03-07T09:26:47.864402711+01:00 stderr F I0307 08:26:47.863350       1 handler.go:275] Adding GroupVersion snapshot.storage.k8s.io v1beta1 to ResourceManager
2024-03-07T09:26:47.876931143+01:00 stderr F I0307 08:26:47.876831       1 handler.go:275] Adding GroupVersion snapshot.storage.k8s.io v1 to ResourceManager
2024-03-07T09:26:47.87694331+01:00 stderr F I0307 08:26:47.876859       1 handler.go:275] Adding GroupVersion snapshot.storage.k8s.io v1beta1 to ResourceManager
2024-03-07T09:26:49.279998842+01:00 stderr F I0307 08:26:49.279413       1 alloc.go:330] "allocated clusterIPs" service="kube-system/rke2-snapshot-validation-webhook" clusterIPs=map[IPv4:10.43.226.185]
2024-03-07T09:26:52.461403022+01:00 stderr F I0307 08:26:52.461132       1 alloc.go:330] "allocated clusterIPs" service="kube-system/rke2-metrics-server" clusterIPs=map[IPv4:10.43.3.54]
2024-03-07T09:26:52.508074908+01:00 stderr F I0307 08:26:52.507311       1 handler.go:275] Adding GroupVersion metrics.k8s.io v1beta1 to ResourceManager
2024-03-07T09:26:52.508090283+01:00 stderr F E0307 08:26:52.507631       1 handler_proxy.go:144] error resolving kube-system/rke2-metrics-server: no endpoints available for service "rke2-metrics-server"
2024-03-07T09:26:52.519436002+01:00 stderr F I0307 08:26:52.517469       1 controller.go:624] quota admission added evaluator for: networkpolicies.networking.k8s.io
2024-03-07T09:26:53.507803076+01:00 stderr F W0307 08:26:53.507620       1 handler_proxy.go:100] no RequestInfo found in the context
2024-03-07T09:26:53.50781391+01:00 stderr F W0307 08:26:53.507698       1 handler_proxy.go:100] no RequestInfo found in the context
2024-03-07T09:26:53.507815619+01:00 stderr F E0307 08:26:53.507700       1 controller.go:116] loading OpenAPI spec for "v1beta1.metrics.k8s.io" failed with: failed to retrieve openAPI spec, http error: ResponseCode: 503, Body: service unavailable
2024-03-07T09:26:53.507816827+01:00 stderr F , Header: map[Content-Type:[text/plain; charset=utf-8] X-Content-Type-Options:[nosniff]]
2024-03-07T09:26:53.50781816+01:00 stderr F I0307 08:26:53.507710       1 controller.go:129] OpenAPI AggregationController: action for item v1beta1.metrics.k8s.io: Rate Limited Requeue.
2024-03-07T09:26:53.507819744+01:00 stderr F E0307 08:26:53.507717       1 controller.go:113] loading OpenAPI spec for "v1beta1.metrics.k8s.io" failed with: Error, could not get list of group versions for APIService
2024-03-07T09:26:53.509188509+01:00 stderr F I0307 08:26:53.508935       1 controller.go:126] OpenAPI AggregationController: action for item v1beta1.metrics.k8s.io: Rate Limited Requeue.
2024-03-07T09:27:01.983088384+01:00 stderr F I0307 08:27:01.982994       1 alloc.go:330] "allocated clusterIPs" service="kube-system/rke2-ingress-nginx-controller-admission" clusterIPs=map[IPv4:10.43.164.114]
2024-03-07T09:27:22.892596796+01:00 stderr F I0307 08:27:22.880964       1 handler.go:275] Adding GroupVersion metrics.k8s.io v1beta1 to ResourceManager
JCzz commented 8 months ago

I had it running while attending a meeting(30 min.) Now it is running?

brandond commented 8 months ago

sounds like your VM is just slow?

JCzz commented 8 months ago

That is definitely plausible, but I can install Kubernetes plain vanilla one-tenth of the time on same vm. Anyways I runs. Thanks

brandond commented 8 months ago

RKE2 isn't the most lightweight of distros. If you're looking for something that works almost exactly the same as rke2 but comes up quickly, you might give k3s a try.