Core DNS missing NodeHosts key in Configmap

When deploying latest k3s version v1.29.0+k3s1 the coredns pod is stuck in ContainerCreating stage as it cannot find the key NodeHosts in configmap coredns. When looking at the manifests definitions, it looks the problem is real.
Upon searching k3s documentation there is no mention of how to specify those NodeHosts without manually editing configmap after deployment.
Error:
Warning  FailedMount  85s (x19 over 23m)  kubelet            MountVolume.SetUp failed for volume "config-volume" : configmap references non-existent config key: NodeHosts
Manifests Link:
https://github.com/k3s-io/k3s/blob/master/manifests/coredns.yaml

The NodeHosts key is maintained by a controller that runs in the k3s server process. It ensures that the key exists, and contains an entry for every node in the cluster. Confirm that you see nodes listed in kubectl get node -o wide, and that there are no errors in the k3s journald log that might indicate why it's failing to update the configmap.

If the k3s is uninstalled and installed couple of times, The problem start to appear and persist after that. In the journal logs I can see that
Jan 23 15:00:59 vm-165 k3s[699204]: time="2024-01-23T15:00:59+02:00" level=warning msg="Unable to fetch coredns config map: configmaps "coredns" not found"
K3s nodes YAML:
apiVersion: v1
items:

apiVersion: v1
kind: Node
metadata:
annotations:
alpha.kubernetes.io/provided-node-ip: <IP_ADDRESS>
etcd.k3s.cattle.io/node-address: <IP_ADDRESS>
etcd.k3s.cattle.io/node-name: vm-165.tests.lab.net-03b3f407
flannel.alpha.coreos.com/backend-data: '{"VNI":1,"VtepMAC":"3e:40:74:1b:49:7e"}'
flannel.alpha.coreos.com/backend-type: vxlan
flannel.alpha.coreos.com/kube-subnet-manager: "true"
flannel.alpha.coreos.com/public-ip: <IP_ADDRESS>
k3s.io/encryption-config-hash: start-f34e200ca9e32f01069b791f6654af685af5487c329e8935fc45eda80502e68d
k3s.io/external-ip: <IP_ADDRESS>
k3s.io/hostname: vm-165.tests.lab.net
k3s.io/internal-ip: <IP_ADDRESS>
k3s.io/node-args: '["server","--cluster-init","true","--disable","traefik","--default-local-storage-path","/var/lib/rancher/storage","--disable-helm-controller","true","--https-listen-port","6443","--kube-apiserver-arg","audit-log-path=/var/lib/rancher/k3s/server/logs/audit.log","--kube-apiserver-arg","audit-policy-file=/var/lib/rancher/k3s/server/audit.yaml","--kube-apiserver-arg","audit-log-maxage=30","--kube-apiserver-arg","audit-log-maxbackup=10","--kube-apiserver-arg","audit-log-maxsize=100","--kube-apiserver-arg","request-timeout=300s","--kube-apiserver-arg","service-account-lookup=true","--kube-apiserver-arg","anonymous-auth=false","--kube-cloud-controller-manager-arg","webhook-secure-port=0","--kube-controller-manager-arg","terminated-pod-gc-threshold=12500","--kube-controller-manager-arg","use-service-account-credentials=true","--kubelet-arg","container-log-max-files=4","--kubelet-arg","container-log-max-size=50Mi","--kubelet-arg","streaming-connection-idle-timeout=5m","--kubelet-arg","make-iptables-util-chains=true","--node-external-ip","<IP_ADDRESS>","--node-name","vm-165.tests.lab.net","--prefer-bundled-bin","true","--protect-kernel-defaults","true","--secrets-encryption","true","--tls-san","<IP_ADDRESS>","--write-kubeconfig-mode","0600"]'
k3s.io/node-config-hash: A34B3T7OUQMIDGJXFI3KAYFMLFUNHUG7VU5PZZMBY5NBN3M4YQHQ====
k3s.io/node-env: '{"K3S_DATA_DIR":"/var/lib/rancher/k3s/data/28f7e87eba734b7f7731dc900e2c84e0e98ce869f3dcf57f65dc7bbb80e12e56","K3S_INTERNAL_CERTS_EXPIRATION_DAYS":"730","K3S_UPGRADE":"false"}'
node.alpha.kubernetes.io/ttl: "0"
volumes.kubernetes.io/controller-managed-attach-detach: "true"
finalizers:

wrangler.cattle.io/node
wrangler.cattle.io/managed-etcd-controller
labels:
beta.kubernetes.io/arch: amd64
beta.kubernetes.io/instance-type: k3s
beta.kubernetes.io/os: linux
kubernetes.io/arch: amd64
kubernetes.io/hostname: vm-165.tests.lab.net
kubernetes.io/os: linux
node-role.kubernetes.io/control-plane: "true"
node-role.kubernetes.io/etcd: "true"
node-role.kubernetes.io/master: "true"
node.kubernetes.io/instance-type: k3s
name: vm-165.tests.lab.net
resourceVersion: "10767"
uid: 4f4463ab-3e4e-44dc-a684-7af8d16920f7
spec:
podCIDR: <IP_ADDRESS>/24
podCIDRs:
<IP_ADDRESS>/24
providerID: k3s://vm-165.tests.lab.net
status:
addresses:
address: <IP_ADDRESS>
type: InternalIP
address: <IP_ADDRESS>
type: ExternalIP
address: vm-165.tests.lab.net
type: Hostname
allocatable:
cpu: "16"
ephemeral-storage: "202891775022"
hugepages-1Gi: "0"
hugepages-2Mi: "0"
memory: 32649356Ki
pods: "110"
capacity:
cpu: "16"
ephemeral-storage: 208564736Ki
hugepages-1Gi: "0"
hugepages-2Mi: "0"
memory: 32649356Ki
pods: "110"
conditions:
lastHeartbeatTime: "2024-01-23T14:54:11Z"
lastTransitionTime: "2024-01-23T13:52:55Z"
message: kubelet has sufficient memory available
reason: KubeletHasSufficientMemory
status: "False"
type: MemoryPressure
lastHeartbeatTime: "2024-01-23T14:54:11Z"
lastTransitionTime: "2024-01-23T13:52:55Z"
message: kubelet has no disk pressure
reason: KubeletHasNoDiskPressure
status: "False"
type: DiskPressure
lastHeartbeatTime: "2024-01-23T14:54:11Z"
lastTransitionTime: "2024-01-23T13:52:55Z"
message: kubelet has sufficient PID available
reason: KubeletHasSufficientPID
status: "False"
type: PIDPressure
lastHeartbeatTime: "2024-01-23T14:54:11Z"
lastTransitionTime: "2024-01-23T13:52:55Z"
message: kubelet is posting ready status
reason: KubeletReady
status: "True"
type: Ready
lastHeartbeatTime: "2024-01-23T13:53:10Z"
lastTransitionTime: "2024-01-23T13:53:10Z"
message: Node is a voting member of the etcd cluster
reason: MemberNotLearner
status: "True"
type: EtcdIsVoter
daemonEndpoints:
kubeletEndpoint:
Port: 10250
images:
names:

docker.io/rancher/klipper-helm:v0.8.2-build20230815
sizeBytes: 256386482

names:

docker.io/rancher/mirrored-library-traefik:2.10.5
sizeBytes: 152810877

names:

docker.io/rancher/mirrored-metrics-server:v0.6.3
sizeBytes: 70293467

names:

docker.io/rancher/mirrored-coredns-coredns:1.10.1
sizeBytes: 53618774

names:

docker.io/rancher/local-path-provisioner:v0.0.24
sizeBytes: 40448904

names:

docker.io/rancher/klipper-lb:v0.4.4
sizeBytes: 12479235

names:

docker.io/rancher/mirrored-library-busybox:1.36.1
sizeBytes: 4494167

names:

docker.io/rancher/mirrored-pause:3.6
sizeBytes: 685866
nodeInfo:
architecture: amd64
bootID: 9b5cc646-1840-4e2b-a1b2-966a2cf6ee15
containerRuntimeVersion: containerd://1.7.11-k3s2
kernelVersion: 4.18.0-477.10.1.el8_8.x86_64
kubeProxyVersion: v1.28.5+k3s1
kubeletVersion: v1.28.5+k3s1
machineID: dbe31cb559074f648b289837ab12412f
operatingSystem: linux
osImage: Red Hat Enterprise Linux 8.8 (Ootpa)
systemUUID: dbe31cb5-5907-4f64-8b28-9837ab12412f
kind: List
metadata:
resourceVersion: ""

K3s journald logs:
-- Logs begin at Mon 2024-01-22 12:57:23 EET, end at Tue 2024-01-23 15:09:10 EET. --
Jan 23 15:00:18 vm-165 systemd[1]: Starting Lightweight Kubernetes...
 It will be removed in a future release.
Jan 23 15:00:24 vm-165 k3s[699204]: time="2024-01-23T15:00:24+02:00" level=info msg="Waiting for API server to become available"
Jan 23 15:00:24 vm-165 k3s[699204]: I0123 15:00:24.437406  699204 options.go:220] external host was not specified, using <IP_ADDRESS>
Jan 23 15:00:24 vm-165 k3s[699204]: I0123 15:00:24.438360  699204 server.go:156] Version: v1.28.5+k3s1
Jan 23 15:00:24 vm-165 k3s[699204]: I0123 15:00:24.438392  699204 server.go:158] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Jan 23 15:00:24 vm-165 k3s[699204]: I0123 15:00:24.716355  699204 shared_informer.go:311] Waiting for caches to sync for node_authorizer
Jan 23 15:00:24 vm-165 k3s[699204]: I0123 15:00:24.732948  699204 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.
Jan 23 15:00:24 vm-165 k3s[699204]: I0123 15:00:24.733969  699204 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.

Jan 23 15:00:24 vm-165 k3s[699204]: I0123 15:00:24.972042  699204 handler.go:275] Adding GroupVersion  v1 to ResourceManager
Jan 23 15:00:24 vm-165 k3s[699204]: I0123 15:00:24.972517  699204 instance.go:709] API group "internal.apiserver.k8s.io" is not enabled, skipping.

Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.300140  699204 handler.go:275] Adding GroupVersion authentication.k8s.io v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.300288  699204 genericapiserver.go:744] Skipping API authentication.k8s.io/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.300322  699204 genericapiserver.go:744] Skipping API authentication.k8s.io/v1alpha1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: time="2024-01-23T15:00:25+02:00" level=warning msg="SELinux is enabled on this host, but k3s has not been started with --selinux - containerd SELinux support is disabled"
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.303306  699204 handler.go:275] Adding GroupVersion authorization.k8s.io v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.303352  699204 genericapiserver.go:744] Skipping API authorization.k8s.io/v1beta1 because it has no resources.

Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.316589  699204 handler.go:275] Adding GroupVersion batch v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.316662  699204 genericapiserver.go:744] Skipping API batch/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.318713  699204 handler.go:275] Adding GroupVersion certificates.k8s.io v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.318758  699204 genericapiserver.go:744] Skipping API certificates.k8s.io/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.318769  699204 genericapiserver.go:744] Skipping API certificates.k8s.io/v1alpha1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.319771  699204 handler.go:275] Adding GroupVersion coordination.k8s.io v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.319798  699204 genericapiserver.go:744] Skipping API coordination.k8s.io/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.319873  699204 genericapiserver.go:744] Skipping API discovery.k8s.io/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.320846  699204 handler.go:275] Adding GroupVersion discovery.k8s.io v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.323477  699204 handler.go:275] Adding GroupVersion networking.k8s.io v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.323518  699204 genericapiserver.go:744] Skipping API networking.k8s.io/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.323529  699204 genericapiserver.go:744] Skipping API networking.k8s.io/v1alpha1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.324662  699204 handler.go:275] Adding GroupVersion node.k8s.io v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.324703  699204 genericapiserver.go:744] Skipping API node.k8s.io/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.324715  699204 genericapiserver.go:744] Skipping API node.k8s.io/v1alpha1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.326044  699204 handler.go:275] Adding GroupVersion policy v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.326074  699204 genericapiserver.go:744] Skipping API policy/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.329333  699204 handler.go:275] Adding GroupVersion rbac.authorization.k8s.io v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.329369  699204 genericapiserver.go:744] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.329379  699204 genericapiserver.go:744] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.330431  699204 handler.go:275] Adding GroupVersion scheduling.k8s.io v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.330500  699204 genericapiserver.go:744] Skipping API scheduling.k8s.io/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.330518  699204 genericapiserver.go:744] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.335454  699204 handler.go:275] Adding GroupVersion storage.k8s.io v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.335510  699204 genericapiserver.go:744] Skipping API storage.k8s.io/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.335524  699204 genericapiserver.go:744] Skipping API storage.k8s.io/v1alpha1 because it has no resources.

Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.340629  699204 genericapiserver.go:744] Skipping API flowcontrol.apiserver.k8s.io/v1alpha1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.347616  699204 handler.go:275] Adding GroupVersion apps v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.347666  699204 genericapiserver.go:744] Skipping API apps/v1beta2 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.347678  699204 genericapiserver.go:744] Skipping API apps/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.349313  699204 handler.go:275] Adding GroupVersion admissionregistration.k8s.io v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.349346  699204 genericapiserver.go:744] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.349357  699204 genericapiserver.go:744] Skipping API admissionregistration.k8s.io/v1alpha1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.350190  699204 handler.go:275] Adding GroupVersion events.k8s.io v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.350219  699204 genericapiserver.go:744] Skipping API events.k8s.io/v1beta1 because it has no resources.
Jan 23 15:00:25 vm-165 k3s[699204]: I0123 15:00:25.361915  699204 handler.go:275] Adding GroupVersion apiregistration.k8s.io v1 to ResourceManager
Jan 23 15:00:25 vm-165 k3s[699204]: W0123 15:00:25.361974  699204 genericapiserver.go:744] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources.

Jan 23 15:00:26 vm-165 k3s[699204]: I0123 15:00:26.159137  699204 autoregister_controller.go:141] Starting autoregister controller
Jan 23 15:00:26 vm-165 k3s[699204]: I0123 15:00:26.159146  699204 cache.go:32] Waiting for caches to sync for autoregister controller
Jan 23 15:00:26 vm-165 k3s[699204]: I0123 15:00:26.159158  699204 cache.go:39] Caches are synced for autoregister controller
Jan 23 15:00:26 vm-165 k3s[699204]: I0123 15:00:26.159198  699204 shared_informer.go:318] Caches are synced for configmaps
Jan 23 15:00:26 vm-165 k3s[699204]: I0123 15:00:26.160586  699204 controller.go:624] quota admission added evaluator for: namespaces
Jan 23 15:00:26 vm-165 k3s[699204]: I0123 15:00:26.161646  699204 shared_informer.go:318] Caches are synced for cluster_authentication_trust_controller
Jan 23 15:00:26 vm-165 k3s[699204]: I0123 15:00:26.227390  699204 alloc.go:330] "allocated clusterIPs" service="default/kubernetes" clusterIPs={"IPv4":"<IP_ADDRESS>"}
Jan 23 15:00:26 vm-165 k3s[699204]: W0123 15:00:26.244573  699204 lease.go:263] Resetting endpoints for master service "kubernetes" to [<IP_ADDRESS>]
Jan 23 15:00:26 vm-165 k3s[699204]: I0123 15:00:26.247031  699204 controller.go:624] quota admission added evaluator for: endpoints
Jan 23 15:00:26 vm-165 k3s[699204]: I0123 15:00:26.256682  699204 controller.go:624] quota admission added evaluator for: endpointslices.discovery.k8s.io
Jan 23 15:00:26 vm-165 k3s[699204]: E0123 15:00:26.271473  699204 controller.go:102] Error removing old endpoints from kubernetes service: no API server IP addresses were listed in storage, refusing to erase all endpoints for the kubernetes Service
Jan 23 15:00:26 vm-165 k3s[699204]: time="2024-01-23T15:00:26+02:00" level=info msg="containerd is now running"
Jan 23 15:00:26 vm-165 k3s[699204]: time="2024-01-23T15:00:26+02:00" level=info msg="Importing images from /var/lib/rancher/k3s/agent/images/k3s-airgap-images-amd64.tar.gz"
Jan 23 15:00:26 vm-165 k3s[699204]: I0123 15:00:26.350998  699204 controller.go:624] quota admission added evaluator for: leases.coordination.k8s.io
Jan 23 15:00:27 vm-165 k3s[699204]: I0123 15:00:27.070287  699204 storage_scheduling.go:95] created PriorityClass system-node-critical with value<PHONE_NUMBER>
Jan 23 15:00:27 vm-165 k3s[699204]: I0123 15:00:27.080915  699204 storage_scheduling.go:95] created PriorityClass system-cluster-critical with value<PHONE_NUMBER>
Jan 23 15:00:27 vm-165 k3s[699204]: I0123 15:00:27.080971  699204 storage_scheduling.go:111] all system priority classes are created successfully or already exist.
Jan 23 15:00:28 vm-165 k3s[699204]: I0123 15:00:28.182021  699204 controller.go:624] quota admission added evaluator for: roles.rbac.authorization.k8s.io
Jan 23 15:00:28 vm-165 k3s[699204]: I0123 15:00:28.278860  699204 controller.go:624] quota admission added evaluator for: rolebindings.rbac.authorization.k8s.io
Jan 23 15:00:29 vm-165 k3s[699204]: time="2024-01-23T15:00:29+02:00" level=info msg="Kube API server is now running"
Jan 23 15:00:29 vm-165 k3s[699204]: time="2024-01-23T15:00:29+02:00" level=info msg="ETCD server is now running"
Jan 23 15:00:29 vm-165 k3s[699204]: time="2024-01-23T15:00:29+02:00" level=info msg="k3s is up and running"
Jan 23 15:00:29 vm-165 k3s[699204]: time="2024-01-23T15:00:29+02:00" level=info msg="Waiting for cloud-controller-manager privileges to become available"
Jan 23 15:00:29 vm-165 k3s[699204]: W0123 15:00:29.092783  699204 feature_gate.go:241] Setting GA feature gate JobTrackingWithFinalizers=true. It will be removed in a future release.
Jan 23 15:00:29 vm-165 systemd[1]: Started Lightweight Kubernetes.

Jan 23 15:00:29 vm-165 k3s[699204]: I0123 15:00:29.918648  699204 leaderelection.go:250] attempting to acquire leader lease kube-system/k3s-etcd...

Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.305846  699204 leaderelection.go:260] successfully acquired lease kube-system/k3s-cloud-controller-manager
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.306286  699204 event.go:307] "Event occurred" object="kube-system/k3s-cloud-controller-manager" fieldPath="" kind="Lease" apiVersion="coordination.k8s.io/v1" type="Normal" reason="LeaderElection" message="vm-165_a5002b72-c6f4-4e07-86c7-6b671cc3d99f became leader"
Jan 23 15:00:33 vm-165 k3s[699204]: E0123 15:00:33.329116  699204 controllermanager.go:524] unable to get all supported resources from server: unable to retrieve the complete list of server APIs: metrics.k8s.io/v1beta1: stale GroupVersion discovery: metrics.k8s.io/v1beta1
Jan 23 15:00:33 vm-165 k3s[699204]: time="2024-01-23T15:00:33+02:00" level=info msg="Creating  event broadcaster"
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.386641  699204 shared_informer.go:318] Caches are synced for client-ca::kube-system::extension-apiserver-authentication::client-ca-file
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.386758  699204 shared_informer.go:318] Caches are synced for RequestHeaderAuthRequestController
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.386968  699204 shared_informer.go:318] Caches are synced for client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file
Jan 23 15:00:33 vm-165 k3s[699204]: W0123 15:00:33.396548  699204 handler_proxy.go:93] no RequestInfo found in the context
Jan 23 15:00:33 vm-165 k3s[699204]: E0123 15:00:33.396651  699204 controller.go:113] loading OpenAPI spec for "v1beta1.metrics.k8s.io" failed with: Error, could not get list of group versions for APIService
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.396675  699204 controller.go:126] OpenAPI AggregationController: action for item v1beta1.metrics.k8s.io: Rate Limited Requeue.
Jan 23 15:00:33 vm-165 k3s[699204]: W0123 15:00:33.396807  699204 handler_proxy.go:93] no RequestInfo found in the context
Jan 23 15:00:33 vm-165 k3s[699204]: E0123 15:00:33.397093  699204 controller.go:102] loading OpenAPI spec for "v1beta1.metrics.k8s.io" failed with: failed to download v1beta1.metrics.k8s.io: failed to retrieve openAPI spec, http error: ResponseCode: 503, Body: service unavailable
Jan 23 15:00:33 vm-165 k3s[699204]: , Header: map[Content-Type:[text/plain; charset=utf-8] X-Content-Type-Options:[nosniff]]
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.397793  699204 controller.go:109] OpenAPI AggregationController: action for item v1beta1.metrics.k8s.io: Rate Limited Requeue.

Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.509135  699204 node_controller.go:174] Waiting for informer caches to sync
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.509269  699204 controllermanager.go:337] Started "cloud-node-lifecycle-controller"
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.509467  699204 node_lifecycle_controller.go:113] Sending events to api server
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.509825  699204 controllermanager.go:337] Started "service-lb-controller"
Jan 23 15:00:33 vm-165 k3s[699204]: W0123 15:00:33.509850  699204 controllermanager.go:314] "node-route-controller" is disabled
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.510096  699204 controller.go:231] Starting service controller
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.510180  699204 shared_informer.go:311] Waiting for caches to sync for service
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.510365  699204 event.go:307] "Event occurred" object="kube-system/resource-reader" fieldPath="" kind="Addon" apiVersion="k3s.cattle.io/v1" type="Normal" reason="ApplyingManifest" message="Applying manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/resource-reader.yaml""
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.543120  699204 event.go:307] "Event occurred" object="kube-system/resource-reader" fieldPath="" kind="Addon" apiVersion="k3s.cattle.io/v1" type="Normal" reason="AppliedManifest" message="Applied manifest at "/var/lib/rancher/k3s/server/manifests/metrics-server/resource-reader.yaml""
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.610570  699204 shared_informer.go:318] Caches are synced for service
Jan 23 15:00:33 vm-165 k3s[699204]: time="2024-01-23T15:00:33+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.913199  699204 event.go:307] "Event occurred" object="kube-system/rolebindings" fieldPath="" kind="Addon" apiVersion="k3s.cattle.io/v1" type="Normal" reason="ApplyingManifest" message="Applying manifest at "/var/lib/rancher/k3s/server/manifests/rolebindings.yaml""
Jan 23 15:00:33 vm-165 k3s[699204]: I0123 15:00:33.995017  699204 event.go:307] "Event occurred" object="kube-system/rolebindings" fieldPath="" kind="Addon" apiVersion="k3s.cattle.io/v1" type="Normal" reason="AppliedManifest" message="Applied manifest at "/var/lib/rancher/k3s/server/manifests/rolebindings.yaml""
Jan 23 15:00:34 vm-165 k3s[699204]: I0123 15:00:34.297615  699204 event.go:307] "Event occurred" object="vm-165.tests.lab.net" fieldPath="" kind="Node" apiVersion="" type="Normal" reason="NodePasswordValidationComplete" message="Deferred node password secret validation complete"
Jan 23 15:00:34 vm-165 k3s[699204]: I0123 15:00:34.317001  699204 event.go:307] "Event occurred" object="kube-system/runtimes" fieldPath="" kind="Addon" apiVersion="k3s.cattle.io/v1" type="Normal" reason="ApplyingManifest" message="Applying manifest at "/var/lib/rancher/k3s/server/manifests/runtimes.yaml""
Jan 23 15:00:34 vm-165 k3s[699204]: I0123 15:00:34.530409  699204 event.go:307] "Event occurred" object="kube-system/runtimes" fieldPath="" kind="Addon" apiVersion="k3s.cattle.io/v1" type="Normal" reason="AppliedManifest" message="Applied manifest at "/var/lib/rancher/k3s/server/manifests/runtimes.yaml""
Jan 23 15:00:35 vm-165 k3s[699204]: time="2024-01-23T15:00:35+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:36 vm-165 k3s[699204]: time="2024-01-23T15:00:36+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:37 vm-165 k3s[699204]: time="2024-01-23T15:00:37+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:38 vm-165 k3s[699204]: time="2024-01-23T15:00:38+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:40 vm-165 k3s[699204]: time="2024-01-23T15:00:40+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:41 vm-165 k3s[699204]: time="2024-01-23T15:00:41+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:42 vm-165 k3s[699204]: time="2024-01-23T15:00:42+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:43 vm-165 k3s[699204]: I0123 15:00:43.344727  699204 range_allocator.go:111] "No Secondary Service CIDR provided.  Proceeding to collect garbage"
Jan 23 15:00:44 vm-165 k3s[699204]: W0123 15:00:44.617736  699204 handler_proxy.go:93] no RequestInfo found in the context
Jan 23 15:00:44 vm-165 k3s[699204]: E0123 15:00:44.617934  699204 controller.go:102] loading OpenAPI spec for "v1beta1.metrics.k8s.io" failed with: failed to download v1beta1.metrics.k8s.io: failed to retrieve openAPI spec, http error: ResponseCode: 503, Body: service unavailable
Jan 23 15:00:44 vm-165 k3s[699204]: , Header: map[Content-Type:[text/plain; charset=utf-8] X-Content-Type-Options:[nosniff]]
Jan 23 15:00:44 vm-165 k3s[699204]: I0123 15:00:44.617960  699204 controller.go:109] OpenAPI AggregationController: action for item v1beta1.metrics.k8s.io: Rate Limited Requeue.
Jan 23 15:00:44 vm-165 k3s[699204]: W0123 15:00:44.617969  699204 handler_proxy.go:93] no RequestInfo found in the context
Jan 23 15:00:44 vm-165 k3s[699204]: E0123 15:00:44.618068  699204 controller.go:113] loading OpenAPI spec for "v1beta1.metrics.k8s.io" failed with: Error, could not get list of group versions for APIService
Jan 23 15:00:44 vm-165 k3s[699204]: I0123 15:00:44.619129  699204 controller.go:126] OpenAPI AggregationController: action for item v1beta1.metrics.k8s.io: Rate Limited Requeue.
Jan 23 15:00:44 vm-165 k3s[699204]: time="2024-01-23T15:00:44+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:46 vm-165 k3s[699204]: time="2024-01-23T15:00:46+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:47 vm-165 k3s[699204]: time="2024-01-23T15:00:47+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:48 vm-165 k3s[699204]: time="2024-01-23T15:00:48+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:49 vm-165 k3s[699204]: time="2024-01-23T15:00:49+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:50 vm-165 k3s[699204]: time="2024-01-23T15:00:50+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:52 vm-165 k3s[699204]: time="2024-01-23T15:00:52+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:53 vm-165 k3s[699204]: time="2024-01-23T15:00:53+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:54 vm-165 k3s[699204]: time="2024-01-23T15:00:54+02:00" level=info msg="Waiting for control-plane node vm-165.tests.lab.net startup: nodes "vm-165.tests.lab.net" not found"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Imported docker.io/rancher/klipper-helm:v0.8.2-build20230815"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Imported docker.io/rancher/klipper-lb:v0.4.4"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Imported docker.io/rancher/local-path-provisioner:v0.0.24"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Imported docker.io/rancher/mirrored-coredns-coredns:1.10.1"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Imported docker.io/rancher/mirrored-library-busybox:1.36.1"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Imported docker.io/rancher/mirrored-library-traefik:2.10.5"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Imported docker.io/rancher/mirrored-metrics-server:v0.6.3"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Imported docker.io/rancher/mirrored-pause:3.6"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Imported images from /var/lib/rancher/k3s/agent/images/k3s-airgap-images-amd64.tar.gz in 29.181608796s"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Connecting to proxy" url="wss://<IP_ADDRESS>:6443/v1-k3s/connect"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Running kubelet --address=<IP_ADDRESS> --allowed-unsafe-sysctls=net.ipv4.ip_forward,net.ipv6.conf.all.forwarding --anonymous-auth=false --authentication-token-webhook=true --authorization-mode=Webhook --cgroup-driver=systemd --client-ca-file=/var/lib/rancher/k3s/agent/client-ca.crt --cloud-provider=external --cluster-dns=<IP_ADDRESS> --cluster-domain=cluster.local --container-log-max-files=4 --container-log-max-size=50Mi --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=<IP_ADDRESS> --hostname-override=vm-165.tests.lab.net --kubeconfig=/var/lib/rancher/k3s/agent/kubelet.kubeconfig --make-iptables-util-chains=true --node-ip=<IP_ADDRESS> --node-labels= --pod-infra-container-image=rancher/mirrored-pause:3.6 --pod-manifest-path=/var/lib/rancher/k3s/agent/pod-manifests --protect-kernel-defaults=true --read-only-port=0 --resolv-conf=/etc/resolv.conf --serialize-image-pulls=false --streaming-connection-idle-timeout=5m --tls-cert-file=/var/lib/rancher/k3s/agent/serving-kubelet.crt --tls-private-key-file=/var/lib/rancher/k3s/agent/serving-kubelet.key"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Handling backend connection request [vm-165.tests.lab.net]"
Jan 23 15:00:55 vm-165 k3s[699204]: Flag --cloud-provider has been deprecated, will be removed in 1.25 or later, in favor of removing cloud provider code from Kubelet.
Jan 23 15:00:55 vm-165 k3s[699204]: Flag --containerd has been deprecated, This is a cadvisor flag that was mistakenly registered with the Kubelet. Due to legacy concerns, it will follow the standard CLI deprecation timeline before being removed.
Jan 23 15:00:55 vm-165 k3s[699204]: Flag --pod-infra-container-image has been deprecated, will be removed in a future release. Image garbage collector will get sandbox image information from CRI.
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.529850  699204 server.go:202] "--pod-infra-container-image will not be pruned by the image garbage collector in kubelet and should also be set in the remote runtime"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.534181  699204 server.go:462] "Kubelet version" kubeletVersion="v1.28.5+k3s1"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.534280  699204 server.go:464] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.537877  699204 dynamic_cafile_content.go:157] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/agent/client-ca.crt"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.564814  699204 server.go:720] "--cgroups-per-qos enabled, but --cgroup-root was not specified.  defaulting to /"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.565599  699204 container_manager_linux.go:265] "Container manager verified user specified cgroup-root exists" cgroupRoot=[]
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.565898  699204 container_manager_linux.go:270] "Creating Container Manager object based on Node Config" nodeConfig={"RuntimeCgroupsName":"","SystemCgroupsName":"","KubeletCgroupsName":"","KubeletOOMScoreAdj":-999,"ContainerRuntime":"","CgroupsPerQOS":true,"CgroupRoot":"/","CgroupDriver":"systemd","KubeletRootDir":"/var/lib/kubelet","ProtectKernelDefaults":true,"KubeReservedCgroupName":"","SystemReservedCgroupName":"","ReservedSystemCPUs":{},"EnforceNodeAllocatable":{"pods":{}},"KubeReserved":null,"SystemReserved":null,"HardEvictionThresholds":[{"Signal":"imagefs.available","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.05},"GracePeriod":0,"MinReclaim":null},{"Signal":"nodefs.available","Operator":"LessThan","Value":{"Quantity":null,"Percentage":0.05},"GracePeriod":0,"MinReclaim":null}],"QOSReserved":{},"CPUManagerPolicy":"none","CPUManagerPolicyOptions":null,"TopologyManagerScope":"container","CPUManagerReconcilePeriod":10000000000,"ExperimentalMemoryManagerPolicy":"None","ExperimentalMemoryManagerReservedMemory":null,"PodPidsLimit":-1,"EnforceCPULimits":true,"CPUCFSQuotaPeriod":100000000,"TopologyManagerPolicy":"none","TopologyManagerPolicyOptions":null}
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.565933  699204 topology_manager.go:138] "Creating topology manager with none policy"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.565947  699204 container_manager_linux.go:301] "Creating device plugin manager"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.566086  699204 state_mem.go:36] "Initialized new in-memory state store"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.566219  699204 kubelet.go:393] "Attempting to sync node with API server"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.566264  699204 kubelet.go:298] "Adding static pod path" path="/var/lib/rancher/k3s/agent/pod-manifests"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.566298  699204 kubelet.go:309] "Adding apiserver pod source"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.566316  699204 apiserver.go:42] "Waiting for node sync before watching apiserver pods"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.567761  699204 kuberuntime_manager.go:257] "Container runtime initialized" containerRuntime="containerd" version="v1.7.11-k3s2" apiVersion="v1"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.568696  699204 server.go:1227] "Started kubelet"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.569041  699204 ratelimit.go:65] "Setting rate limiting for podresources endpoint" qps=100 burstTokens=10
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.569312  699204 server.go:162] "Starting to listen" address="<IP_ADDRESS>" port=10250
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.569631  699204 server.go:233] "Starting to serve the podresources API" endpoint="unix:/var/lib/kubelet/pod-resources/kubelet.sock"
Jan 23 15:00:55 vm-165 k3s[699204]: E0123 15:00:55.569785  699204 cri_stats_provider.go:448] "Failed to get the info of the filesystem with mountpoint" err="unable to find data in memory cache" mountpoint="/var/lib/rancher/k3s/agent/containerd/io.containerd.snapshotter.v1.overlayfs"
Jan 23 15:00:55 vm-165 k3s[699204]: E0123 15:00:55.569887  699204 kubelet.go:1431] "Image garbage collection failed once. Stats initialization may not have completed yet" err="invalid capacity 0 on image filesystem"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.571131  699204 fs_resource_analyzer.go:67] "Starting FS ResourceAnalyzer"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.571295  699204 volume_manager.go:291] "Starting Kubelet Volume Manager"
Jan 23 15:00:55 vm-165 k3s[699204]: E0123 15:00:55.571474  699204 kubelet_node_status.go:458] "Error getting the current node from lister" err="node "vm-165.tests.lab.net" not found"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.571511  699204 desired_state_of_world_populator.go:151] "Desired state populator starts to run"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.571666  699204 reconciler_new.go:29] "Reconciler: start to sync state"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.571704  699204 server.go:462] "Adding debug handlers to kubelet server"
Jan 23 15:00:55 vm-165 k3s[699204]: E0123 15:00:55.580302  699204 remote_runtime.go:432] "ContainerStatus from runtime service failed" err="rpc error: code = NotFound desc = an error occurred when try to find container "0ad686d8dddf66c9f29cd4d4398b265bfb6fe54f80a65b0b564a7f0c5fc58d48": not found" containerID="0ad686d8dddf66c9f29cd4d4398b265bfb6fe54f80a65b0b564a7f0c5fc58d48"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.580394  699204 kuberuntime_gc.go:360] "Error getting ContainerStatus for containerID" containerID="0ad686d8dddf66c9f29cd4d4398b265bfb6fe54f80a65b0b564a7f0c5fc58d48" err="rpc error: code = NotFound desc = an error occurred when try to find container "0ad686d8dddf66c9f29cd4d4398b265bfb6fe54f80a65b0b564a7f0c5fc58d48": not found"
Jan 23 15:00:55 vm-165 k3s[699204]: E0123 15:00:55.581653  699204 remote_runtime.go:432] "ContainerStatus from runtime service failed" err="rpc error: code = NotFound desc = an error occurred when try to find container "e67e963ea942627c360508605fe19a3481e9c26304aeb5dc5b15d3cd78ebd13b": not found" containerID="e67e963ea942627c360508605fe19a3481e9c26304aeb5dc5b15d3cd78ebd13b"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.581752  699204 kuberuntime_gc.go:360] "Error getting ContainerStatus for containerID" containerID="e67e963ea942627c360508605fe19a3481e9c26304aeb5dc5b15d3cd78ebd13b" err="rpc error: code = NotFound desc = an error occurred when try to find container "e67e963ea942627c360508605fe19a3481e9c26304aeb5dc5b15d3cd78ebd13b": not found"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.585986  699204 kubelet_network_linux.go:50] "Initialized iptables rules." protocol="IPv4"
Jan 23 15:00:55 vm-165 k3s[699204]: E0123 15:00:55.586212  699204 nodelease.go:49] "Failed to get node when trying to set owner ref to the node lease" err="nodes "vm-165.tests.lab.net" not found" node="vm-165.tests.lab.net"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.587723  699204 kubelet_network_linux.go:50] "Initialized iptables rules." protocol="IPv6"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.587803  699204 status_manager.go:217] "Starting to sync pod status with apiserver"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.587851  699204 kubelet.go:2303] "Starting kubelet main sync loop"
Jan 23 15:00:55 vm-165 k3s[699204]: E0123 15:00:55.588107  699204 kubelet.go:2327] "Skipping pod synchronization" err="[container runtime status check may not have completed yet, PLEG is not healthy: pleg has yet to be successful]"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.673874  699204 kubelet_node_status.go:70] "Attempting to register node" node="vm-165.tests.lab.net"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.689142  699204 kubelet_node_status.go:73] "Successfully registered node" node="vm-165.tests.lab.net"
Jan 23 15:00:55 vm-165 k3s[699204]: E0123 15:00:55.691877  699204 kubelet.go:2327] "Skipping pod synchronization" err="container runtime status check may not have completed yet"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.696505  699204 actual_state_of_world.go:547] "Failed to update statusUpdateNeeded field in actual state of world" err="Failed to set statusUpdateNeeded to needed true, because nodeName="vm-165.tests.lab.net" does not exist"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.697104  699204 node_controller.go:431] Initializing node vm-165.tests.lab.net with cloud provider
Jan 23 15:00:55 vm-165 k3s[699204]: E0123 15:00:55.697532  699204 node_controller.go:240] error syncing 'vm-165.tests.lab.net': failed to get instance metadata for node vm-165.tests.lab.net: address annotations not yet set, requeuing
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.704406  699204 node_controller.go:431] Initializing node vm-165.tests.lab.net with cloud provider
Jan 23 15:00:55 vm-165 k3s[699204]: E0123 15:00:55.704795  699204 node_controller.go:240] error syncing 'vm-165.tests.lab.net': failed to get instance metadata for node vm-165.tests.lab.net: address annotations not yet set, requeuing
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.714806  699204 node_controller.go:431] Initializing node vm-165.tests.lab.net with cloud provider
Jan 23 15:00:55 vm-165 k3s[699204]: E0123 15:00:55.714907  699204 node_controller.go:240] error syncing 'vm-165.tests.lab.net': failed to get instance metadata for node vm-165.tests.lab.net: address annotations not yet set, requeuing
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.718330  699204 node_controller.go:431] Initializing node vm-165.tests.lab.net with cloud provider
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Annotations and labels have been set successfully on node: vm-165.tests.lab.net"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Starting flannel with backend vxlan"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.728458  699204 range_allocator.go:380] "Set node PodCIDR" node="vm-165.tests.lab.net" podCIDRs=["<IP_ADDRESS>/24"]
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Flannel found PodCIDR assigned for node vm-165.tests.lab.net"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="The interface enp1s0 with ipv4 address <IP_ADDRESS> will be used by flannel"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.730913  699204 cpu_manager.go:214] "Starting CPU manager" policy="none"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.730961  699204 cpu_manager.go:215] "Reconciling" reconcilePeriod="10s"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.730998  699204 state_mem.go:36] "Initialized new in-memory state store"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.731488  699204 kube.go:145] Waiting 10m0s for node controller to sync
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.731519  699204 kube.go:489] Starting kube subnet manager
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.733882  699204 policy_none.go:49] "None policy: Start"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.736129  699204 memory_manager.go:169] "Starting memorymanager" policy="None"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.736208  699204 state_mem.go:35] "Initializing new in-memory state store"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.751727  699204 manager.go:471] "Failed to read data from checkpoint" checkpoint="kubelet_internal_checkpoint" err="checkpoint is not found"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.752606  699204 plugin_manager.go:118] "Starting Kubelet Plugin Manager"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Running kube-proxy --cluster-cidr=<IP_ADDRESS>/16 --conntrack-max-per-core=0 --conntrack-tcp-timeout-close-wait=0s --conntrack-tcp-timeout-established=0s --healthz-bind-address=<IP_ADDRESS> --hostname-override=vm-165.tests.lab.net --kubeconfig=/var/lib/rancher/k3s/agent/kubeproxy.kubeconfig --proxy-mode=iptables"
Jan 23 15:00:55 vm-165 k3s[699204]: time="2024-01-23T15:00:55+02:00" level=info msg="Starting the netpol controller version v2.0.0-20230925161250-364f994b140b, built on 2023-12-27T16:01:02Z, go1.20.12"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.842028  699204 network_policy_controller.go:164] Starting network policy controller
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.851758  699204 node_controller.go:502] Successfully initialized node vm-165.tests.lab.net with cloud provider
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.852072  699204 event.go:307] "Event occurred" object="vm-165.tests.lab.net" fieldPath="" kind="Node" apiVersion="v1" type="Normal" reason="Synced" message="Node synced successfully"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.855735  699204 node.go:141] Successfully retrieved node IP: <IP_ADDRESS>
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.856011  699204 kuberuntime_manager.go:1528] "Updating runtime config through cri with podcidr" CIDR="<IP_ADDRESS>/24"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.857601  699204 kubelet_network.go:61] "Updating Pod CIDR" originalPodCIDR="" newPodCIDR="<IP_ADDRESS>/24"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.866039  699204 server.go:632] "kube-proxy running in dual-stack mode" primary ipFamily="IPv4"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.869217  699204 server_others.go:152] "Using iptables Proxier"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.869376  699204 server_others.go:421] "Detect-local-mode set to ClusterCIDR, but no cluster CIDR for family" ipFamily="IPv6"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.869395  699204 server_others.go:438] "Defaulting to no-op detect-local"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.869430  699204 proxier.go:251] "Setting route_localnet=1 to allow node-ports on localhost; to change this either disable iptables.localhostNodePorts (--iptables-localhost-nodeports) or set nodePortAddresses (--nodeport-addresses) to filter loopback addresses"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.869778  699204 server.go:846] "Version info" version="v1.28.5+k3s1"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.869803  699204 server.go:848] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.870669  699204 config.go:188] "Starting service config controller"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.870735  699204 shared_informer.go:311] Waiting for caches to sync for service config
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.870785  699204 config.go:97] "Starting endpoint slice config controller"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.870799  699204 shared_informer.go:311] Waiting for caches to sync for endpoint slice config
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.870814  699204 config.go:315] "Starting node config controller"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.870857  699204 shared_informer.go:311] Waiting for caches to sync for node config
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.901868  699204 network_policy_controller.go:176] Starting network policy controller full sync goroutine
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.963685  699204 kubelet_node_status.go:493] "Fast updating node status as it just became ready"
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.970914  699204 shared_informer.go:318] Caches are synced for service config
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.970971  699204 shared_informer.go:318] Caches are synced for node config
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.970933  699204 shared_informer.go:318] Caches are synced for endpoint slice config
Jan 23 15:00:55 vm-165 k3s[699204]: I0123 15:00:55.978623  699204 topologycache.go:237] "Can't get CPU or zone information for node" node="vm-165.tests.lab.net"
Jan 23 15:00:56 vm-165 k3s[699204]: I0123 15:00:56.161280  699204 serving.go:355] Generated self-signed cert in-memory
Jan 23 15:00:56 vm-165 k3s[699204]: time="2024-01-23T15:00:56+02:00" level=info msg="Stopped tunnel to <IP_ADDRESS>:6443"
Jan 23 15:00:56 vm-165 k3s[699204]: time="2024-01-23T15:00:56+02:00" level=info msg="Connecting to proxy" url="wss://<IP_ADDRESS>:6443/v1-k3s/connect"
Jan 23 15:00:56 vm-165 k3s[699204]: time="2024-01-23T15:00:56+02:00" level=info msg="Proxy done" err="context canceled" url="wss://<IP_ADDRESS>:6443/v1-k3s/connect"
Jan 23 15:00:56 vm-165 k3s[699204]: time="2024-01-23T15:00:56+02:00" level=info msg="error in remotedialer server [400]: websocket: close 1006 (abnormal closure): unexpected EOF"
Jan 23 15:00:56 vm-165 k3s[699204]: time="2024-01-23T15:00:56+02:00" level=info msg="Tunnel authorizer set Kubelet Port 10250"
Jan 23 15:00:56 vm-165 k3s[699204]: time="2024-01-23T15:00:56+02:00" level=info msg="Handling backend connection request [vm-165.tests.lab.net]"
Jan 23 15:00:56 vm-165 k3s[699204]: I0123 15:00:56.567691  699204 apiserver.go:52] "Watching apiserver"
Jan 23 15:00:56 vm-165 k3s[699204]: I0123 15:00:56.672105  699204 desired_state_of_world_populator.go:159] "Finished populating initial desired state of world"
Jan 23 15:00:56 vm-165 k3s[699204]: time="2024-01-23T15:00:56+02:00" level=warning msg="Unable to fetch coredns config map: configmaps "coredns" not found"
Jan 23 15:00:56 vm-165 k3s[699204]: I0123 15:00:56.731888  699204 kube.go:152] Node controller sync successful
Jan 23 15:00:56 vm-165 k3s[699204]: I0123 15:00:56.732091  699204 vxlan.go:141] VXLAN config: VNI=1 Port=0 GBP=false Learning=false DirectRouting=false
Jan 23 15:00:56 vm-165 k3s[699204]: I0123 15:00:56.753398  699204 kube.go:510] Creating the node lease for IPv4. This is the n.Spec.PodCIDRs: [<IP_ADDRESS>/24]
Jan 23 15:00:56 vm-165 k3s[699204]: I0123 15:00:56.763918  699204 server.go:154] "Starting Kubernetes Scheduler" version="v1.28.5+k3s1"
Jan 23 15:00:56 vm-165 k3s[699204]: I0123 15:00:56.763984  699204 server.go:156] "Golang settings" GOGC="" GOMAXPROCS="" GOTRACEBACK=""
Jan 23 15:00:56 vm-165 k3s[699204]: time="2024-01-23T15:00:56+02:00" level=info msg="Wrote flannel subnet file to /run/flannel/subnet.env"
Jan 23 15:00:56 vm-165 k3s[699204]: time="2024-01-23T15:00:56+02:00" level=info msg="Running flannel backend."

 No retries permitted until 2024-01-23 15:00:57.581872216 +0200 EET m=+35.811588534 (durationBeforeRetry 500ms). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume") pod "coredns-6799fbcd5-wzffs" (UID: "e5551773-502a-4e54-8d2d-63baf98cc232") : configmap references non-existent config key: NodeHosts
Jan 23 15:00:57 vm-165 k3s[699204]: E0123 15:00:57.585972  699204 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume podName:e5551773-502a-4e54-8d2d-63baf98cc232 nodeName:}" failed. No retries permitted until 2024-01-23 15:00:58.585937131 +0200 EET m=+36.815653339 (durationBeforeRetry 1s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume") pod "coredns-6799fbcd5-wzffs" (UID: "e5551773-502a-4e54-8d2d-63baf98cc232") : configmap references non-existent config key: NodeHosts
Jan 23 15:00:58 vm-165 k3s[699204]: time="2024-01-23T15:00:58+02:00" level=warning msg="Unable to fetch coredns config map: configmaps "coredns" not found"
Jan 23 15:00:58 vm-165 k3s[699204]: E0123 15:00:58.592084  699204 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume podName:e5551773-502a-4e54-8d2d-63baf98cc232 nodeName:}" failed. No retries permitted until 2024-01-23 15:01:00.592031241 +0200 EET m=+38.821747492 (durationBeforeRetry 2s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume") pod "coredns-6799fbcd5-wzffs" (UID: "e5551773-502a-4e54-8d2d-63baf98cc232") : configmap references non-existent config key: NodeHosts
Jan 23 15:00:58 vm-165 k3s[699204]: I0123 15:00:58.639193  699204 replica_set.go:676] "Finished syncing" kind="ReplicaSet" key="kube-system/local-path-provisioner-84db5d44d9" duration="12.395766ms"
Jan 23 15:00:58 vm-165 k3s[699204]: I0123 15:00:58.639411  699204 replica_set.go:676] "Finished syncing" kind="ReplicaSet" key="kube-system/local-path-provisioner-84db5d44d9" duration="100.723µs"
Jan 23 15:00:58 vm-165 k3s[699204]: time="2024-01-23T15:00:58+02:00" level=warning msg="Unable to fetch coredns config map: configmaps "coredns" not found"
Jan 23 15:00:58 vm-165 k3s[699204]: I0123 15:00:58.783101  699204 node_lifecycle_controller.go:1225] "Initializing eviction metric for zone" zone=""
Jan 23 15:00:58 vm-165 k3s[699204]: I0123 15:00:58.783410  699204 node_lifecycle_controller.go:877] "Missing timestamp for Node. Assuming now as a timestamp" node="vm-165.tests.lab.net"
Jan 23 15:00:58 vm-165 k3s[699204]: I0123 15:00:58.783433  699204 event.go:307] "Event occurred" object="vm-165.tests.lab.net" fieldPath="" kind="Node" apiVersion="v1" type="Normal" reason="RegisteredNode" message="Node vm-165.tests.lab.net event: Registered Node vm-165.tests.lab.net in Controller"
Jan 23 15:00:58 vm-165 k3s[699204]: I0123 15:00:58.783576  699204 node_lifecycle_controller.go:1071] "Controller detected that zone is now in new state" zone="" newState="Normal"
Jan 23 15:00:59 vm-165 k3s[699204]: time="2024-01-23T15:00:59+02:00" level=warning msg="Unable to fetch coredns config map: configmaps "coredns" not found"
Jan 23 15:00:59 vm-165 k3s[699204]: time="2024-01-23T15:00:59+02:00" level=warning msg="Unable to fetch coredns config map: configmaps "coredns" not found"
Jan 23 15:00:59 vm-165 k3s[699204]: I0123 15:00:59.638222  699204 pod_startup_latency_tracker.go:102] "Observed pod startup duration" pod="kube-system/local-path-provisioner-84db5d44d9-jjw6f" podStartSLOduration=16.6381034 podCreationTimestamp="2024-01-23 15:00:43 +0200 EET" firstStartedPulling="0001-01-01 00:00:00 +0000 UTC" lastFinishedPulling="0001-01-01 00:00:00 +0000 UTC" observedRunningTime="2024-01-23 15:00:58.626887134 +0200 EET m=+36.856603462" watchObservedRunningTime="2024-01-23 15:00:59.6381034 +0200 EET m=+37.867819689"
Jan 23 15:00:59 vm-165 k3s[699204]: I0123 15:00:59.638838  699204 replica_set.go:676] "Finished syncing" kind="ReplicaSet" key="kube-system/metrics-server-67c658944b" duration="122.472µs"
Jan 23 15:00:59 vm-165 k3s[699204]: time="2024-01-23T15:00:59+02:00" level=info msg="Labels and annotations have been set successfully on node: vm-165.tests.lab.net"
Jan 23 15:00:59 vm-165 k3s[699204]: time="2024-01-23T15:00:59+02:00" level=warning msg="Unable to fetch coredns config map: configmaps "coredns" not found"
Jan 23 15:01:00 vm-165 k3s[699204]: E0123 15:01:00.604732  699204 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume podName:e5551773-502a-4e54-8d2d-63baf98cc232 nodeName:}" failed. No retries permitted until 2024-01-23 15:01:04.604678391 +0200 EET m=+42.834394688 (durationBeforeRetry 4s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume") pod "coredns-6799fbcd5-wzffs" (UID: "e5551773-502a-4e54-8d2d-63baf98cc232") : configmap references non-existent config key: NodeHosts
Jan 23 15:01:04 vm-165 k3s[699204]: E0123 15:01:04.637275  699204 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume podName:e5551773-502a-4e54-8d2d-63baf98cc232 nodeName:}" failed. No retries permitted until 2024-01-23 15:01:12.637184694 +0200 EET m=+50.866900941 (durationBeforeRetry 8s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume") pod "coredns-6799fbcd5-wzffs" (UID: "e5551773-502a-4e54-8d2d-63baf98cc232") : configmap references non-existent config key: NodeHosts
Jan 23 15:01:10 vm-165 k3s[699204]: time="2024-01-23T15:01:10+02:00" level=info msg="Adding etcd member vm-165.tests.lab.net-41f54d96 status condition"
Jan 23 15:01:10 vm-165 k3s[699204]: time="2024-01-23T15:01:10+02:00" level=warning msg="Unable to fetch coredns config map: configmaps "coredns" not found"
Jan 23 15:01:12 vm-165 k3s[699204]: E0123 15:01:12.698421  699204 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume podName:e5551773-502a-4e54-8d2d-63baf98cc232 nodeName:}" failed. No retries permitted until 2024-01-23 15:01:28.698358883 +0200 EET m=+66.928075221 (durationBeforeRetry 16s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume") pod "coredns-6799fbcd5-wzffs" (UID: "e5551773-502a-4e54-8d2d-63baf98cc232") : configmap references non-existent config key: NodeHosts
Jan 23 15:01:13 vm-165 k3s[699204]: E0123 15:01:13.696853  699204 resource_quota_controller.go:440] unable to retrieve the complete list of server APIs: metrics.k8s.io/v1beta1: stale GroupVersion discovery: metrics.k8s.io/v1beta1
Jan 23 15:01:14 vm-165 k3s[699204]: I0123 15:01:14.124745  699204 garbagecollector.go:816] "failed to discover some groups" groups="<internal error: json: unsupported type: map[schema.GroupVersion]error>"
Jan 23 15:01:15 vm-165 k3s[699204]: I0123 15:01:15.464329  699204 pod_startup_latency_tracker.go:102] "Observed pod startup duration" pod="kube-system/metrics-server-67c658944b-lv5k4" podStartSLOduration=32.46415551 podCreationTimestamp="2024-01-23 15:00:43 +0200 EET" firstStartedPulling="0001-01-01 00:00:00 +0000 UTC" lastFinishedPulling="0001-01-01 00:00:00 +0000 UTC" observedRunningTime="2024-01-23 15:00:59.638635381 +0200 EET m=+37.868351722" watchObservedRunningTime="2024-01-23 15:01:15.46415551 +0200 EET m=+53.693871820"
Jan 23 15:01:15 vm-165 k3s[699204]: I0123 15:01:15.482642  699204 replica_set.go:676] "Finished syncing" kind="ReplicaSet" key="kube-system/metrics-server-67c658944b" duration="18.447615ms"
Jan 23 15:01:15 vm-165 k3s[699204]: I0123 15:01:15.483447  699204 replica_set.go:676] "Finished syncing" kind="ReplicaSet" key="kube-system/metrics-server-67c658944b" duration="292.945µs"
Jan 23 15:01:15 vm-165 k3s[699204]: I0123 15:01:15.561750  699204 handler.go:275] Adding GroupVersion metrics.k8s.io v1beta1 to ResourceManager
Jan 23 15:01:27 vm-165 k3s[699204]: {"level":"warn","ts":"2024-01-23T15:01:27.200323+0200","caller":"etcdserver/util.go:170","msg":"apply request took too long","took":"107.081604ms","expected-duration":"100ms","prefix":"read-only range ","request":"key:"/registry/minions/" range_end:"/registry/minions0" ","response":"range_response_count:1 size:6464"}
Jan 23 15:01:27 vm-165 k3s[699204]: {"level":"info","ts":"2024-01-23T15:01:27.200576+0200","caller":"traceutil/trace.go:171","msg":"trace[1476067477] range","detail":"{range_begin:/registry/minions/; range_end:/registry/minions0; response_count:1; response_revision:593; }","duration":"107.396214ms","start":"2024-01-23T15:01:27.093144+0200","end":"2024-01-23T15:01:27.20054+0200","steps":["trace[1476067477] 'range keys from in-memory index tree'  (duration: 106.750094ms)"],"step_count":1}
Jan 23 15:01:28 vm-165 k3s[699204]: E0123 15:01:28.713328  699204 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume podName:e5551773-502a-4e54-8d2d-63baf98cc232 nodeName:}" failed. No retries permitted until 2024-01-23 15:02:00.713221366 +0200 EET m=+98.942937736 (durationBeforeRetry 32s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume") pod "coredns-6799fbcd5-wzffs" (UID: "e5551773-502a-4e54-8d2d-63baf98cc232") : configmap references non-existent config key: NodeHosts
Jan 23 15:02:00 vm-165 k3s[699204]: E0123 15:02:00.741033  699204 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume podName:e5551773-502a-4e54-8d2d-63baf98cc232 nodeName:}" failed. No retries permitted until 2024-01-23 15:03:04.740967382 +0200 EET m=+162.970683632 (durationBeforeRetry 1m4s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume") pod "coredns-6799fbcd5-wzffs" (UID: "e5551773-502a-4e54-8d2d-63baf98cc232") : configmap references non-existent config key: NodeHosts
Jan 23 15:02:59 vm-165 k3s[699204]: E0123 15:02:59.976799  699204 pod_workers.go:1300] "Error syncing pod, skipping" err="unmounted volumes=[config-volume], unattached volumes=[], failed to process volumes=[]: context deadline exceeded" pod="kube-system/coredns-6799fbcd5-wzffs" podUID="e5551773-502a-4e54-8d2d-63baf98cc232"
Jan 23 15:03:04 vm-165 k3s[699204]: E0123 15:03:04.800928  699204 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume podName:e5551773-502a-4e54-8d2d-63baf98cc232 nodeName:}" failed. No retries permitted until 2024-01-23 15:05:06.800871667 +0200 EET m=+285.030587951 (durationBeforeRetry 2m2s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume") pod "coredns-6799fbcd5-wzffs" (UID: "e5551773-502a-4e54-8d2d-63baf98cc232") : configmap references non-existent config key: NodeHosts
Jan 23 15:05:06 vm-165 k3s[699204]: E0123 15:05:06.815139  699204 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume podName:e5551773-502a-4e54-8d2d-63baf98cc232 nodeName:}" failed. No retries permitted until 2024-01-23 15:07:08.815030265 +0200 EET m=+407.044746512 (durationBeforeRetry 2m2s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume") pod "coredns-6799fbcd5-wzffs" (UID: "e5551773-502a-4e54-8d2d-63baf98cc232") : configmap references non-existent config key: NodeHosts
Jan 23 15:05:18 vm-165 k3s[699204]: E0123 15:05:18.590003  699204 pod_workers.go:1300] "Error syncing pod, skipping" err="unmounted volumes=[config-volume], unattached volumes=[], failed to process volumes=[]: context deadline exceeded" pod="kube-system/coredns-6799fbcd5-wzffs" podUID="e5551773-502a-4e54-8d2d-63baf98cc232"
Jan 23 15:06:01 vm-165 k3s[699204]: time="2024-01-23T15:06:01+02:00" level=warning msg="Unable to fetch coredns config map: configmaps "coredns" not found"
Jan 23 15:07:08 vm-165 k3s[699204]: E0123 15:07:08.894663  699204 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume podName:e5551773-502a-4e54-8d2d-63baf98cc232 nodeName:}" failed. No retries permitted until 2024-01-23 15:09:10.894587981 +0200 EET m=+529.124304231 (durationBeforeRetry 2m2s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume") pod "coredns-6799fbcd5-wzffs" (UID: "e5551773-502a-4e54-8d2d-63baf98cc232") : configmap references non-existent config key: NodeHosts
Jan 23 15:07:33 vm-165 k3s[699204]: E0123 15:07:33.590181  699204 pod_workers.go:1300] "Error syncing pod, skipping" err="unmounted volumes=[config-volume], unattached volumes=[], failed to process volumes=[]: context deadline exceeded" pod="kube-system/coredns-6799fbcd5-wzffs" podUID="e5551773-502a-4e54-8d2d-63baf98cc232"
Jan 23 15:09:10 vm-165 k3s[699204]: E0123 15:09:10.977718  699204 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume podName:e5551773-502a-4e54-8d2d-63baf98cc232 nodeName:}" failed. No retries permitted until 2024-01-23 15:11:12.977656238 +0200 EET m=+651.207372520 (durationBeforeRetry 2m2s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/e5551773-502a-4e54-8d2d-63baf98cc232-config-volume") pod "coredns-6799fbcd5-wzffs" (UID: "e5551773-502a-4e54-8d2d-63baf98cc232") : configmap references non-existent config key: NodeHosts

Please, please attach logs instead of pasting pages and pages into your comment.

I see the same issue when reinstalling k3s on an existing node.
k3s -v
k3s version v1.28.6-rc2+k3s1 (39a00015)
go version go1.20.13

Jan 23 21:08:33 ip-172-31-14-222 k3s[177782]: E0123 21:08:33.181006  177782 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/f8deee67-4280-4982-bb1e-d69722202533-config-volume podName:f8deee67-4280-4982-bb1e-d69722202533 nodeName:}" failed. No retries permitted until 2024-01-23 21:10:35.180986425 +0000 UTC m=+632.873841191 (durationBeforeRetry 2m2s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/f8deee67-4280-4982-bb1e-d69722202533-config-volume") pod "coredns-6799fbcd5-9gx7m" (UID: "f8deee67-4280-4982-bb1e-d69722202533") : configmap references non-existent config key: NodeHosts
Jan 23 21:09:05 ip-172-31-14-222 k3s[177782]: E0123 21:09:05.595085  177782 pod_workers.go:1300] "Error syncing pod, skipping" err="unmounted volumes=[config-volume], unattached volumes=[], failed to process volumes=[]: context deadline exceeded" pod="kube-system/coredns-6799fbcd5-9gx7m" podUID="f8deee67-4280-4982-bb1e-d69722202533"
Jan 23 21:10:02 ip-172-31-14-222 k3s[177782]: time="2024-01-23T21:10:02Z" level=info msg="COMPACT revision 0 has already been compacted"
Jan 23 21:10:35 ip-172-31-14-222 k3s[177782]: E0123 21:10:35.223217  177782 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/f8deee67-4280-4982-bb1e-d69722202533-config-volume podName:f8deee67-4280-4982-bb1e-d69722202533 nodeName:}" failed. No retries permitted until 2024-01-23 21:12:37.223197275 +0000 UTC m=+754.916052040 (durationBeforeRetry 2m2s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/f8deee67-4280-4982-bb1e-d69722202533-config-volume") pod "coredns-6799fbcd5-9gx7m" (UID: "f8deee67-4280-4982-bb1e-d69722202533") : configmap references non-existent config key: NodeHosts

k describe po -n kube-system   coredns-6799fbcd5-9gx7m
Name:                 coredns-6799fbcd5-9gx7m
Namespace:            kube-system
Priority:<PHONE_NUMBER>
Priority Class Name:  system-cluster-critical
Service Account:      coredns
Node:                 ip-172-31-14-222/<IP_ADDRESS>
Start Time:           Tue, 23 Jan 2024 21:00:19 +0000
Labels:               k8s-app=kube-dns
                      pod-template-hash=6799fbcd5
Annotations:          <none>
Status:               Pending
IP:
IPs:                  <none>
Controlled By:        ReplicaSet/coredns-6799fbcd5
Containers:
  coredns:
    Container ID:
    Image:         rancher/mirrored-coredns-coredns:1.10.1
    Image ID:
    Ports:         53/UDP, 53/TCP, 9153/TCP
    Host Ports:    0/UDP, 0/TCP, 0/TCP
    Args:
      -conf
      /etc/coredns/Corefile
    State:          Waiting
      Reason:       ContainerCreating
    Ready:          False
    Restart Count:  0
    Limits:
      memory:  170Mi
    Requests:
      cpu:        100m
      memory:     70Mi
    Liveness:     http-get http://:8080/health delay=60s timeout=1s period=10s #success=1 #failure=3
    Readiness:    http-get http://:8181/ready delay=0s timeout=1s period=2s #success=1 #failure=3
    Environment:  <none>
    Mounts:
      /etc/coredns from config-volume (ro)
      /etc/coredns/custom from custom-config-volume (ro)
      /var/run/secrets/kubernetes.io/serviceaccount from kube-api-access-fb8v9 (ro)
Conditions:
  Type              Status
  Initialized       True
  Ready             False
  ContainersReady   False
  PodScheduled      True
Volumes:
  config-volume:
    Type:      ConfigMap (a volume populated by a ConfigMap)
    Name:      coredns
    Optional:  false
  custom-config-volume:
    Type:      ConfigMap (a volume populated by a ConfigMap)
    Name:      coredns-custom
    Optional:  true
  kube-api-access-fb8v9:
    Type:                     Projected (a volume that contains injected data from multiple sources)
    TokenExpirationSeconds:   3607
    ConfigMapName:            kube-root-ca.crt
    ConfigMapOptional:        <nil>
    DownwardAPI:              true
QoS Class:                    Burstable
Node-Selectors:               kubernetes.io/os=linux
Tolerations:                  CriticalAddonsOnly op=Exists
                              node-role.kubernetes.io/control-plane:NoSchedule op=Exists
                              node-role.kubernetes.io/master:NoSchedule op=Exists
                              node.kubernetes.io/not-ready:NoExecute op=Exists for 300s
                              node.kubernetes.io/unreachable:NoExecute op=Exists for 300s
Topology Spread Constraints:  kubernetes.io/hostname:DoNotSchedule when max skew 1 is exceeded for selector k8s-app=kube-dns
Events:
  Type     Reason       Age                 From               Message
  ----     ------       ----                ----               -------
  Normal   Scheduled    11m                 default-scheduler  Successfully assigned kube-system/coredns-6799fbcd5-9gx7m to ip-172-31-14-222
  Warning  FailedMount  57s (x13 over 11m)  kubelet            MountVolume.SetUp failed for volume "config-volume" : configmap references non-existent config key: NodeHosts

Node looks good
Name:               ip-172-31-14-222
Roles:              control-plane,master
Labels:             beta.kubernetes.io/arch=amd64
                    beta.kubernetes.io/os=linux
                    kubernetes.io/arch=amd64
                    kubernetes.io/hostname=ip-172-31-14-222
                    kubernetes.io/os=linux
                    node-role.appliance.securiti.io/primary=true
                    node-role.kubernetes.io/control-plane=true
                    node-role.kubernetes.io/master=true
                    role=node
Annotations:        flannel.alpha.coreos.com/backend-data: {"VNI":1,"VtepMAC":"76:74:84:50:87:8e"}
                    flannel.alpha.coreos.com/backend-type: vxlan
                    flannel.alpha.coreos.com/kube-subnet-manager: true
                    flannel.alpha.coreos.com/public-ip: <IP_ADDRESS>
                    k3s.io/encryption-config-hash: start-dcca54130d05e9b8b799b299d8b94a668ec0c20a2122be382e838160c7981bd5
                    k3s.io/node-args:
                      ["server","--write-kubeconfig-mode","0600","--token-file","/etc/rancher/k3s/securiti-token","--service-cidr","<IP_ADDRESS>/16","--cluster-cid...
                    k3s.io/node-config-hash: 5K4Q4MGONAD4L4GOVZ64G7I3DBB6O4MU3YFVMK7ZUSSUYUZAJD3Q====
                    k3s.io/node-env: {"K3S_DATA_DIR":"/mnt/rancher/k3s/data/46057a1eb55d262c2ef9480c0ed431b83123f777044ecff60bae0c2906493fb8"}
                    node.alpha.kubernetes.io/ttl: 0
                    volumes.kubernetes.io/controller-managed-attach-detach: true
CreationTimestamp:  Tue, 23 Jan 2024 21:00:14 +0000
Taints:             <none>
Unschedulable:      false
Lease:
  HolderIdentity:  ip-172-31-14-222
  AcquireTime:     <unset>
  RenewTime:       Tue, 23 Jan 2024 21:17:36 +0000
Conditions:
  Type             Status  LastHeartbeatTime                 LastTransitionTime                Reason                       Message
  ----             ------  -----------------                 ------------------                ------                       -------
  MemoryPressure   False   Tue, 23 Jan 2024 21:15:43 +0000   Tue, 23 Jan 2024 21:00:14 +0000   KubeletHasSufficientMemory   kubelet has sufficient memory available
  DiskPressure     False   Tue, 23 Jan 2024 21:15:43 +0000   Tue, 23 Jan 2024 21:00:14 +0000   KubeletHasNoDiskPressure     kubelet has no disk pressure
  PIDPressure      False   Tue, 23 Jan 2024 21:15:43 +0000   Tue, 23 Jan 2024 21:00:14 +0000   KubeletHasSufficientPID      kubelet has sufficient PID available
  Ready            True    Tue, 23 Jan 2024 21:15:43 +0000   Tue, 23 Jan 2024 21:00:14 +0000   KubeletReady                 kubelet is posting ready status. AppArmor enabled
Addresses:
  InternalIP:  <IP_ADDRESS>
  Hostname:    ip-172-31-14-222
Capacity:
  cpu:                8
  ephemeral-storage:  157252588Ki
  hugepages-1Gi:      0
  hugepages-2Mi:      0
  memory:             32300788Ki
  pods:               110
Allocatable:
  cpu:                8
  ephemeral-storage:<PHONE_NUMBER>87
  hugepages-1Gi:      0
  hugepages-2Mi:      0
  memory:             32300788Ki
  pods:               110
System Info:
  Machine ID:                 ec259277641405433b30fac0ae0f31f2
  System UUID:                ec259277-6414-0543-3b30-fac0ae0f31f2
  Boot ID:                    a6ea1790-f248-465b-af26-01cfa5c0a9ed
  Kernel Version:             5.14.21-150400.24.100-default
  OS Image:                   SUSE Linux Enterprise Server 15 SP4
  Operating System:           linux
  Architecture:               amd64
  Container Runtime Version:  containerd://1.7.11-k3s2
  Kubelet Version:            v1.28.6-rc2+k3s1
  Kube-Proxy Version:         v1.28.6-rc2+k3s1
PodCIDR:                      <IP_ADDRESS>/24
PodCIDRs:                     <IP_ADDRESS>/24
Non-terminated Pods:          (3 in total)
  Namespace                   Name                                       CPU Requests  CPU Limits  Memory Requests  Memory Limits  Age
  ---------                   ----                                       ------------  ----------  ---------------  -------------  ---
  kube-system                 coredns-6799fbcd5-9gx7m                    100m (1%)     0 (0%)      70Mi (0%)        170Mi (0%)     17m
  kube-system                 local-path-provisioner-84db5d44d9-j5k6l    0 (0%)        0 (0%)      0 (0%)           0 (0%)         17m
  kube-system                 metrics-server-67c658944b-wkbk8            100m (1%)     0 (0%)      70Mi (0%)        0 (0%)         17m
Allocated resources:
  (Total limits may be over 100 percent, i.e., overcommitted.)
  Resource           Requests    Limits
  --------           --------    ------
  cpu                200m (2%)   0 (0%)
  memory             140Mi (0%)  170Mi (0%)
  ephemeral-storage  0 (0%)      0 (0%)
  hugepages-1Gi      0 (0%)      0 (0%)
  hugepages-2Mi      0 (0%)      0 (0%)
Events:
  Type     Reason                          Age                From             Message
  ----     ------                          ----               ----             -------
  Normal   Starting                        17m                kube-proxy
  Normal   NodePasswordValidationComplete  17m                k3s-supervisor   Deferred node password secret validation complete
  Normal   Starting                        17m                kubelet          Starting kubelet.
  Warning  InvalidDiskCapacity             17m                kubelet          invalid capacity 0 on image filesystem
  Normal   NodeAllocatableEnforced         17m                kubelet          Updated Node Allocatable limit across pods
  Normal   NodeHasSufficientMemory         17m (x2 over 17m)  kubelet          Node ip-172-31-14-222 status is now: NodeHasSufficientMemory
  Normal   NodeHasNoDiskPressure           17m (x2 over 17m)  kubelet          Node ip-172-31-14-222 status is now: NodeHasNoDiskPressure
  Normal   NodeHasSufficientPID            17m (x2 over 17m)  kubelet          Node ip-172-31-14-222 status is now: NodeHasSufficientPID
  Normal   NodeReady                       17m                kubelet          Node ip-172-31-14-222 status is now: NodeReady
  Normal   RegisteredNode                  17m                node-controller  Node ip-172-31-14-222 event: Registered Node ip-172-31-14-222 in Controller

The manifest on disk is missing NodeHosts
apiVersion: v1
kind: ServiceAccount
metadata:
  name: coredns
  namespace: kube-system
---
apiVersion: rbac.authorization.k8s.io/v1
kind: ClusterRole
metadata:
  labels:
    kubernetes.io/bootstrapping: rbac-defaults
  name: system:coredns
rules:
- apiGroups:
  - ""
  resources:
  - endpoints
  - services
  - pods
  - namespaces
  verbs:
  - list
  - watch
- apiGroups:
  - discovery.k8s.io
  resources:
  - endpointslices
  verbs:
  - list
  - watch
---
apiVersion: rbac.authorization.k8s.io/v1
kind: ClusterRoleBinding
metadata:
  annotations:
    rbac.authorization.kubernetes.io/autoupdate: "true"
  labels:
    kubernetes.io/bootstrapping: rbac-defaults
  name: system:coredns
roleRef:
  apiGroup: rbac.authorization.k8s.io
  kind: ClusterRole
  name: system:coredns
subjects:
- kind: ServiceAccount
  name: coredns
  namespace: kube-system
---
apiVersion: v1
kind: ConfigMap
metadata:
  name: coredns
  namespace: kube-system
data:
  Corefile: |
    .:53 {
        errors
        health
        ready
        kubernetes cluster.local in-addr.arpa ip6.arpa {
          pods insecure
          fallthrough in-addr.arpa ip6.arpa
        }
        hosts /etc/coredns/NodeHosts {
          ttl 60
          reload 15s
          fallthrough
        }
        prometheus :9153
        forward . /etc/resolv.conf
        cache 30
        loop
        reload
        loadbalance
        import /etc/coredns/custom/*.override
    }
    import /etc/coredns/custom/*.server
---
apiVersion: apps/v1
kind: Deployment
metadata:
  name: coredns
  namespace: kube-system
  labels:
    k8s-app: kube-dns
    kubernetes.io/name: "CoreDNS"
spec:
  revisionHistoryLimit: 0
  strategy:
    type: RollingUpdate
    rollingUpdate:
      maxUnavailable: 1
  selector:
    matchLabels:
      k8s-app: kube-dns
  template:
    metadata:
      labels:
        k8s-app: kube-dns
    spec:
      priorityClassName: "system-cluster-critical"
      serviceAccountName: coredns
      tolerations:
        - key: "CriticalAddonsOnly"
          operator: "Exists"
        - key: "node-role.kubernetes.io/control-plane"
          operator: "Exists"
          effect: "NoSchedule"
        - key: "node-role.kubernetes.io/master"
          operator: "Exists"
          effect: "NoSchedule"
      nodeSelector:
        kubernetes.io/os: linux
      topologySpreadConstraints:
        - maxSkew: 1
          topologyKey: kubernetes.io/hostname
          whenUnsatisfiable: DoNotSchedule
          labelSelector:
            matchLabels:
              k8s-app: kube-dns
      containers:
      - name: coredns
        image: rancher/mirrored-coredns-coredns:1.10.1
        imagePullPolicy: IfNotPresent
        resources:
          limits:
            memory: 170Mi
          requests:
            cpu: 100m
            memory: 70Mi
        args: [ "-conf", "/etc/coredns/Corefile" ]
        volumeMounts:
        - name: config-volume
          mountPath: /etc/coredns
          readOnly: true
        - name: custom-config-volume
          mountPath: /etc/coredns/custom
          readOnly: true
        ports:
        - containerPort: 53
          name: dns
          protocol: UDP
        - containerPort: 53
          name: dns-tcp
          protocol: TCP
        - containerPort: 9153
          name: metrics
          protocol: TCP
        securityContext:
          allowPrivilegeEscalation: false
          capabilities:
            add:
            - NET_BIND_SERVICE
            drop:
            - all
          readOnlyRootFilesystem: true
        livenessProbe:
          httpGet:
            path: /health
            port: 8080
            scheme: HTTP
          initialDelaySeconds: 60
          periodSeconds: 10
          timeoutSeconds: 1
          successThreshold: 1
          failureThreshold: 3
        readinessProbe:
          httpGet:
            path: /ready
            port: 8181
            scheme: HTTP
          initialDelaySeconds: 0
          periodSeconds: 2
          timeoutSeconds: 1
          successThreshold: 1
          failureThreshold: 3
      dnsPolicy: Default
      volumes:
        - name: config-volume
          configMap:
            name: coredns
            items:
            - key: Corefile
              path: Corefile
            - key: NodeHosts
              path: NodeHosts
        - name: custom-config-volume
          configMap:
            name: coredns-custom
            optional: true
---
apiVersion: v1
kind: Service
metadata:
  name: kube-dns
  namespace: kube-system
  annotations:
    prometheus.io/port: "9153"
    prometheus.io/scrape: "true"
  labels:
    k8s-app: kube-dns
    kubernetes.io/cluster-service: "true"
    kubernetes.io/name: "CoreDNS"
spec:
  selector:
    k8s-app: kube-dns
  clusterIP: <IP_ADDRESS>
  clusterIPs: [<IP_ADDRESS>]
  ports:
  - name: dns
    port: 53
    protocol: UDP
  - name: dns-tcp
    port: 53
    protocol: TCP
  - name: metrics
    port: 9153
    protocol: TCP
  ipFamilyPolicy: SingleStack

The only relevant line in the logs
Jan 22 23:20:13 ip-172-31-14-222 k3s[60896]: W0122 23:20:13.562441   60896 reflector.go:458] k8s.io/client-go@v1.28.6-k3s1/tools/cache/reflector.go:229: watch of *v1.Node ended with: an error on the server ("unable to decode an event from the watch stream: context canceled") has prevented the request from succeeding
Jan 23 21:00:02 ip-172-31-14-222 k3s[177782]: time="2024-01-23T21:00:02Z" level=error msg="error while range on /registry/serviceaccounts/ /registry/serviceaccounts/: context canceled"
Jan 23 21:00:02 ip-172-31-14-222 k3s[177782]: time="2024-01-23T21:00:02Z" level=error msg="error while range on /registry/serviceaccounts/ /registry/serviceaccounts/: context canceled"
Jan 23 21:00:03 ip-172-31-14-222 k3s[177782]: E0123 21:00:03.287253  177782 controller.go:102] Error removing old endpoints from kubernetes service: no API server IP addresses were listed in storage, refusing to erase all endpoints for the kubernetes Service

The manifest on disk isn't intended to have that key. It's supposed to be added and modified by a controller that runs on the servers. However that controller has logger errors complaining that the configmap itself does not exist. Are you able to view that configmap in the running cluster?

In my setup the configmap is visible in the cluster but still controller is unable to fetch configmap.
configmap.yaml.log

Yes, I see this on both versions 1.28 and 1.29. To me it happens when trying to upgrade k3s:

Install k3s 1.27.X
upgrade to 1.28.X or 1.29.X
uninstall k3s

repeat the same loop again on the same VM.
If the VM is fresh, the installation goes through. But this is important for us to make sure that upgrade to a production will not have same problem, hence I am trying to figure out the root cause of it.

I have a customer with seemingly this same issue, v1.28.5+k3s1
The CoreDNS pods are not starting due to the missing NodeHosts key in the ConfigMap.
k3s.node.yaml.txt
k3s-any.log
coredns configmap.yaml.txt
cored-dns-pod.yaml.txt

@safderali5 what process are you using to upgrade from 1.27? When you upgrade to 1.29, are you stepping through 1.28 first?
Similarly, how are you uninstalling k3s? Can you confirm that the uninstall script is completing successfully and all files are removed from disk?

@harrisonbc was your cluster in question also upgraded, and if so from what version?

I will find out

@safderali5 your kubectl get node output is inconsistent, but at least one of your nodes is using a non-standard data-dir:
k3s.io/node-env: {"K3S_DATA_DIR":"/mnt/rancher/k3s/data/46057a1eb55d262c2ef9480c0ed431b83123f777044ecff60bae0c2906493fb8"}
The uninstall script only removes content from the default data-dir at /var/lib/rancher/k3s, so you are not actually uninstalling K3s unless you manually remove the content from this path. I suspect you are simply re-testing on the same cluster over and over again.

@brandond  it's @harsimranmaan  nodes that are using non standard data dir.

@safderali5 what process are you using to upgrade from 1.27? When you upgrade to 1.29, are you stepping through 1.28 first? Can you list the specific patch releases that you are upgrading from and to?
Similarly, how are you uninstalling k3s? Can you confirm that the uninstall script is completing successfully and all files are removed from disk?

I am using uninstall script generated by k3s and located at /usr/local/bin/k3s-uninstall.sh.

I have done a fresh trial on a VM running k3s 1.28.5+k3s1, Steps include.

Remove existing installation using script /usr/local/bin/k3s-uninstall.sh. (This installation had same problem)
Reinstall the same version 1.28.5+k3s1 again on the same host

Problem is still the same, coredns configmap is not updated with NodeHosts.
Here are the logs of this trial:
coredns-configmap.yaml.log
coredns-pod.log
k3s.log
node.yaml.log
uninstall-old-k3s.log

You've not mentioned this this at any point, but from your node yaml I see that you have a bunch of extra configuration and env vars. Several of the env vars are not used by K3s itself for anything, and I am unsure what you're trying to achieve by setting them.
Can you provide the exact command you are running to install k3s, along with any config that you are placing in config.yaml, and any other config that you are passing to the core Kubernetes components, such as the audit policy file? Please also call out anything that you're deploying to the cluster that might restrict or otherwise interfere with access to resources, such as OPA Gatekeeper or Kyverno.
Also, I see that you're are using a custom data-dir on some of the nodes; is this still something you're doing when testing?
k3s.io/node-args:
  - server
  - --cluster-init
  - "true"
  - --disable
  - traefik
  - --default-local-storage-path
  - /var/lib/rancher/storage
  - --disable-helm-controller
  - "true"
  - --https-listen-port
  - "6443"
  - --kube-apiserver-arg
  - audit-log-path=/var/lib/rancher/k3s/server/logs/audit.log
  - --kube-apiserver-arg
  - audit-policy-file=/var/lib/rancher/k3s/server/audit.yaml
  - --kube-apiserver-arg
  - audit-log-maxage=30
  - --kube-apiserver-arg
  - audit-log-maxbackup=10
  - --kube-apiserver-arg
  - audit-log-maxsize=100
  - --kube-apiserver-arg
  - request-timeout=300s
  - --kube-apiserver-arg
  - service-account-lookup=true
  - --kube-apiserver-arg
  - anonymous-auth=false
  - --kube-cloud-controller-manager-arg
  - webhook-secure-port=0
  - --kube-controller-manager-arg
  - terminated-pod-gc-threshold=12500
  - --kube-controller-manager-arg
  - use-service-account-credentials=true
  - --kubelet-arg
  - container-log-max-files=4
  - --kubelet-arg
  - container-log-max-size=50Mi
  - --kubelet-arg
  - streaming-connection-idle-timeout=5m
  - --kubelet-arg
  - make-iptables-util-chains=true
  - --node-external-ip
  - <IP_ADDRESS>
  - --node-name
  - vm-165.tests.lab.net
  - --prefer-bundled-bin
  - "true"
  - --protect-kernel-defaults
  - "true"
  - --secrets-encryption
  - "true"
  - --tls-san
  - <IP_ADDRESS>
  - --write-kubeconfig-mode
  - "0600"
k3s.io/node-env:
  K3S_DATA_DIR: /var/lib/rancher/k3s/data/28f7e87eba734b7f7731dc900e2c84e0e98ce869f3dcf57f65dc7bbb80e12e56
  K3S_INTERNAL_CERTS_EXPIRATION_DAYS: "730"
  K3S_UPGRADE: "false"

My installation method is:
    export INSTALL_K3S_SELINUX_WARN=true
    export INSTALL_K3S_SKIP_DOWNLOAD=true
    export INSTALL_K3S_SKIP_SELINUX_RPM=true
    ./install.sh

The script install.sh is from k3s source code of version 1.28.5+k3s1.
While the config.yam passed to the k3s is:
cluster-init: true
disable:
  - traefik
default-local-storage-path: /var/lib/rancher/storage
disable-helm-controller: true
https-listen-port: 6443
kube-apiserver-arg:
  - 'audit-log-path=/var/lib/rancher/k3s/server/logs/audit.log'
  - 'request-timeout=300s'
  - 'service-account-lookup=true'
  - 'anonymous-auth=false'
kube-cloud-controller-manager-arg:
  - 'webhook-secure-port=0'
kube-controller-manager-arg:
  - 'terminated-pod-gc-threshold=12500'
  - 'use-service-account-credentials=true'
kubelet-arg:
  - 'container-log-max-files=4'
  - 'container-log-max-size=50Mi'
  - 'streaming-connection-idle-timeout=5m'
  - 'make-iptables-util-chains=true'
node-external-ip: <IP_ADDRESS>
node-name: vm-139.tests.lab.net
prefer-bundled-bin: true
protect-kernel-defaults: true
secrets-encryption: true
tls-san:
  - <IP_ADDRESS>
write-kubeconfig-mode: "0600"

There is custom path used for persistent storage used by local path provisioner. Other storage paths are default in my setup.

The node external IP is set so that loadbalancer service shall get that IP, as per the docs:
"If the ServiceLB Pod runs on a node that has an external IP configured, the node's external IP is populated into the Service's status.loadBalancer.ingress address list"

Where are the  K3S_INTERNAL_CERTS_EXPIRATION_DAYS=730 and K3S_UPGRADE=false env vars coming from?

"If the ServiceLB Pod runs on a node that has an external IP configured, the node's external IP is populated into the Service's status.loadBalancer.ingress address list"

Right, and if there is no external IP, then the internal IP is used. The external IP overrides the internal IP. If they are the same, you should not set it.

I was facing the very same odd behavior when the coredns CM did not contain the NodeHosts entry, here is the plain config to reproduce the problem:
# mkdir -p /var/lib/rancher/k3s/agent/images
# curl -fsSL https://github.com/k3s-io/k3s/releases/download/v1.28.5%2Bk3s1/k3s-airgap-images-amd64.tar.zst -o /var/lib/rancher/k3s/agent/images/k3s-airgap-images.tar.zst
# export INSTALL_K3S_SKIP_DOWNLOAD="true"
# export INSTALL_K3S_VERSION: "v1.28.5+k3s1"
# export INSTALL_K3S_EXEC="server --node-ip=<IP_ADDRESS> --flannel-iface=enp0s8 --write-kubeconfig-mode=644 --kube-apiserver-arg=service-node-port-range=30000-30100 --secrets-encryption --disable=traefik --disable=servicelb --disable-helm-controller --disable-network-policy --kubelet-arg cloud-provider=external"
# curl -sfL https://get.k3s.io | sh -

the node itself was in absolutely normal shape:
status:
  addresses:
  - address: <IP_ADDRESS>
    type: InternalIP
  - address: master
    type: Hostname

but the coredns pod wasn`t starting because of the missing entry in the CM, the k3s systemd unit has had many failed attempts to read the entire CM like this:
Jan 28 23:01:51 master k3s[2619]: time="2024-01-28T23:01:51Z" level=warning msg="Unable to fetch coredns config map: configmaps \"coredns\" not found"

apparently, caused by https://github.com/k3s-io/k3s/blob/master/pkg/node/controller.go#L81
I run sudo systemctl restart k3s.service and the problem has disappeared, it's able to identify the CM properly.

I assume there's some kind of a race-condition, when the controller is too fast to read this data from the CM, fails, then coredns deployment kicks in and stuck trying to access missing CM reference in the deployment in here

The controller's cache should get populated eventually; it should succeed after a few retries at worst. I'm curious what's preventing the configmap cache from getting filled.

@avoidik  I am running that same release of K3s with the same args and I am unable to reproduce:
      k3s.io/node-args: '["server","--node-ip","<IP_ADDRESS>","--flannel-iface","eth0","--write-kubeconfig-mode","644","--kube-apiserver-arg","service-node-port-range=30000-30100","--secrets-encryption","--disable","traefik","--disable","servicelb","--disable-helm-controller","--disable-network-policy","--kubelet-arg","cloud-provider=external","--debug"]

If you start k3s with --debug you should see a log message when the configmap is created, after which the
I0129 21:39:18.945026      53 shared_informer.go:311] Waiting for caches to sync for configmaps
I0129 21:39:19.045107      53 shared_informer.go:318] Caches are synced for configmaps
WARN[0004] Unable to fetch coredns config map: configmaps "coredns" not found
WARN[0004] Unable to fetch coredns config map: configmaps "coredns" not found
INFO[0004] Cluster dns configmap has been set successfully
WARN[0004] Unable to fetch coredns config map: configmaps "coredns" not found
WARN[0004] Unable to fetch coredns config map: configmaps "coredns" not found
INFO[0004] Starting /v1, Kind=ConfigMap controller
WARN[0005] Unable to fetch coredns config map: configmaps "coredns" not found
DEBU[0006] DesiredSet - Created /v1, Kind=ConfigMap kube-system/coredns for  kube-system/coredns
DEBU[0006] DesiredSet - Created /v1, Kind=ConfigMap kube-system/local-path-config for  kube-system/local-storage
INFO[0007] Updated coredns node hosts entry [<IP_ADDRESS> k3s-server-1]

Is the coredns pod still in the ContainerCreating state?

No, because the node host entry was added - see the last log line.
brandond@dev01:~$ kubectl get pod -A -o wide
NAMESPACE     NAME                                      READY   STATUS    RESTARTS   AGE   IP          NODE           NOMINATED NODE   READINESS GATES
kube-system   coredns-6799fbcd5-rwxbb                   1/1     Running   0          20m   <IP_ADDRESS>   k3s-server-1   <none>           <none>
kube-system   local-path-provisioner-84db5d44d9-8qpgx   1/1     Running   0          20m   <IP_ADDRESS>   k3s-server-1   <none>           <none>
kube-system   metrics-server-67c658944b-69lvq           1/1     Running   0          20m   <IP_ADDRESS>   k3s-server-1   <none>           <none>

@brandond I now see what's going on when the --debug flag is set, I was using just a single master-node cluster without the worker nodes booted, I saw the following messages on repeat:
Feb 04 14:05:28 master k3s[2552]: E0204 14:05:28.564159    2552 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/bf89b133-b239-422f-b721-2f03c096caeb-config-volume podName:bf89b133-b239-422f-b721-2f03c096caeb nodeName:}" failed. No retries permitted until 2024-02-04 14:07:30.564092871 +0000 UTC m=+270.574186074 (durationBeforeRetry 2m2s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/bf89b133-b239-422f-b721-2f03c096caeb-config-volume") pod "coredns-6799fbcd5-b2nl4" (UID: "bf89b133-b239-422f-b721-2f03c096caeb") : configmap references non-existent config key: NodeHosts
...
Feb 04 14:07:30 master k3s[2552]: E0204 14:07:30.634478    2552 nestedpendingoperations.go:348] Operation for "{volumeName:kubernetes.io/configmap/bf89b133-b239-422f-b721-2f03c096caeb-config-volume podName:bf89b133-b239-422f-b721-2f03c096caeb nodeName:}" failed. No retries permitted until 2024-02-04 14:09:32.634419534 +0000 UTC m=+392.644512724 (durationBeforeRetry 2m2s). Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/bf89b133-b239-422f-b721-2f03c096caeb-config-volume") pod "coredns-6799fbcd5-b2nl4" (UID: "bf89b133-b239-422f-b721-2f03c096caeb") : configmap references non-existent config key: NodeHosts
...
Feb 04 14:07:37 master k3s[2552]: E0204 14:07:37.245568    2552 pod_workers.go:1300] "Error syncing pod, skipping" err="unmounted volumes=[config-volume], unattached volumes=[], failed to process volumes=[]: context deadline exceeded" pod="kube-system/coredns-6799fbcd5-b2nl4" podUID="bf89b133-b239-422f-b721-2f03c096caeb"
...
Feb 04 14:08:34 master k3s[2552]: time="2024-02-04T14:08:34Z" level=debug msg="Tunnel server egress proxy updating Node master IP <IP_ADDRESS>/32"
...
Feb 04 14:08:34 master k3s[2552]: time="2024-02-04T14:08:34Z" level=warning msg="Unable to fetch coredns config map: configmaps \"coredns\" not found"
...

and here is pending coredns pod status (10 minutes was not enough to recover):
$ kubectl get pods -n kube-system
NAME                                      READY   STATUS              RESTARTS   AGE
coredns-6799fbcd5-b2nl4                   0/1     ContainerCreating   0          10m
local-path-provisioner-84db5d44d9-7lnnh   1/1     Running             0          10m
metrics-server-67c658944b-6h227           1/1     Running             0          10m

here is a sample Vagrantfile which could help to reproduce the problem in isolation:
ENV_DEFAULTS = {
  INSTALL_K3S_SKIP_DOWNLOAD: "true",
  INSTALL_K3S_VERSION: "v1.28.5+k3s1",
  K3S_TOKEN: "43bf98d8fb25e7fd4275ae06f33adacd",
  IFACE_NAME: "enp0s8",
}

Vagrant.configure(2) do |config|
  config.vm.define 'master' do |master|
    master.vm.box = 'ubuntu/focal64'
    master.vm.hostname = 'master'
    master.vm.synced_folder '.', '/vagrant', type: 'virtualbox'
    master.vm.network 'private_network', ip: '<IP_ADDRESS>'
    master.vm.provider 'virtualbox' do |v|
      v.memory = 2048
      v.cpus = 2
      v.name = 'k3s-master-01'
      v.customize ['modifyvm', :id, '--audio', 'none']
      v.customize ["modifyvm", :id, "--ioapic", 'on']
    end
    master.vm.provision 'shell', env: ENV_DEFAULTS, inline: <<-'SHELL'
      curl -fsSL https://get.k3s.io -o install.sh
      curl -fsSL https://github.com/k3s-io/k3s/releases/download/$INSTALL_K3S_VERSION/k3s -o /usr/local/bin/k3s
      chmod +x /usr/local/bin/k3s
      mkdir -p /var/lib/rancher/k3s/agent/images
      curl -fsSL https://github.com/k3s-io/k3s/releases/download/$INSTALL_K3S_VERSION/k3s-airgap-images-amd64.tar.zst -o /var/lib/rancher/k3s/agent/images/k3s-airgap-images.tar.zst
      IPADDR="$(ip addr show ${IFACE_NAME} | grep 'inet ' | awk '{print $2;}' | cut -d'/' -f1)"
      export INSTALL_K3S_EXEC="server --node-ip=${IPADDR} --flannel-iface=${IFACE_NAME} --write-kubeconfig-mode=644 --kube-apiserver-arg=service-node-port-range=30000-30100 --secrets-encryption --disable=traefik --disable=servicelb --disable-helm-controller --disable-network-policy --kubelet-arg cloud-provider=external --debug"
      sh install.sh
      if [ -f /etc/rancher/k3s/k3s.yaml ]; then
        cp /etc/rancher/k3s/k3s.yaml /tmp/
        sed -i "s/<IP_ADDRESS>/${IPADDR}/" /tmp/k3s.yaml
        mkdir -p /home/vagrant/.kube
        cp /tmp/k3s.yaml /home/vagrant/.kube/config
        cp /tmp/k3s.yaml /vagrant/
        rm -f /tmp/k3s.yaml
        chown -R vagrant:vagrant /home/vagrant/.kube
      fi
    SHELL
  end
end

# vagrant up
# export KUBECONFIG="$(pwd)/k3s.yaml"
# kubectl get nodes
# kubectl get pods -n kube-system
# vagrant ssh

interesting observation, it works as expected if I'd comment out the part where the airgapped images being downloaded, this makes me think about the assumption regarding the race condition I made before
# mkdir -p /var/lib/rancher/k3s/agent/images
# curl -fsSL https://github.com/k3s-io/k3s/releases/download/$INSTALL_K3S_VERSION/k3s-airgap-images-amd64.tar.zst -o /var/lib/rancher/k3s/agent/images/k3s-airgap-images.tar.zst

I think the key here is the startup being delayed a bit by the image import, combined with the helm controller being disabled. That results in the node controller running too late to trigger initialization of the configmap cache.

Validated on Version:
-$ k3s version v1.29.1+k3s-de825845 (de825845)

Environment Details
Infrastructure
Cloud EC2 instance
Node(s) CPU architecture, OS, and Version:
PRETTY_NAME="Ubuntu 22.04.1 LTS"
NAME="Ubuntu"
VERSION_ID="22.04"
Cluster Configuration:
1 server node
Steps to validate the fix

Install k3s from airgap releases
Start k3s with those flags:

 --node-ip={internal-ip} --flannel-iface={proper-interface} --write-kubeconfig-mode=644 --kube-apiserver-arg=service-node-port-range=30000-30100 --secrets-encryption --disable=traefik --disable=servicelb --disable-helm-controller --disable-network-policy --kubelet-arg cloud-provider=external --debug

Validate nodes and pods are all ok
Validate that coredns is starting and running correctly

Reproduction Issue:

 export INSTALL_K3S_VERSION="v1.29.1-rc2+k3s2"
mkdir -p /var/lib/rancher/k3s/agent/images
curl -fsSL https://github.com/k3s-io/k3s/releases/download/${INSTALL_K3S_VERSION}/k3s-airgap-images-amd64.tar.zst -o /var/lib/rancher/k3s/agent/images/k3s-airgap-images.tar.zst
curl -fsSL get.k3s.io | sh -s - --node-ip=internal-ip --flannel-iface={proper-local-interface} --write-kubeconfig-mode=644 --kube-apiserver-arg=service-node-port-range=30000-30100 --secrets-encryption --disable=traefik --disable=servicelb --disable-helm-controller --disable-network-policy --kubelet-arg cloud-provider=external --debug

~$ kgn
NAME               STATUS   ROLES                  AGE   VERSION
ip-    Ready    control-plane,master   42s   v1.28.5+k3s1

$ journalctl -eu k3s |
 Error: MountVolume.SetUp failed for volume "config-volume" (UniqueName: "kubernetes.io/configmap/9cd2f346-b205-4a0c-92c4-24df86fa190f-config-volume") pod "coredns-6799fbcd5-x7md2" (UID: "9cd2f346-b205-4a0c-92c4-24df86fa190f") : configmap references non-existent config key: NodeHosts

~$ kgp -A
NAMESPACE     NAME                                      READY   STATUS              RESTARTS   AGE
kube-system   coredns-6799fbcd5-x7md2                   0/1     ContainerCreating   0          2m11s
kube-system   local-path-provisioner-84db5d44d9-s6g6h   1/1     Running             0          2m11s
kube-system   metrics-server-67c658944b-wjc7l           1/1     Running             0          2m11s

Validation Results:

 ~$ k3s -v
k3s version v1.29.1+k3s-de825845 (de825845)
go version go1.21.6

$ k3s kubectl get nodes
NAME              STATUS   ROLES                  AGE   VERSION
ip-   Ready    control-plane,master   20m   v1.29.1+k3s-de825845

 $ k3s kubectl get pods -A
NAMESPACE     NAME                                      READY   STATUS    RESTARTS      AGE
kube-system   local-path-provisioner-6c86858495-dr6sc   1/1     Running   1 (45m ago)   50m
kube-system   coredns-6799fbcd5-cst6j                   1/1     Running   0             50m
kube-system   metrics-server-67c658944b-whd7k           1/1     Running   0             50m

Hi, I have this happening in a fresh Hetzner Cloud VM with k3s version v1.29.4+k3s1 (94e29e2e). Basically I have the same error message, and same behaviour as others in this thread. However, systemctl restart k3s.service doesn't help me.
It's not an airgap install, it's a basic one. This is the relevant part of my cloud-init:

cloud-init
runcmd:
  # 1 setup k3s
  - >
    curl -sfL https://get.k3s.io | sh -s - server
    --cluster-init
    --disable-cloud-controller
    --node-name="$(hostname -f)"
    --kubelet-arg="cloud-provider=external"
    --secrets-encryption

  # 2 setup helm
  - curl -fsSL https://raw.githubusercontent.com/helm/helm/main/scripts/get-helm-3 | bash

  # 3 install Hetzner Cloud Controller Manager
  #   a) setup the api token
  - kubectl -n kube-system create secret generic hcloud --from-literal=token=SECRET_VALUE

  #   b) install hccm via helm
  - >
    helm repo add hcloud https://charts.hetzner.cloud &&
    helm repo update hcloud &&
    helm --kubeconfig /etc/rancher/k3s/k3s.yaml install hccm hcloud/hcloud-cloud-controller-manager -n kube-system

What else should I provide to help debug this?

@InCogNiTo124 please open a new issue describing your configuration. It does not sound like the same problem.

Hi, I have this happening in a fresh Hetzner Cloud VM with k3s version v1.29.4+k3s1 (94e29e2e). Basically I have the same error message, and same behaviour as others in this thread. However, systemctl restart k3s.service doesn't help me.

After painful few months, I seem to have fixed it by disabling public ipv6 on a Hetzner instance. I'm finally successfully running something after v1.28.6+k3s2 (eg v1.30.6+k3s1 works)