kubelet do not restart kube-apiserver #7616

chenyuanrun · 2025-01-17T04:41:24Z

chenyuanrun
Jan 17, 2025

Environmental Info:
RKE2 Version:
rke2 version v1.30.5+rke2r1 (0c83bc8)
go version go1.22.6 X:boringcrypto

Node(s) CPU architecture, OS, and Version:
Linux node90 5.14.0-427.18.1.el9_4.x86_64 #1 SMP PREEMPT_DYNAMIC Mon May 27 16:35:12 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux

Cluster Configuration:
3 servers, using docker(with cri-docker) as container runtime.

NAME     STATUS     ROLES                       AGE   VERSION
node90   NotReady   control-plane,etcd,master   20h   v1.30.5+rke2r1
node91   Ready      control-plane,etcd,master   20h   v1.30.5+rke2r1
node92   Ready      control-plane,etcd,master   20h   v1.30.5+rke2r1

basic config file:

node-ip: 192.168.99.90
token: deadbeef
tls-san:
  - 192.168.99.100
container-runtime-endpoint: /var/run/cri-dockerd.sock
etcd-arg:
  - heartbeat-interval=1000
  - election-timeout=10000

Describe the bug:

apiserver(as a static pod, running in docker container) is down, but kubelet do not restart it;

Steps To Reproduce:

Installed RKE2:
Can not reproduce this bug.

Expected behavior:

kubelet restart apiserver while apiserver is down;

Actual behavior:

kubelet do not restart apiserver;

Additional context / logs:

kubelet known that apiserver is down, but do not retry to restart it:

E0116 20:20:53.051102 2050705 controller.go:195] "Failed to update lease" err="Put \"https://127.0.0.1:6443/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/node90?timeout=10s\": net/http: request canceled (Client.Timeout exceeded while awaiting headers)"
I0116 20:20:56.800654 2050705 status_manager.go:853] "Failed to get status for pod" podUID="575f511fdeaaf4b3262637b443848b04" pod="kube-system/kube-apiserver-node90" err="etcdserver: request timed out"
W0116 20:20:57.950715 2050705 transport.go:356] Unable to cancel request for *otelhttp.Transport
E0116 20:20:57.950945 2050705 kubelet_node_status.go:544] "Error updating node status, will retry" err="error getting node \"node90\": Get \"https://127.0.0.1:6443/api/v1/nodes/node90?timeout=10s\": net/http: request canceled (Client.Timeout exceeded while awaiting headers)"
W0116 20:21:03.051999 2050705 transport.go:356] Unable to cancel request for *otelhttp.Transport
E0116 20:21:03.052161 2050705 controller.go:195] "Failed to update lease" err="Put \"https://127.0.0.1:6443/apis/coordination.k8s.io/v1/namespaces/kube-node-lease/leases/node90?timeout=10s\": net/http: request canceled (Client.Timeout exceeded while awaiting headers)"
I0116 20:21:03.052200 2050705 controller.go:115] "failed to update lease using latest lease, fallback to ensure lease" err="failed 5 attempts to update lease"
W0116 20:21:07.951547 2050705 transport.go:356] Unable to cancel request for *otelhttp.Transport
E0116 20:21:07.951738 2050705 kubelet_node_status.go:544] "Error updating node status, will retry" err="error getting node \"node90\": Get \"https://127.0.0.1:6443/api/v1/nodes/node90?timeout=10s\": net/http: request canceled (Client.Timeout exceeded while awaiting headers)"
E0116 20:21:11.264596 2050705 event.go:359] "Server rejected event (will not retry!)" err="Timeout: request did not complete within requested timeout - context deadline exceeded" event=<
        &Event{ObjectMeta:{kube-apiserver-node90.181b45c9525f7bb0  kube-system    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] [] []},InvolvedObject:ObjectReference{Kind:Pod,Namespace:kube-system,Name:kube-apiserver-node90,UID:575f511fdeaaf4b3262637b443848b04,APIVersion:v1,ResourceVersion:,FieldPath:spec.containers{kube-apiserver},},Reason:Unhealthy,Message:Readiness probe failed: Error from server (InternalError): an error on the server ("[+]ping ok\n[+]log ok\n[-]etcd failed: reason withheld\n[-]etcd-readiness failed: reason withheld\n[+]kms-providers ok\n[+]informer-sync ok\n[+]poststarthook/start-encryption-provider-config-automatic-reload ok\n[+]poststarthook/start-apiserver-admission-initializer ok\n[+]poststarthook/generic-apiserver-start-informers ok\n[+]poststarthook/priority-and-fairness-config-consumer ok\n[+]poststarthook/priority-and-fairness-filter ok\n[+]poststarthook/storage-object-count-tracker-hook ok\n[+]poststarthook/start-apiextensions-informers ok\n[+]poststarthook/start-apiextensions-controllers ok\n[+]poststarthook/crd-informer-synced ok\n[+]poststarthook/start-service-ip-repair-controllers ok\n[+]poststarthook/rbac/bootstrap-roles ok\n[+]poststarthook/scheduling/bootstrap-system-priority-classes ok\n[+]poststarthook/priority-and-fairness-config-producer ok\n[+]poststarthook/start-system-namespaces-controller ok\n[+]poststarthook/bootstrap-controller ok\n[+]poststarthook/start-cluster-authentication-info-controller ok\n[+]poststarthook/start-kube-apiserver-identity-lease-controller ok\n[+]poststarthook/start-kube-apiserver-identity-lease-garbage-collector ok\n[+]poststarthook/start-legacy-token-tracking-controller ok\n[+]poststarthook/aggregator-reload-proxy-client-cert ok\n[+]poststarthook/start-kube-aggregator-informers ok\n[+]poststarthook/apiservice-registration-controller ok\n[+]poststarthook/apiservice-status-available-controller ok\n[+]poststarthook/apiservice-discovery-controller ok\n[+]poststarthook/kube-apiserver-autoregistration ok\n[+]autoregister-completion ok\n[+]poststarthook/apiservice-openapi-controller ok\n[+]poststarthook/apiservice-openapiv3-controller ok\n[+]shutdown ok\nreadyz check failed") has prevented the request from succeeding
        ,Source:EventSource{Component:kubelet,Host:node90,},FirstTimestamp:2025-01-16 20:20:12.254190512 +0000 UTC m=+3353.300980686,LastTimestamp:2025-01-16 20:20:17.240511839 +0000 UTC m=+3358.287302030,Count:2,Type:Warning,EventTime:0001-01-01 00:00:00 +0000 UTC,Series:nil,Action:,Related:nil,ReportingController:kubelet,ReportingInstance:node90,}
 >
W0116 20:21:13.053389 2050705 transport.go:356] Unable to cancel request for *otelhttp.Transport

apiserver.log
kubelet.log
rke2-server.log

Answered by chenyuanrun

Jan 17, 2025

For anyone facing my problem, check if you have a dead nfs(or other network filesystem) mount in your node, try to umount it (umount -f /PATH or umount -f -l /PATH), and check if your kubelet run as expected.

I do not if this is a bug or this is desired, I hope the rke2 developer may notice this problem. If this is not a but, just close this issue.

View full answer

chenyuanrun · 2025-01-17T04:43:50Z

chenyuanrun
Jan 17, 2025
Author

kube-apiserver is always down:

# docker ps -a | grep apiserver
f55be3295bb8   e0d7e579b2a7                 "kube-apiserver --ad…"     9 hours ago    Exited (137) 8 hours ago              k8s_kube-apiserver_kube-apiserver-node90_kube-system_575f511fdeaaf4b3262637b443848b04_3
993f4cf78ce1   e0d7e579b2a7                 "kube-apiserver --ad…"     21 hours ago   Exited (137) 9 hours ago              k8s_kube-apiserver_kube-apiserver-node90_kube-system_575f511fdeaaf4b3262637b443848b04_2
8d51c6658bdb   rancher/mirrored-pause:3.6   "/pause"                   21 hours ago   Up 21 hours                           k8s_POD_kube-apiserver-node90_kube-system_575f511fdeaaf4b3262637b443848b04_1

etcd is fine:

# docker ps -a | grep etcd
c054501b2437   19f8e656ed90                 "etcd --config-file=…"     21 hours ago   Up 21 hours                           k8s_etcd_etcd-node90_kube-system_2f3899b6569aea71f6a61fbefbadf0cd_1
fcc854350ea3   rancher/mirrored-pause:3.6   "/pause"                   21 hours ago   Up 21 hours                           k8s_POD_etcd-node90_kube-system_2f3899b6569aea71f6a61fbefbadf0cd_1

rke2-server and kubelet is also running, but waiting for API server to become available:

# systemctl status rke2-server
● rke2-server.service - Rancher Kubernetes Engine v2 (server)
     Loaded: loaded (/usr/local/lib/systemd/system/rke2-server.service; enabled; preset: disabled)
    Drop-In: /etc/systemd/system/rke2-server.service.d
             └─override.conf
     Active: activating (start) since Fri 2025-01-17 04:40:49 UTC; 2min 24s ago
       Docs: https://github.com/rancher/rke2#readme
    Process: 3242145 ExecStartPre=/bin/sh -xc ! /usr/bin/systemctl is-enabled --quiet nm-cloud-setup.service (code=exited, status=0/SUCCESS)
    Process: 3242147 ExecStartPre=/sbin/modprobe br_netfilter (code=exited, status=0/SUCCESS)
    Process: 3242148 ExecStartPre=/sbin/modprobe overlay (code=exited, status=0/SUCCESS)
   Main PID: 3242149 (rke2)
      Tasks: 27
     Memory: 160.3M
        CPU: 3min 8.808s
     CGroup: /system.slice/rke2-server.service
             ├─3242149 "/usr/local/bin/rke2 server"
             └─3242695 kubelet --volume-plugin-dir=/var/lib/kubelet/volumeplugins --file-check-frequency=5s --sync-frequency=30s --address=0.0.0.0 --anonymous-auth=false --authentication-token-webhook=true --authorization-mode=Webhook --cgroup-driver=cgroupfs --client-ca-file=/var/lib/rancher/rke2/agent/client-ca.crt --cloud-provider=external --cluster-dns=1>

Jan 17 04:41:05 node90 rke2[3242149]: time="2025-01-17T04:41:05Z" level=info msg="Running kube-proxy --cluster-cidr=10.42.0.0/16 --conntrack-max-per-core=0 --conntrack-tcp-timeout-close-wait=0s --conntrack-tcp-timeout-established=0s --healthz-bind-address=127.0.0.1 --hostname-override=node90 --kubeconfig=/var/lib/rancher/rke2/agent/kubeproxy.kubeconfig --pro>
Jan 17 04:41:33 node90 rke2[3242149]: time="2025-01-17T04:41:33Z" level=info msg="Waiting for API server to become available"
Jan 17 04:41:33 node90 rke2[3242149]: time="2025-01-17T04:41:33Z" level=info msg="Waiting for API server to become available"
Jan 17 04:42:03 node90 rke2[3242149]: time="2025-01-17T04:42:03Z" level=info msg="Waiting for API server to become available"
Jan 17 04:42:03 node90 rke2[3242149]: time="2025-01-17T04:42:03Z" level=info msg="Waiting for API server to become available"
Jan 17 04:42:33 node90 rke2[3242149]: time="2025-01-17T04:42:33Z" level=info msg="Waiting for API server to become available"
Jan 17 04:42:33 node90 rke2[3242149]: 2025/01/17 04:42:33 ERROR: [transport] Client received GoAway with error code ENHANCE_YOUR_CALM and debug data equal to ASCII "too_many_pings".
Jan 17 04:42:33 node90 rke2[3242149]: time="2025-01-17T04:42:33Z" level=info msg="Waiting for API server to become available"
Jan 17 04:43:03 node90 rke2[3242149]: time="2025-01-17T04:43:03Z" level=info msg="Waiting for API server to become available"
Jan 17 04:43:03 node90 rke2[3242149]: time="2025-01-17T04:43:03Z" level=info msg="Waiting for API server to become available"

0 replies

chenyuanrun · 2025-01-17T04:45:28Z

chenyuanrun
Jan 17, 2025
Author

May relate to this upstream k8s bug, but I am not sure: kubernetes/kubernetes#105543

0 replies

chenyuanrun · 2025-01-17T04:48:07Z

chenyuanrun
Jan 17, 2025
Author

etcd is running:

# etcdctl member list
b014b767723c214, started, node92-3852b531, https://192.168.99.92:2380, https://192.168.99.92:2379, false
dc6ba2177dfb32ef, started, node91-70449c1c, https://192.168.99.91:2380, https://192.168.99.91:2379, false
e5d5789c8b00cba5, started, node90-50f1414f, https://192.168.99.90:2380, https://192.168.99.90:2379, false

0 replies

chenyuanrun · 2025-01-17T05:00:57Z

chenyuanrun
Jan 17, 2025
Author

restart kubelet do not fix this problem, and kubelet stuck on "Starting controller":

W0117 04:56:22.631421 3274131 feature_gate.go:246] Setting GA feature gate CloudDualStackNodeIPs=true. It will be removed in a future release.
W0117 04:56:22.631798 3274131 feature_gate.go:246] Setting GA feature gate CloudDualStackNodeIPs=true. It will be removed in a future release.
I0117 04:56:22.639251 3274131 server.go:484] "Kubelet version" kubeletVersion="v1.30.5+rke2r1"
I0117 04:56:22.639307 3274131 server.go:486] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
W0117 04:56:22.639476 3274131 feature_gate.go:246] Setting GA feature gate CloudDualStackNodeIPs=true. It will be removed in a future release.
W0117 04:56:22.639621 3274131 feature_gate.go:246] Setting GA feature gate CloudDualStackNodeIPs=true. It will be removed in a future release.
I0117 04:56:22.649881 3274131 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/var/lib/rancher/rke2/agent/client-ca.crt"

0 replies

chenyuanrun · 2025-01-17T05:04:57Z

chenyuanrun
Jan 17, 2025
Author

restart rke2-server do not fix this problem:

Jan 17 05:02:12 node90 rke2[3285824]: time="2025-01-17T05:02:12Z" level=info msg="Server node token is available at /var/lib/rancher/rke2/server/token"
Jan 17 05:02:12 node90 rke2[3285824]: time="2025-01-17T05:02:12Z" level=info msg="To join server node to cluster: rke2 server -s https://192.168.99.90:9345 -t ${SERVER_NODE_TOKEN}"
Jan 17 05:02:12 node90 rke2[3285824]: time="2025-01-17T05:02:12Z" level=info msg="Agent node token is available at /var/lib/rancher/rke2/server/agent-token"
Jan 17 05:02:12 node90 rke2[3285824]: time="2025-01-17T05:02:12Z" level=info msg="To join agent node to cluster: rke2 agent -s https://192.168.99.90:9345 -t ${AGENT_NODE_TOKEN}"
Jan 17 05:02:12 node90 rke2[3285824]: time="2025-01-17T05:02:12Z" level=info msg="Wrote kubeconfig /etc/rancher/rke2/rke2.yaml"
Jan 17 05:02:12 node90 rke2[3285824]: time="2025-01-17T05:02:12Z" level=info msg="Run: rke2 kubectl"
Jan 17 05:02:12 node90 rke2[3285824]: time="2025-01-17T05:02:12Z" level=info msg="Pod for etcd is synced"
Jan 17 05:02:12 node90 rke2[3285824]: time="2025-01-17T05:02:12Z" level=info msg="etcd data store connection OK"
Jan 17 05:02:12 node90 rke2[3285824]: time="2025-01-17T05:02:12Z" level=info msg="Saving cluster bootstrap data to datastore"
Jan 17 05:02:12 node90 rke2[3285824]: time="2025-01-17T05:02:12Z" level=info msg="Waiting for API server to become available"
Jan 17 05:02:12 node90 rke2[3285824]: time="2025-01-17T05:02:12Z" level=warning msg="Bootstrap key already exists"
Jan 17 05:02:13 node90 rke2[3285824]: time="2025-01-17T05:02:13Z" level=info msg="Password verified locally for node node90"
Jan 17 05:02:13 node90 rke2[3285824]: time="2025-01-17T05:02:13Z" level=info msg="certificate CN=node90 signed by CN=rke2-server-ca@1737011168: notBefore=2025-01-16 07:06:12 +0000 UTC notAfter=2124-12-24 05:02:13 +0000 UTC"
Jan 17 05:02:13 node90 rke2[3285824]: time="2025-01-17T05:02:13Z" level=info msg="certificate CN=system:node:node90,O=system:nodes signed by CN=rke2-client-ca@1737011168: notBefore=2025-01-16 07:06:12 +0000 UTC notAfter=2124-12-24 05:02:13 +0000 UTC"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Module overlay was already loaded"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Module nf_conntrack was already loaded"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Module br_netfilter was already loaded"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Module iptable_nat was already loaded"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Module iptable_filter was already loaded"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Runtime image index.docker.io/rancher/rke2-runtime:v1.30.5-rke2r1 bin and charts directories already exist; skipping extract"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/harvester-csi-driver.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-flannel.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-traefik-crd.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-snapshot-validation-webhook.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/harvester-cloud-provider.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rancher-vsphere-cpi.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-metrics-server.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-multus.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-snapshot-controller.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rancher-vsphere-csi.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-canal.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-ingress-nginx.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-snapshot-controller-crd.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-traefik.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-calico-crd.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-calico.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-cilium.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-coredns.yaml to set cluster configuration values"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Connecting to proxy" url="wss://127.0.0.1:9345/v1-rke2/connect"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Creating rke2-cert-monitor event broadcaster"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Running kubelet --address=0.0.0.0 --alsologtostderr=false --anonymous-auth=false --authentication-token-webhook=true --authorization-mode=Webhook --cgroup-driver=cgroupfs --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:///var/run/cri-dockerd.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=node90 --image-service-endpoint=unix:///var/run/cri-dockerd.sock --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.99.90 --node-labels= --pod-manifest-path=/var/lib/rancher/rke2/agent/pod-manifests --read-only-port=0 --resolv-conf=/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"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Handling backend connection request [node90]"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Remotedialer connected to proxy" url="wss://127.0.0.1:9345/v1-rke2/connect"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=error msg="Sending HTTP 503 response to 127.0.0.1:45728: runtime core not ready"
Jan 17 05:02:14 node90 rke2[3285824]: time="2025-01-17T05:02:14Z" level=info msg="Running kube-proxy --cluster-cidr=10.42.0.0/16 --conntrack-max-per-core=0 --conntrack-tcp-timeout-close-wait=0s --conntrack-tcp-timeout-established=0s --healthz-bind-address=127.0.0.1 --hostname-override=node90 --kubeconfig=/var/lib/rancher/rke2/agent/kubeproxy.kubeconfig --proxy-mode=iptables"
Jan 17 05:02:42 node90 rke2[3285824]: time="2025-01-17T05:02:42Z" level=info msg="Waiting for API server to become available"
Jan 17 05:02:42 node90 rke2[3285824]: time="2025-01-17T05:02:42Z" level=info msg="Waiting for API server to become available"
Jan 17 05:03:12 node90 rke2[3285824]: time="2025-01-17T05:03:12Z" level=info msg="Waiting for API server to become available"
Jan 17 05:03:12 node90 rke2[3285824]: time="2025-01-17T05:03:12Z" level=info msg="Waiting for API server to become available"
Jan 17 05:03:42 node90 rke2[3285824]: time="2025-01-17T05:03:42Z" level=info msg="Waiting for API server to become available"
Jan 17 05:03:42 node90 rke2[3285824]: 2025/01/17 05:03:42 ERROR: [transport] Client received GoAway with error code ENHANCE_YOUR_CALM and debug data equal to ASCII "too_many_pings".
Jan 17 05:03:42 node90 rke2[3285824]: time="2025-01-17T05:03:42Z" level=info msg="Waiting for API server to become available"
Jan 17 05:04:12 node90 rke2[3285824]: time="2025-01-17T05:04:12Z" level=info msg="Waiting for API server to become available"
Jan 17 05:04:12 node90 rke2[3285824]: time="2025-01-17T05:04:12Z" level=info msg="Waiting for API server to become available"
Jan 17 05:04:42 node90 rke2[3285824]: time="2025-01-17T05:04:42Z" level=info msg="Waiting for API server to become available"
Jan 17 05:04:42 node90 rke2[3285824]: time="2025-01-17T05:04:42Z" level=info msg="Waiting for API server to become available"

0 replies

chenyuanrun · 2025-01-17T05:09:15Z

chenyuanrun
Jan 17, 2025
Author

restart cri-docker do not fix.

0 replies

chenyuanrun · 2025-01-17T05:10:27Z

chenyuanrun
Jan 17, 2025
Author

delete the pause container of apiserver do not fix.

0 replies

chenyuanrun · 2025-01-17T05:24:55Z

chenyuanrun
Jan 17, 2025
Author

restart docker and then restart rke2-server do not fix, now all docker container is down and rke2-server is waiting for multiple services:

# docker ps
CONTAINER ID   IMAGE     COMMAND   CREATED   STATUS    PORTS     NAMES

Jan 17 05:20:34 node90 rke2[3326114]: time="2025-01-17T05:20:34Z" level=info msg="Server node token is available at /var/lib/rancher/rke2/server/token"
Jan 17 05:20:34 node90 rke2[3326114]: time="2025-01-17T05:20:34Z" level=info msg="To join server node to cluster: rke2 server -s https://192.168.99.90:9345 -t ${SERVER_NODE_TOKEN}"
Jan 17 05:20:34 node90 rke2[3326114]: time="2025-01-17T05:20:34Z" level=info msg="Agent node token is available at /var/lib/rancher/rke2/server/agent-token"
Jan 17 05:20:34 node90 rke2[3326114]: time="2025-01-17T05:20:34Z" level=info msg="To join agent node to cluster: rke2 agent -s https://192.168.99.90:9345 -t ${AGENT_NODE_TOKEN}"
Jan 17 05:20:34 node90 rke2[3326114]: time="2025-01-17T05:20:34Z" level=info msg="Wrote kubeconfig /etc/rancher/rke2/rke2.yaml"
Jan 17 05:20:34 node90 rke2[3326114]: time="2025-01-17T05:20:34Z" level=info msg="Run: rke2 kubectl"
Jan 17 05:20:34 node90 rke2[3326114]: time="2025-01-17T05:20:34Z" level=info msg="Pod for etcd not synced (pod sandbox not found), retrying"
Jan 17 05:20:35 node90 rke2[3326114]: time="2025-01-17T05:20:35Z" level=info msg="Password verified locally for node node90"
Jan 17 05:20:35 node90 rke2[3326114]: time="2025-01-17T05:20:35Z" level=info msg="certificate CN=node90 signed by CN=rke2-server-ca@1737011168: notBefore=2025-01-16 07:06:12 +0000 UTC notAfter=2124-12-24 05:20:35 +0000 UTC"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="certificate CN=system:node:node90,O=system:nodes signed by CN=rke2-client-ca@1737011168: notBefore=2025-01-16 07:06:12 +0000 UTC notAfter=2124-12-24 05:20:36 +0000 UTC"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Module overlay was already loaded"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Module nf_conntrack was already loaded"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Module br_netfilter was already loaded"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Module iptable_nat was already loaded"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Module iptable_filter was already loaded"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Runtime image index.docker.io/rancher/rke2-runtime:v1.30.5-rke2r1 bin and charts directories already exist; skipping extract"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rancher-vsphere-cpi.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-calico.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-snapshot-controller-crd.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/harvester-cloud-provider.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-calico-crd.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-cilium.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-coredns.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-metrics-server.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-traefik-crd.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-traefik.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/harvester-csi-driver.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rancher-vsphere-csi.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-canal.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-multus.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-snapshot-controller.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-flannel.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-ingress-nginx.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Updated manifest /var/lib/rancher/rke2/server/manifests/rke2-snapshot-validation-webhook.yaml to set cluster configuration values"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Connecting to proxy" url="wss://127.0.0.1:9345/v1-rke2/connect"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Creating rke2-cert-monitor event broadcaster"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Running kubelet --address=0.0.0.0 --alsologtostderr=false --anonymous-auth=false --authentication-token-webhook=true --authorization-mode=Webhook --cgroup-driver=cgroupfs --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:///var/run/cri-dockerd.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=node90 --image-service-endpoint=unix:///var/run/cri-dockerd.sock --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.99.90 --node-labels= --pod-manifest-path=/var/lib/rancher/rke2/agent/pod-manifests --read-only-port=0 --resolv-conf=/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"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Handling backend connection request [node90]"
Jan 17 05:20:36 node90 rke2[3326114]: time="2025-01-17T05:20:36Z" level=info msg="Remotedialer connected to proxy" url="wss://127.0.0.1:9345/v1-rke2/connect"
Jan 17 05:20:37 node90 rke2[3326114]: time="2025-01-17T05:20:37Z" level=error msg="Sending HTTP 503 response to 127.0.0.1:42256: runtime core not ready"
Jan 17 05:20:37 node90 rke2[3326114]: time="2025-01-17T05:20:37Z" level=info msg="Running kube-proxy --cluster-cidr=10.42.0.0/16 --conntrack-max-per-core=0 --conntrack-tcp-timeout-close-wait=0s --conntrack-tcp-timeout-established=0s --healthz-bind-address=127.0.0.1 --hostname-override=node90 --kubeconfig=/var/lib/rancher/rke2/agent/kubeproxy.kubeconfig --proxy-mode=iptables"
Jan 17 05:20:54 node90 rke2[3326114]: time="2025-01-17T05:20:54Z" level=info msg="Pod for etcd not synced (pod sandbox not found), retrying"
Jan 17 05:21:04 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:21:04.494423Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:21:04 node90 rke2[3326114]: time="2025-01-17T05:21:04Z" level=info msg="Failed to test data store connection: context deadline exceeded"
Jan 17 05:21:04 node90 rke2[3326114]: time="2025-01-17T05:21:04Z" level=info msg="Waiting for etcd server to become available"
Jan 17 05:21:04 node90 rke2[3326114]: time="2025-01-17T05:21:04Z" level=info msg="Waiting for API server to become available"
Jan 17 05:21:06 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:21:06.860561Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:21:06 node90 rke2[3326114]: time="2025-01-17T05:21:06Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:21:14 node90 rke2[3326114]: time="2025-01-17T05:21:14Z" level=info msg="Pod for etcd not synced (pod sandbox not found), retrying"
Jan 17 05:21:21 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:21:21.861005Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:21:21 node90 rke2[3326114]: time="2025-01-17T05:21:21Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:21:34 node90 rke2[3326114]: time="2025-01-17T05:21:34Z" level=info msg="Waiting for etcd server to become available"
Jan 17 05:21:34 node90 rke2[3326114]: time="2025-01-17T05:21:34Z" level=info msg="Waiting for API server to become available"
Jan 17 05:21:34 node90 rke2[3326114]: time="2025-01-17T05:21:34Z" level=info msg="Pod for etcd not synced (pod sandbox not found), retrying"
Jan 17 05:21:36 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:21:36.861486Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:21:36 node90 rke2[3326114]: time="2025-01-17T05:21:36Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:21:39 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:21:39.494972Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:21:39 node90 rke2[3326114]: time="2025-01-17T05:21:39Z" level=info msg="Failed to test data store connection: context deadline exceeded"
Jan 17 05:21:51 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:21:51.8619Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:21:51 node90 rke2[3326114]: time="2025-01-17T05:21:51Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:21:54 node90 rke2[3326114]: time="2025-01-17T05:21:54Z" level=info msg="Pod for etcd not synced (pod sandbox not found), retrying"
Jan 17 05:22:04 node90 rke2[3326114]: time="2025-01-17T05:22:04Z" level=info msg="Waiting for etcd server to become available"
Jan 17 05:22:04 node90 rke2[3326114]: time="2025-01-17T05:22:04Z" level=info msg="Waiting for API server to become available"
Jan 17 05:22:06 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:22:06.862313Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:22:06 node90 rke2[3326114]: time="2025-01-17T05:22:06Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:22:14 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:22:14.49529Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:22:14 node90 rke2[3326114]: time="2025-01-17T05:22:14Z" level=info msg="Failed to test data store connection: context deadline exceeded"
Jan 17 05:22:14 node90 rke2[3326114]: time="2025-01-17T05:22:14Z" level=info msg="Pod for etcd not synced (pod sandbox not found), retrying"
Jan 17 05:22:21 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:22:21.862775Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:22:21 node90 rke2[3326114]: time="2025-01-17T05:22:21Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:22:34 node90 rke2[3326114]: time="2025-01-17T05:22:34Z" level=info msg="Waiting for etcd server to become available"
Jan 17 05:22:34 node90 rke2[3326114]: time="2025-01-17T05:22:34Z" level=info msg="Waiting for API server to become available"
Jan 17 05:22:34 node90 rke2[3326114]: time="2025-01-17T05:22:34Z" level=info msg="Pod for etcd not synced (pod sandbox not found), retrying"
Jan 17 05:22:36 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:22:36.863369Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:22:36 node90 rke2[3326114]: time="2025-01-17T05:22:36Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:22:49 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:22:49.495622Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:22:49 node90 rke2[3326114]: time="2025-01-17T05:22:49Z" level=info msg="Failed to test data store connection: context deadline exceeded"
Jan 17 05:22:51 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:22:51.863761Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:22:51 node90 rke2[3326114]: time="2025-01-17T05:22:51Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:22:54 node90 rke2[3326114]: time="2025-01-17T05:22:54Z" level=info msg="Pod for etcd not synced (pod sandbox not found), retrying"
Jan 17 05:23:04 node90 rke2[3326114]: time="2025-01-17T05:23:04Z" level=info msg="Waiting for etcd server to become available"
Jan 17 05:23:04 node90 rke2[3326114]: time="2025-01-17T05:23:04Z" level=info msg="Waiting for API server to become available"
Jan 17 05:23:06 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:23:06.864125Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:23:06 node90 rke2[3326114]: time="2025-01-17T05:23:06Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:23:14 node90 rke2[3326114]: time="2025-01-17T05:23:14Z" level=info msg="Pod for etcd not synced (pod sandbox not found), retrying"
Jan 17 05:23:21 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:23:21.864374Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:23:21 node90 rke2[3326114]: time="2025-01-17T05:23:21Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:23:24 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:23:24.495989Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:23:24 node90 rke2[3326114]: time="2025-01-17T05:23:24Z" level=info msg="Failed to test data store connection: context deadline exceeded"
Jan 17 05:23:34 node90 rke2[3326114]: time="2025-01-17T05:23:34Z" level=info msg="Waiting for etcd server to become available"
Jan 17 05:23:34 node90 rke2[3326114]: time="2025-01-17T05:23:34Z" level=info msg="Waiting for API server to become available"
Jan 17 05:23:34 node90 rke2[3326114]: time="2025-01-17T05:23:34Z" level=info msg="Pod for etcd not synced (pod sandbox not found), retrying"
Jan 17 05:23:36 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:23:36.864685Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:23:36 node90 rke2[3326114]: time="2025-01-17T05:23:36Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:23:51 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:23:51.86517Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:23:51 node90 rke2[3326114]: time="2025-01-17T05:23:51Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:23:54 node90 rke2[3326114]: time="2025-01-17T05:23:54Z" level=info msg="Pod for etcd not synced (pod sandbox not found), retrying"
Jan 17 05:23:59 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:23:59.49634Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:23:59 node90 rke2[3326114]: time="2025-01-17T05:23:59Z" level=info msg="Failed to test data store connection: context deadline exceeded"
Jan 17 05:24:04 node90 rke2[3326114]: time="2025-01-17T05:24:04Z" level=info msg="Waiting for etcd server to become available"
Jan 17 05:24:04 node90 rke2[3326114]: time="2025-01-17T05:24:04Z" level=info msg="Waiting for API server to become available"
Jan 17 05:24:06 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:24:06.865495Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:24:06 node90 rke2[3326114]: time="2025-01-17T05:24:06Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:24:14 node90 rke2[3326114]: time="2025-01-17T05:24:14Z" level=info msg="Pod for etcd not synced (pod sandbox not found), retrying"
Jan 17 05:24:21 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:24:21.865775Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:24:21 node90 rke2[3326114]: time="2025-01-17T05:24:21Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"
Jan 17 05:24:34 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:24:34.496955Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:24:34 node90 rke2[3326114]: time="2025-01-17T05:24:34Z" level=info msg="Failed to test data store connection: context deadline exceeded"
Jan 17 05:24:34 node90 rke2[3326114]: time="2025-01-17T05:24:34Z" level=info msg="Waiting for etcd server to become available"
Jan 17 05:24:34 node90 rke2[3326114]: time="2025-01-17T05:24:34Z" level=info msg="Waiting for API server to become available"
Jan 17 05:24:34 node90 rke2[3326114]: time="2025-01-17T05:24:34Z" level=info msg="Pod for etcd not synced (pod sandbox not found), retrying"
Jan 17 05:24:36 node90 rke2[3326114]: {"level":"warn","ts":"2025-01-17T05:24:36.866109Z","logger":"etcd-client","caller":"v3@v3.5.13-k3s1/retry_interceptor.go:62","msg":"retrying of unary invoker failed","target":"etcd-endpoints://0xc002bb65a0/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\""}
Jan 17 05:24:36 node90 rke2[3326114]: time="2025-01-17T05:24:36Z" level=error msg="Failed to check local etcd status for learner management: context deadline exceeded"

0 replies

chenyuanrun · 2025-01-17T05:35:12Z

chenyuanrun
Jan 17, 2025
Author

This node has a dead nfs mount, force umount it and kubelet run as expected, kube-apiserver is started successfully.

0 replies

chenyuanrun · 2025-01-17T05:38:16Z

chenyuanrun
Jan 17, 2025
Author

For anyone facing my problem, check if you have a dead nfs(or other network filesystem) mount in your node, try to umount it (umount -f /PATH or umount -f -l /PATH), and check if your kubelet run as expected.

I do not if this is a bug or this is desired, I hope the rke2 developer may notice this problem. If this is not a but, just close this issue.

0 replies

brandond · 2025-01-17T05:39:52Z

brandond
Jan 17, 2025
Maintainer

We do not test or support rke2 with the docker container runtime. You're welcome to use it (or any other CRI implementation) but we don't support it.

Why are you trying to use docker/cri-dockerd in the first place?

0 replies

chenyuanrun · 2025-01-17T05:45:56Z

chenyuanrun
Jan 17, 2025
Author

@brandond
We need docker to build and test our image/container, we have tried rke2's builtin containerd and nerdctl/buildkit, but if rke2 is down, the builtin containerd is also down, which make we hard to debug the container.

And all of us are familier with docker instead of cri/containerd, some of our applications are deployed directly to docker but not k8s.

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

kubelet do not restart kube-apiserver #7616

{{title}}

Replies: 12 comments

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Select a reply

kubelet do not restart kube-apiserver #7616

chenyuanrun Jan 17, 2025

Replies: 12 comments

chenyuanrun Jan 17, 2025 Author

chenyuanrun Jan 17, 2025 Author

chenyuanrun Jan 17, 2025 Author

chenyuanrun Jan 17, 2025 Author

chenyuanrun Jan 17, 2025 Author

chenyuanrun Jan 17, 2025 Author

chenyuanrun Jan 17, 2025 Author

chenyuanrun Jan 17, 2025 Author

chenyuanrun Jan 17, 2025 Author

chenyuanrun Jan 17, 2025 Author

brandond Jan 17, 2025 Maintainer

chenyuanrun Jan 17, 2025 Author

chenyuanrun
Jan 17, 2025

chenyuanrun
Jan 17, 2025
Author

chenyuanrun
Jan 17, 2025
Author

chenyuanrun
Jan 17, 2025
Author

chenyuanrun
Jan 17, 2025
Author

chenyuanrun
Jan 17, 2025
Author

chenyuanrun
Jan 17, 2025
Author

chenyuanrun
Jan 17, 2025
Author

chenyuanrun
Jan 17, 2025
Author

chenyuanrun
Jan 17, 2025
Author

chenyuanrun
Jan 17, 2025
Author

brandond
Jan 17, 2025
Maintainer

chenyuanrun
Jan 17, 2025
Author