nightkr
commented
2 years ago Stopping my old k3d cluster that was running in the background seems to have resolved the issue, and new clusters create fine again.
Curiously, kind also failed to create any clusters, with the following node logs:
docker logs kind-control-plane -f
``` INFO: ensuring we can execute mount/umount even with userns-remap INFO: remounting /sys read-only INFO: making mounts shared INFO: detected cgroup v2 INFO: clearing and regenerating /etc/machine-id Initializing machine ID from random generator. INFO: faking /sys/class/dmi/id/product_name to be "kind" INFO: faking /sys/class/dmi/id/product_uuid to be random INFO: faking /sys/devices/virtual/dmi/id/product_uuid as well INFO: setting iptables to detected mode: legacy INFO: Detected IPv4 address: 172.23.0.2 INFO: Detected IPv6 address: fc00:f853:ccd:e793::2 systemd 248.3-1ubuntu8.1 running in system mode. (+PAM +AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT +GNUTLS -OPENSSL +ACL +BLKID +CURL +ELFUTILS -FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP -LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified) Detected virtualization docker. Detected architecture x86-64. Welcome to Ubuntu 21.10! Failed to create control group inotify object: Too many open files Failed to allocate manager object: Too many open files [!!!!!!] Failed to allocate manager object. Exiting PID 1... INFO: ensuring we can execute mount/umount even with userns-remap INFO: remounting /sys read-only INFO: making mounts shared INFO: detected cgroup v2 INFO: clearing and regenerating /etc/machine-id Initializing machine ID from random generator. INFO: faking /sys/class/dmi/id/product_name to be "kind" INFO: faking /sys/class/dmi/id/product_uuid to be random INFO: faking /sys/devices/virtual/dmi/id/product_uuid as well INFO: setting iptables to detected mode: legacy INFO: Detected IPv4 address: 172.23.0.2 INFO: Detected old IPv4 address: 172.23.0.2 sed: can't read /etc/kubernetes/manifests/*.yaml: No such file or directory sed: can't read /var/lib/kubelet/kubeadm-flags.env: No such file or directory INFO: Detected IPv6 address: fc00:f853:ccd:e793::2 INFO: Detected old IPv6 address: fc00:f853:ccd:e793::2 sed: can't read /etc/kubernetes/manifests/*.yaml: No such file or directory sed: can't read /var/lib/kubelet/kubeadm-flags.env: No such file or directory systemd 248.3-1ubuntu8.1 running in system mode. (+PAM +AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT +GNUTLS -OPENSSL +ACL +BLKID +CURL +ELFUTILS -FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP -LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified) Detected virtualization docker. Detected architecture x86-64. Welcome to Ubuntu 21.10! Failed to create control group inotify object: Too many open files Failed to allocate manager object: Too many open files [!!!!!!] Failed to allocate manager object. Exiting PID 1... ```This seems to suggest that the k3d cluster was leaking inotify watches somewhere.. My inotify limits are already quite astronomical:
$ sudo sysctl -a | grep inotify
fs.inotify.max_queued_events = 16384
fs.inotify.max_user_instances = 1024
fs.inotify.max_user_watches = 524288
user.max_inotify_instances = 1024
user.max_inotify_watches = 524288
iwilltry42
aitorpazos
What did you do
How was the cluster created?
k3d cluster create fooWhat did you do afterwards?
kubectl run foo --image=busybox --rm -it) and noticed that it seemed to hang on startupkubectl describe pod foo) and noted that it was never scheduled to a Nodekubectl get nodes) and noted that no Node objects existWhat did you expect to happen
Podshould run and give me a shell.Node.Screenshots or terminal output
kubectl run/describe/get
``` $ kubectl run foo --image=busybox --rm -it& $ kubectl describe pod foo Name: foo Namespace: default Priority: 0 Node:Curiously, the server container logs keep complaining about being unable to find
runtime.v1alpha2.RuntimeService:server container logs
``` time="2022-02-11T11:22:29Z" level=info msg="Starting k3s v1.22.2+k3s2 (3f5774b4)" time="2022-02-11T11:22:29Z" level=info msg="Configuring sqlite3 database connection pooling: maxIdleConns=2, maxOpenConns=0, connMaxLifetime=0s" time="2022-02-11T11:22:29Z" level=info msg="Configuring database table schema and indexes, this may take a moment..." time="2022-02-11T11:22:29Z" level=info msg="Database tables and indexes are up to date" time="2022-02-11T11:22:29Z" level=info msg="Kine available at unix://kine.sock" time="2022-02-11T11:22:29Z" level=info msg="certificate CN=system:admin,O=system:masters signed by CN=k3s-client-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:29 +0000 UTC" time="2022-02-11T11:22:29Z" level=info msg="certificate CN=system:kube-controller-manager signed by CN=k3s-client-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:29 +0000 UTC" time="2022-02-11T11:22:29Z" level=info msg="certificate CN=system:kube-scheduler signed by CN=k3s-client-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:29 +0000 UTC" time="2022-02-11T11:22:29Z" level=info msg="certificate CN=kube-apiserver signed by CN=k3s-client-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:29 +0000 UTC" time="2022-02-11T11:22:29Z" level=info msg="certificate CN=system:kube-proxy signed by CN=k3s-client-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:29 +0000 UTC" time="2022-02-11T11:22:29Z" level=info msg="certificate CN=system:k3s-controller signed by CN=k3s-client-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:29 +0000 UTC" time="2022-02-11T11:22:29Z" level=info msg="certificate CN=k3s-cloud-controller-manager signed by CN=k3s-client-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:29 +0000 UTC" time="2022-02-11T11:22:29Z" level=info msg="certificate CN=kube-apiserver signed by CN=k3s-server-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:29 +0000 UTC" time="2022-02-11T11:22:29Z" level=info msg="certificate CN=system:auth-proxy signed by CN=k3s-request-header-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:29 +0000 UTC" time="2022-02-11T11:22:29Z" level=info msg="certificate CN=etcd-server signed by CN=etcd-server-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:29 +0000 UTC" time="2022-02-11T11:22:29Z" level=info msg="certificate CN=etcd-client signed by CN=etcd-server-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:29 +0000 UTC" time="2022-02-11T11:22:29Z" level=info msg="certificate CN=etcd-peer signed by CN=etcd-peer-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:29 +0000 UTC" time="2022-02-11T11:22:29Z" level=info msg="certificate CN=k3s,O=k3s signed by CN=k3s-server-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:29 +0000 UTC" time="2022-02-11T11:22:29Z" level=info msg="Active TLS secret (ver=) (count 10): map[listener.cattle.io/cn-0.0.0.0:0.0.0.0 listener.cattle.io/cn-10.43.0.1:10.43.0.1 listener.cattle.io/cn-127.0.0.1:127.0.0.1 listener.cattle.io/cn-172.29.0.3:172.29.0.3 listener.cattle.io/cn-k3d-foo-server-0:k3d-foo-server-0 listener.cattle.io/cn-kubernetes:kubernetes listener.cattle.io/cn-kubernetes.default:kubernetes.default listener.cattle.io/cn-kubernetes.default.svc:kubernetes.default.svc listener.cattle.io/cn-kubernetes.default.svc.cluster.local:kubernetes.default.svc.cluster.local listener.cattle.io/cn-localhost:localhost listener.cattle.io/fingerprint:SHA1=FB473CA2A839175D300220BA26E34D832FC636FF]" time="2022-02-11T11:22:29Z" level=info msg="Running kube-apiserver --advertise-port=6443 --allow-privileged=true --anonymous-auth=false --api-audiences=https://kubernetes.default.svc.cluster.local,k3s --authorization-mode=Node,RBAC --bind-address=127.0.0.1 --cert-dir=/var/lib/rancher/k3s/server/tls/temporary-certs --client-ca-file=/var/lib/rancher/k3s/server/tls/client-ca.crt --enable-admission-plugins=NodeRestriction --etcd-servers=unix://kine.sock --feature-gates=JobTrackingWithFinalizers=true --insecure-port=0 --kubelet-certificate-authority=/var/lib/rancher/k3s/server/tls/server-ca.crt --kubelet-client-certificate=/var/lib/rancher/k3s/server/tls/client-kube-apiserver.crt --kubelet-client-key=/var/lib/rancher/k3s/server/tls/client-kube-apiserver.key --profiling=false --proxy-client-cert-file=/var/lib/rancher/k3s/server/tls/client-auth-proxy.crt --proxy-client-key-file=/var/lib/rancher/k3s/server/tls/client-auth-proxy.key --requestheader-allowed-names=system:auth-proxy --requestheader-client-ca-file=/var/lib/rancher/k3s/server/tls/request-header-ca.crt --requestheader-extra-headers-prefix=X-Remote-Extra- --requestheader-group-headers=X-Remote-Group --requestheader-username-headers=X-Remote-User --secure-port=6444 --service-account-issuer=https://kubernetes.default.svc.cluster.local --service-account-key-file=/var/lib/rancher/k3s/server/tls/service.key --service-account-signing-key-file=/var/lib/rancher/k3s/server/tls/service.key --service-cluster-ip-range=10.43.0.0/16 --service-node-port-range=30000-32767 --storage-backend=etcd3 --tls-cert-file=/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.crt --tls-private-key-file=/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.key" Flag --insecure-port has been deprecated, This flag has no effect now and will be removed in v1.24. I0211 11:22:29.536471 7 server.go:581] external host was not specified, using 172.29.0.3 I0211 11:22:29.536705 7 server.go:175] Version: v1.22.2+k3s2 I0211 11:22:29.768202 7 shared_informer.go:240] Waiting for caches to sync for node_authorizer I0211 11:22:29.768873 7 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. I0211 11:22:29.768881 7 plugins.go:161] Loaded 11 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota. I0211 11:22:29.769595 7 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. I0211 11:22:29.769602 7 plugins.go:161] Loaded 11 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota. W0211 11:22:29.779471 7 genericapiserver.go:455] Skipping API apiextensions.k8s.io/v1beta1 because it has no resources. I0211 11:22:29.780027 7 instance.go:278] Using reconciler: lease I0211 11:22:29.817694 7 rest.go:130] the default service ipfamily for this cluster is: IPv4 W0211 11:22:30.021452 7 genericapiserver.go:455] Skipping API authentication.k8s.io/v1beta1 because it has no resources. W0211 11:22:30.022708 7 genericapiserver.go:455] Skipping API authorization.k8s.io/v1beta1 because it has no resources. W0211 11:22:30.032456 7 genericapiserver.go:455] Skipping API certificates.k8s.io/v1beta1 because it has no resources. W0211 11:22:30.033970 7 genericapiserver.go:455] Skipping API coordination.k8s.io/v1beta1 because it has no resources. W0211 11:22:30.038492 7 genericapiserver.go:455] Skipping API networking.k8s.io/v1beta1 because it has no resources. W0211 11:22:30.040597 7 genericapiserver.go:455] Skipping API node.k8s.io/v1alpha1 because it has no resources. W0211 11:22:30.045087 7 genericapiserver.go:455] Skipping API rbac.authorization.k8s.io/v1beta1 because it has no resources. W0211 11:22:30.045096 7 genericapiserver.go:455] Skipping API rbac.authorization.k8s.io/v1alpha1 because it has no resources. W0211 11:22:30.046159 7 genericapiserver.go:455] Skipping API scheduling.k8s.io/v1beta1 because it has no resources. W0211 11:22:30.046165 7 genericapiserver.go:455] Skipping API scheduling.k8s.io/v1alpha1 because it has no resources. W0211 11:22:30.049073 7 genericapiserver.go:455] Skipping API storage.k8s.io/v1alpha1 because it has no resources. W0211 11:22:30.050559 7 genericapiserver.go:455] Skipping API flowcontrol.apiserver.k8s.io/v1alpha1 because it has no resources. W0211 11:22:30.053615 7 genericapiserver.go:455] Skipping API apps/v1beta2 because it has no resources. W0211 11:22:30.053622 7 genericapiserver.go:455] Skipping API apps/v1beta1 because it has no resources. W0211 11:22:30.054959 7 genericapiserver.go:455] Skipping API admissionregistration.k8s.io/v1beta1 because it has no resources. I0211 11:22:30.057739 7 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. I0211 11:22:30.057748 7 plugins.go:161] Loaded 11 validating admission controller(s) successfully in the following order: LimitRanger,ServiceAccount,PodSecurity,Priority,PersistentVolumeClaimResize,RuntimeClass,CertificateApproval,CertificateSigning,CertificateSubjectRestriction,ValidatingAdmissionWebhook,ResourceQuota. W0211 11:22:30.062189 7 genericapiserver.go:455] Skipping API apiregistration.k8s.io/v1beta1 because it has no resources. time="2022-02-11T11:22:30Z" level=info msg="Running kube-scheduler --authentication-kubeconfig=/var/lib/rancher/k3s/server/cred/scheduler.kubeconfig --authorization-kubeconfig=/var/lib/rancher/k3s/server/cred/scheduler.kubeconfig --bind-address=127.0.0.1 --kubeconfig=/var/lib/rancher/k3s/server/cred/scheduler.kubeconfig --leader-elect=false --profiling=false --secure-port=10259" time="2022-02-11T11:22:30Z" level=info msg="Waiting for API server to become available" time="2022-02-11T11:22:30Z" level=info msg="Running kube-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/var/lib/rancher/k3s/server/cred/controller.kubeconfig --authorization-kubeconfig=/var/lib/rancher/k3s/server/cred/controller.kubeconfig --bind-address=127.0.0.1 --cluster-cidr=10.42.0.0/16 --cluster-signing-kube-apiserver-client-cert-file=/var/lib/rancher/k3s/server/tls/client-ca.crt --cluster-signing-kube-apiserver-client-key-file=/var/lib/rancher/k3s/server/tls/client-ca.key --cluster-signing-kubelet-client-cert-file=/var/lib/rancher/k3s/server/tls/client-ca.crt --cluster-signing-kubelet-client-key-file=/var/lib/rancher/k3s/server/tls/client-ca.key --cluster-signing-kubelet-serving-cert-file=/var/lib/rancher/k3s/server/tls/server-ca.crt --cluster-signing-kubelet-serving-key-file=/var/lib/rancher/k3s/server/tls/server-ca.key --cluster-signing-legacy-unknown-cert-file=/var/lib/rancher/k3s/server/tls/client-ca.crt --cluster-signing-legacy-unknown-key-file=/var/lib/rancher/k3s/server/tls/client-ca.key --configure-cloud-routes=false --controllers=*,-service,-route,-cloud-node-lifecycle --feature-gates=JobTrackingWithFinalizers=true --kubeconfig=/var/lib/rancher/k3s/server/cred/controller.kubeconfig --leader-elect=false --profiling=false --root-ca-file=/var/lib/rancher/k3s/server/tls/server-ca.crt --secure-port=10257 --service-account-private-key-file=/var/lib/rancher/k3s/server/tls/service.key --use-service-account-credentials=true" time="2022-02-11T11:22:30Z" level=info msg="Running cloud-controller-manager --allocate-node-cidrs=true --authentication-kubeconfig=/var/lib/rancher/k3s/server/cred/cloud-controller.kubeconfig --authorization-kubeconfig=/var/lib/rancher/k3s/server/cred/cloud-controller.kubeconfig --bind-address=127.0.0.1 --cloud-provider=k3s --cluster-cidr=10.42.0.0/16 --configure-cloud-routes=false --kubeconfig=/var/lib/rancher/k3s/server/cred/cloud-controller.kubeconfig --leader-elect=false --node-status-update-frequency=1m0s --port=0 --profiling=false" time="2022-02-11T11:22:30Z" level=info msg="Node token is available at /var/lib/rancher/k3s/server/token" time="2022-02-11T11:22:30Z" level=info msg="To join node to cluster: k3s agent -s https://172.29.0.3:6443 -t ${NODE_TOKEN}" time="2022-02-11T11:22:30Z" level=info msg="Wrote kubeconfig /output/kubeconfig.yaml" time="2022-02-11T11:22:30Z" level=info msg="Run: k3s kubectl" time="2022-02-11T11:22:30Z" level=info msg="Cluster-Http-Server 2022/02/11 11:22:30 http: TLS handshake error from 127.0.0.1:59414: remote error: tls: bad certificate" time="2022-02-11T11:22:30Z" level=info msg="Cluster-Http-Server 2022/02/11 11:22:30 http: TLS handshake error from 127.0.0.1:59420: remote error: tls: bad certificate" time="2022-02-11T11:22:30Z" level=info msg="certificate CN=k3d-foo-server-0 signed by CN=k3s-server-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:30 +0000 UTC" time="2022-02-11T11:22:30Z" level=info msg="certificate CN=system:node:k3d-foo-server-0,O=system:nodes signed by CN=k3s-client-ca@1644578549: notBefore=2022-02-11 11:22:29 +0000 UTC notAfter=2023-02-11 11:22:30 +0000 UTC" time="2022-02-11T11:22:30Z" level=info msg="Module overlay was already loaded" time="2022-02-11T11:22:30Z" level=info msg="Module nf_conntrack was already loaded" time="2022-02-11T11:22:30Z" level=info msg="Module br_netfilter was already loaded" time="2022-02-11T11:22:30Z" level=info msg="Module iptable_nat was already loaded" time="2022-02-11T11:22:30Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_max' to 786432" time="2022-02-11T11:22:30Z" level=error msg="Failed to set sysctl: open /proc/sys/net/netfilter/nf_conntrack_max: permission denied" time="2022-02-11T11:22:30Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_established' to 86400" time="2022-02-11T11:22:30Z" level=info msg="Set sysctl 'net/netfilter/nf_conntrack_tcp_timeout_close_wait' to 3600" time="2022-02-11T11:22:30Z" level=info msg="Logging containerd to /var/lib/rancher/k3s/agent/containerd/containerd.log" time="2022-02-11T11:22:30Z" level=info msg="Running containerd -c /var/lib/rancher/k3s/agent/etc/containerd/config.toml -a /run/k3s/containerd/containerd.sock --state /run/k3s/containerd --root /var/lib/rancher/k3s/agent/containerd" time="2022-02-11T11:22:31Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" I0211 11:22:31.308927 7 dynamic_cafile_content.go:155] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt" I0211 11:22:31.308927 7 dynamic_cafile_content.go:155] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt" I0211 11:22:31.309097 7 dynamic_serving_content.go:129] "Starting controller" name="serving-cert::/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.crt::/var/lib/rancher/k3s/server/tls/serving-kube-apiserver.key" I0211 11:22:31.309304 7 secure_serving.go:266] Serving securely on 127.0.0.1:6444 I0211 11:22:31.309341 7 tlsconfig.go:240] "Starting DynamicServingCertificateController" I0211 11:22:31.309387 7 available_controller.go:491] Starting AvailableConditionController I0211 11:22:31.309395 7 cache.go:32] Waiting for caches to sync for AvailableConditionController controller I0211 11:22:31.309425 7 apf_controller.go:299] Starting API Priority and Fairness config controller I0211 11:22:31.309473 7 naming_controller.go:291] Starting NamingConditionController I0211 11:22:31.309495 7 nonstructuralschema_controller.go:192] Starting NonStructuralSchemaConditionController I0211 11:22:31.309500 7 apiapproval_controller.go:186] Starting KubernetesAPIApprovalPolicyConformantConditionController I0211 11:22:31.309530 7 establishing_controller.go:76] Starting EstablishingController I0211 11:22:31.309534 7 autoregister_controller.go:141] Starting autoregister controller I0211 11:22:31.309537 7 crd_finalizer.go:266] Starting CRDFinalizer I0211 11:22:31.309543 7 cache.go:32] Waiting for caches to sync for autoregister controller I0211 11:22:31.309480 7 customresource_discovery_controller.go:209] Starting DiscoveryController I0211 11:22:31.309554 7 crdregistration_controller.go:111] Starting crd-autoregister controller I0211 11:22:31.309559 7 shared_informer.go:240] Waiting for caches to sync for crd-autoregister I0211 11:22:31.309724 7 controller.go:83] Starting OpenAPI AggregationController I0211 11:22:31.309763 7 controller.go:85] Starting OpenAPI controller I0211 11:22:31.309807 7 apiservice_controller.go:97] Starting APIServiceRegistrationController I0211 11:22:31.309817 7 cache.go:32] Waiting for caches to sync for APIServiceRegistrationController controller I0211 11:22:31.309819 7 dynamic_serving_content.go:129] "Starting controller" name="aggregator-proxy-cert::/var/lib/rancher/k3s/server/tls/client-auth-proxy.crt::/var/lib/rancher/k3s/server/tls/client-auth-proxy.key" I0211 11:22:31.310214 7 cluster_authentication_trust_controller.go:440] Starting cluster_authentication_trust_controller controller I0211 11:22:31.310222 7 shared_informer.go:240] Waiting for caches to sync for cluster_authentication_trust_controller I0211 11:22:31.310257 7 dynamic_cafile_content.go:155] "Starting controller" name="client-ca-bundle::/var/lib/rancher/k3s/server/tls/client-ca.crt" I0211 11:22:31.310285 7 dynamic_cafile_content.go:155] "Starting controller" name="request-header::/var/lib/rancher/k3s/server/tls/request-header-ca.crt" I0211 11:22:31.317094 7 controller.go:611] quota admission added evaluator for: namespaces E0211 11:22:31.322062 7 controller.go:151] Unable to perform initial Kubernetes service initialization: Service "kubernetes" is invalid: spec.clusterIPs: Invalid value: []string{"10.43.0.1"}: failed to allocate IP 10.43.0.1: cannot allocate resources of type serviceipallocations at this time E0211 11:22:31.322869 7 controller.go:156] Unable to remove old endpoints from kubernetes service: StorageError: key not found, Code: 1, Key: /registry/masterleases/172.29.0.3, ResourceVersion: 0, AdditionalErrorMsg: I0211 11:22:31.368264 7 shared_informer.go:247] Caches are synced for node_authorizer I0211 11:22:31.410153 7 cache.go:39] Caches are synced for APIServiceRegistrationController controller I0211 11:22:31.410177 7 apf_controller.go:304] Running API Priority and Fairness config worker I0211 11:22:31.410201 7 cache.go:39] Caches are synced for AvailableConditionController controller I0211 11:22:31.410216 7 shared_informer.go:247] Caches are synced for crd-autoregister I0211 11:22:31.410225 7 cache.go:39] Caches are synced for autoregister controller I0211 11:22:31.410315 7 shared_informer.go:247] Caches are synced for cluster_authentication_trust_controller time="2022-02-11T11:22:32Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" I0211 11:22:32.309478 7 controller.go:132] OpenAPI AggregationController: action for item : Nothing (removed from the queue). I0211 11:22:32.309491 7 controller.go:132] OpenAPI AggregationController: action for item k8s_internal_local_delegation_chain_0000000000: Nothing (removed from the queue). I0211 11:22:32.313165 7 storage_scheduling.go:132] created PriorityClass system-node-critical with value 2000001000 I0211 11:22:32.315773 7 storage_scheduling.go:132] created PriorityClass system-cluster-critical with value 2000000000 I0211 11:22:32.315783 7 storage_scheduling.go:148] all system priority classes are created successfully or already exist. I0211 11:22:32.604198 7 controller.go:611] quota admission added evaluator for: roles.rbac.authorization.k8s.io I0211 11:22:32.622982 7 controller.go:611] quota admission added evaluator for: rolebindings.rbac.authorization.k8s.io W0211 11:22:32.743176 7 lease.go:233] Resetting endpoints for master service "kubernetes" to [172.29.0.3] I0211 11:22:32.743951 7 controller.go:611] quota admission added evaluator for: endpoints I0211 11:22:32.747078 7 controller.go:611] quota admission added evaluator for: endpointslices.discovery.k8s.io time="2022-02-11T11:22:33Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" time="2022-02-11T11:22:33Z" level=info msg="Kube API server is now running" time="2022-02-11T11:22:33Z" level=info msg="k3s is up and running" time="2022-02-11T11:22:33Z" level=info msg="Waiting for cloud-controller-manager privileges to become available" time="2022-02-11T11:22:33Z" level=info msg="Applying CRD addons.k3s.cattle.io" time="2022-02-11T11:22:33Z" level=info msg="Applying CRD helmcharts.helm.cattle.io" time="2022-02-11T11:22:33Z" level=info msg="Applying CRD helmchartconfigs.helm.cattle.io" time="2022-02-11T11:22:33Z" level=info msg="Waiting for CRD helmchartconfigs.helm.cattle.io to become available" I0211 11:22:33.528947 7 serving.go:354] Generated self-signed cert in-memory I0211 11:22:33.591165 7 serving.go:354] Generated self-signed cert in-memory I0211 11:22:33.784159 7 controllermanager.go:186] Version: v1.22.2+k3s2 I0211 11:22:33.786204 7 requestheader_controller.go:169] Starting RequestHeaderAuthRequestController I0211 11:22:33.786217 7 shared_informer.go:240] Waiting for caches to sync for RequestHeaderAuthRequestController I0211 11:22:33.786223 7 configmap_cafile_content.go:201] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file" I0211 11:22:33.786226 7 configmap_cafile_content.go:201] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file" I0211 11:22:33.786233 7 shared_informer.go:240] Waiting for caches to sync for client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file I0211 11:22:33.786240 7 shared_informer.go:240] Waiting for caches to sync for client-ca::kube-system::extension-apiserver-authentication::client-ca-file I0211 11:22:33.786555 7 secure_serving.go:200] Serving securely on 127.0.0.1:10257 I0211 11:22:33.786579 7 tlsconfig.go:240] "Starting DynamicServingCertificateController" time="2022-02-11T11:22:33Z" level=info msg="Done waiting for CRD helmchartconfigs.helm.cattle.io to become available" time="2022-02-11T11:22:33Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-crd-10.3.0.tgz" time="2022-02-11T11:22:33Z" level=info msg="Writing static file: /var/lib/rancher/k3s/server/static/charts/traefik-10.3.0.tgz" time="2022-02-11T11:22:33Z" level=info msg="Failed to get existing traefik HelmChart" error="helmcharts.helm.cattle.io \"traefik\" not found" time="2022-02-11T11:22:33Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/metrics-server-service.yaml" time="2022-02-11T11:22:33Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/resource-reader.yaml" time="2022-02-11T11:22:33Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/rolebindings.yaml" time="2022-02-11T11:22:33Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/coredns.yaml" time="2022-02-11T11:22:33Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/auth-delegator.yaml" time="2022-02-11T11:22:33Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/metrics-server-deployment.yaml" time="2022-02-11T11:22:33Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/auth-reader.yaml" time="2022-02-11T11:22:33Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/metrics-apiservice.yaml" time="2022-02-11T11:22:33Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/traefik.yaml" time="2022-02-11T11:22:33Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/ccm.yaml" time="2022-02-11T11:22:33Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/local-storage.yaml" time="2022-02-11T11:22:33Z" level=info msg="Writing manifest: /var/lib/rancher/k3s/server/manifests/metrics-server/aggregated-metrics-reader.yaml" I0211 11:22:33.886390 7 shared_informer.go:247] Caches are synced for client-ca::kube-system::extension-apiserver-authentication::client-ca-file I0211 11:22:33.886410 7 shared_informer.go:247] Caches are synced for RequestHeaderAuthRequestController I0211 11:22:33.886392 7 shared_informer.go:247] Caches are synced for client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file I0211 11:22:33.896392 7 shared_informer.go:240] Waiting for caches to sync for tokens I0211 11:22:33.903215 7 controller.go:611] quota admission added evaluator for: serviceaccounts I0211 11:22:33.905009 7 controllermanager.go:577] Started "persistentvolume-expander" I0211 11:22:33.905115 7 expand_controller.go:327] Starting expand controller I0211 11:22:33.905122 7 shared_informer.go:240] Waiting for caches to sync for expand I0211 11:22:33.910023 7 controllermanager.go:577] Started "daemonset" W0211 11:22:33.910034 7 controllermanager.go:556] "bootstrapsigner" is disabled W0211 11:22:33.910038 7 controllermanager.go:556] "route" is disabled I0211 11:22:33.910093 7 daemon_controller.go:284] Starting daemon sets controller I0211 11:22:33.910098 7 shared_informer.go:240] Waiting for caches to sync for daemon sets I0211 11:22:33.915339 7 controllermanager.go:577] Started "pvc-protection" I0211 11:22:33.915367 7 pvc_protection_controller.go:110] "Starting PVC protection controller" I0211 11:22:33.915375 7 shared_informer.go:240] Waiting for caches to sync for PVC protection I0211 11:22:33.921465 7 controllermanager.go:577] Started "endpointslicemirroring" I0211 11:22:33.921584 7 endpointslicemirroring_controller.go:212] Starting EndpointSliceMirroring controller I0211 11:22:33.921594 7 shared_informer.go:240] Waiting for caches to sync for endpoint_slice_mirroring W0211 11:22:33.935352 7 authorization.go:47] Authorization is disabled W0211 11:22:33.935365 7 authentication.go:47] Authentication is disabled I0211 11:22:33.935374 7 deprecated_insecure_serving.go:54] Serving healthz insecurely on [::]:10251 I0211 11:22:33.936433 7 controllermanager.go:577] Started "namespace" I0211 11:22:33.936505 7 namespace_controller.go:200] Starting namespace controller I0211 11:22:33.936518 7 shared_informer.go:240] Waiting for caches to sync for namespace I0211 11:22:33.937462 7 requestheader_controller.go:169] Starting RequestHeaderAuthRequestController I0211 11:22:33.937468 7 shared_informer.go:240] Waiting for caches to sync for RequestHeaderAuthRequestController I0211 11:22:33.937484 7 configmap_cafile_content.go:201] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file" I0211 11:22:33.937490 7 shared_informer.go:240] Waiting for caches to sync for client-ca::kube-system::extension-apiserver-authentication::client-ca-file I0211 11:22:33.937503 7 configmap_cafile_content.go:201] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file" I0211 11:22:33.937511 7 shared_informer.go:240] Waiting for caches to sync for client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file I0211 11:22:33.937773 7 secure_serving.go:200] Serving securely on 127.0.0.1:10259 I0211 11:22:33.937792 7 tlsconfig.go:240] "Starting DynamicServingCertificateController" I0211 11:22:33.941922 7 certificate_controller.go:118] Starting certificate controller "csrsigning-kubelet-serving" I0211 11:22:33.941934 7 shared_informer.go:240] Waiting for caches to sync for certificate-csrsigning-kubelet-serving I0211 11:22:33.941963 7 dynamic_serving_content.go:129] "Starting controller" name="csr-controller::/var/lib/rancher/k3s/server/tls/server-ca.crt::/var/lib/rancher/k3s/server/tls/server-ca.key" I0211 11:22:33.942053 7 certificate_controller.go:118] Starting certificate controller "csrsigning-kubelet-client" I0211 11:22:33.942059 7 shared_informer.go:240] Waiting for caches to sync for certificate-csrsigning-kubelet-client I0211 11:22:33.942083 7 dynamic_serving_content.go:129] "Starting controller" name="csr-controller::/var/lib/rancher/k3s/server/tls/client-ca.crt::/var/lib/rancher/k3s/server/tls/client-ca.key" I0211 11:22:33.942133 7 certificate_controller.go:118] Starting certificate controller "csrsigning-kube-apiserver-client" I0211 11:22:33.942140 7 shared_informer.go:240] Waiting for caches to sync for certificate-csrsigning-kube-apiserver-client I0211 11:22:33.942161 7 dynamic_serving_content.go:129] "Starting controller" name="csr-controller::/var/lib/rancher/k3s/server/tls/client-ca.crt::/var/lib/rancher/k3s/server/tls/client-ca.key" I0211 11:22:33.942253 7 controllermanager.go:577] Started "csrsigning" I0211 11:22:33.942312 7 certificate_controller.go:118] Starting certificate controller "csrsigning-legacy-unknown" I0211 11:22:33.942317 7 shared_informer.go:240] Waiting for caches to sync for certificate-csrsigning-legacy-unknown I0211 11:22:33.942331 7 dynamic_serving_content.go:129] "Starting controller" name="csr-controller::/var/lib/rancher/k3s/server/tls/client-ca.crt::/var/lib/rancher/k3s/server/tls/client-ca.key" I0211 11:22:33.948057 7 controllermanager.go:577] Started "serviceaccount" I0211 11:22:33.948137 7 serviceaccounts_controller.go:117] Starting service account controller I0211 11:22:33.948147 7 shared_informer.go:240] Waiting for caches to sync for service account I0211 11:22:33.954029 7 controllermanager.go:577] Started "job" I0211 11:22:33.954133 7 job_controller.go:172] Starting job controller I0211 11:22:33.954140 7 shared_informer.go:240] Waiting for caches to sync for job I0211 11:22:33.959702 7 controllermanager.go:577] Started "replicaset" I0211 11:22:33.959800 7 replica_set.go:186] Starting replicaset controller I0211 11:22:33.959812 7 shared_informer.go:240] Waiting for caches to sync for ReplicaSet I0211 11:22:33.961981 7 controllermanager.go:577] Started "csrapproving" I0211 11:22:33.962067 7 certificate_controller.go:118] Starting certificate controller "csrapproving" I0211 11:22:33.962077 7 shared_informer.go:240] Waiting for caches to sync for certificate-csrapproving I0211 11:22:33.964015 7 controllermanager.go:577] Started "csrcleaner" I0211 11:22:33.964031 7 cleaner.go:82] Starting CSR cleaner controller time="2022-02-11T11:22:33Z" level=info msg="Starting k3s.cattle.io/v1, Kind=Addon controller" I0211 11:22:33.996771 7 shared_informer.go:247] Caches are synced for tokens time="2022-02-11T11:22:34Z" level=info msg="Waiting for control-plane node k3d-foo-server-0 startup: nodes \"k3d-foo-server-0\" not found" time="2022-02-11T11:22:34Z" level=info msg="Cluster dns configmap has been set successfully" I0211 11:22:34.037497 7 shared_informer.go:247] Caches are synced for RequestHeaderAuthRequestController I0211 11:22:34.037572 7 shared_informer.go:247] Caches are synced for client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file I0211 11:22:34.037580 7 shared_informer.go:247] Caches are synced for client-ca::kube-system::extension-apiserver-authentication::client-ca-file I0211 11:22:34.101993 7 controllermanager.go:577] Started "endpoint" I0211 11:22:34.102046 7 endpoints_controller.go:195] Starting endpoint controller I0211 11:22:34.102055 7 shared_informer.go:240] Waiting for caches to sync for endpoint time="2022-02-11T11:22:34Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChart controller" time="2022-02-11T11:22:34Z" level=info msg="Starting helm.cattle.io/v1, Kind=HelmChartConfig controller" time="2022-02-11T11:22:34Z" level=info msg="Starting apps/v1, Kind=DaemonSet controller" time="2022-02-11T11:22:34Z" level=info msg="Starting apps/v1, Kind=Deployment controller" time="2022-02-11T11:22:34Z" level=info msg="Starting rbac.authorization.k8s.io/v1, Kind=ClusterRoleBinding controller" time="2022-02-11T11:22:34Z" level=info msg="Starting batch/v1, Kind=Job controller" time="2022-02-11T11:22:34Z" level=info msg="Starting /v1, Kind=ConfigMap controller" time="2022-02-11T11:22:34Z" level=info msg="Starting /v1, Kind=Node controller" time="2022-02-11T11:22:34Z" level=info msg="Starting /v1, Kind=ServiceAccount controller" time="2022-02-11T11:22:34Z" level=info msg="Starting /v1, Kind=Pod controller" time="2022-02-11T11:22:34Z" level=info msg="Starting /v1, Kind=Endpoints controller" time="2022-02-11T11:22:34Z" level=info msg="Starting /v1, Kind=Service controller" time="2022-02-11T11:22:34Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" I0211 11:22:34.250208 7 controllermanager.go:577] Started "endpointslice" I0211 11:22:34.250252 7 endpointslice_controller.go:257] Starting endpoint slice controller I0211 11:22:34.250260 7 shared_informer.go:240] Waiting for caches to sync for endpoint_slice I0211 11:22:34.557363 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for jobs.batch I0211 11:22:34.557417 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for networkpolicies.networking.k8s.io I0211 11:22:34.557446 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for roles.rbac.authorization.k8s.io I0211 11:22:34.557468 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for leases.coordination.k8s.io I0211 11:22:34.557534 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for serviceaccounts I0211 11:22:34.557572 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for deployments.apps I0211 11:22:34.557642 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for replicasets.apps I0211 11:22:34.557662 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for events.events.k8s.io I0211 11:22:34.557687 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for rolebindings.rbac.authorization.k8s.io I0211 11:22:34.557758 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for helmcharts.helm.cattle.io I0211 11:22:34.557846 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for statefulsets.apps I0211 11:22:34.557874 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for podtemplates I0211 11:22:34.557891 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for limitranges I0211 11:22:34.557914 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for horizontalpodautoscalers.autoscaling I0211 11:22:34.557939 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for csistoragecapacities.storage.k8s.io I0211 11:22:34.557958 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for helmchartconfigs.helm.cattle.io I0211 11:22:34.557976 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for addons.k3s.cattle.io I0211 11:22:34.557993 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for endpoints I0211 11:22:34.558008 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for daemonsets.apps I0211 11:22:34.558026 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for controllerrevisions.apps I0211 11:22:34.558048 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for cronjobs.batch I0211 11:22:34.558067 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for poddisruptionbudgets.policy I0211 11:22:34.558087 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for endpointslices.discovery.k8s.io I0211 11:22:34.558128 7 resource_quota_monitor.go:229] QuotaMonitor created object count evaluator for ingresses.networking.k8s.io I0211 11:22:34.558142 7 controllermanager.go:577] Started "resourcequota" W0211 11:22:34.558149 7 controllermanager.go:556] "tokencleaner" is disabled I0211 11:22:34.558153 7 resource_quota_controller.go:273] Starting resource quota controller I0211 11:22:34.558159 7 shared_informer.go:240] Waiting for caches to sync for resource quota I0211 11:22:34.558175 7 resource_quota_monitor.go:304] QuotaMonitor running I0211 11:22:34.699539 7 controllermanager.go:577] Started "persistentvolume-binder" I0211 11:22:34.699566 7 pv_controller_base.go:308] Starting persistent volume controller I0211 11:22:34.699569 7 shared_informer.go:240] Waiting for caches to sync for persistent volume I0211 11:22:34.850699 7 controllermanager.go:577] Started "ttl-after-finished" I0211 11:22:34.850746 7 ttlafterfinished_controller.go:109] Starting TTL after finished controller I0211 11:22:34.850753 7 shared_informer.go:240] Waiting for caches to sync for TTL after finished time="2022-02-11T11:22:34Z" level=info msg="Starting /v1, Kind=Secret controller" I0211 11:22:35.048778 7 controllermanager.go:577] Started "disruption" I0211 11:22:35.048795 7 disruption.go:363] Starting disruption controller I0211 11:22:35.048805 7 shared_informer.go:240] Waiting for caches to sync for disruption time="2022-02-11T11:22:35Z" level=info msg="Active TLS secret k3s-serving (ver=245) (count 10): map[listener.cattle.io/cn-0.0.0.0:0.0.0.0 listener.cattle.io/cn-10.43.0.1:10.43.0.1 listener.cattle.io/cn-127.0.0.1:127.0.0.1 listener.cattle.io/cn-172.29.0.3:172.29.0.3 listener.cattle.io/cn-k3d-foo-server-0:k3d-foo-server-0 listener.cattle.io/cn-kubernetes:kubernetes listener.cattle.io/cn-kubernetes.default:kubernetes.default listener.cattle.io/cn-kubernetes.default.svc:kubernetes.default.svc listener.cattle.io/cn-kubernetes.default.svc.cluster.local:kubernetes.default.svc.cluster.local listener.cattle.io/cn-localhost:localhost listener.cattle.io/fingerprint:SHA1=FB473CA2A839175D300220BA26E34D832FC636FF]" time="2022-02-11T11:22:35Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" I0211 11:22:35.199823 7 node_ipam_controller.go:91] Sending events to api server. time="2022-02-11T11:22:35Z" level=info msg="Waiting for control-plane node k3d-foo-server-0 startup: nodes \"k3d-foo-server-0\" not found" I0211 11:22:35.994504 7 controller.go:611] quota admission added evaluator for: addons.k3s.cattle.io time="2022-02-11T11:22:35Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"ccm\", UID:\"ecfcacaa-fa8a-46a4-b970-263da2515a01\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"258\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/var/lib/rancher/k3s/server/manifests/ccm.yaml\"" time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"ccm\", UID:\"ecfcacaa-fa8a-46a4-b970-263da2515a01\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"258\", FieldPath:\"\"}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at \"/var/lib/rancher/k3s/server/manifests/ccm.yaml\"" time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"coredns\", UID:\"bc03394a-223c-4bc9-9e86-ef1295d8e913\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"266\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/var/lib/rancher/k3s/server/manifests/coredns.yaml\"" I0211 11:22:36.057938 7 controller.go:611] quota admission added evaluator for: deployments.apps time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"coredns\", UID:\"bc03394a-223c-4bc9-9e86-ef1295d8e913\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"266\", FieldPath:\"\"}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at \"/var/lib/rancher/k3s/server/manifests/coredns.yaml\"" time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"local-storage\", UID:\"84c00b68-3eab-41e9-8967-65e4c77af581\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"279\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/var/lib/rancher/k3s/server/manifests/local-storage.yaml\"" time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"local-storage\", UID:\"84c00b68-3eab-41e9-8967-65e4c77af581\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"279\", FieldPath:\"\"}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at \"/var/lib/rancher/k3s/server/manifests/local-storage.yaml\"" time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"aggregated-metrics-reader\", UID:\"d5a02827-d562-42d7-95ca-918fc4d4538e\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"291\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/aggregated-metrics-reader.yaml\"" time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"aggregated-metrics-reader\", UID:\"d5a02827-d562-42d7-95ca-918fc4d4538e\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"291\", FieldPath:\"\"}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/aggregated-metrics-reader.yaml\"" time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"auth-delegator\", UID:\"20435d77-8fcf-4f3f-857b-7f96650d6a62\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"296\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/auth-delegator.yaml\"" time="2022-02-11T11:22:36Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"auth-delegator\", UID:\"20435d77-8fcf-4f3f-857b-7f96650d6a62\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"296\", FieldPath:\"\"}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/auth-delegator.yaml\"" time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"auth-reader\", UID:\"aec48a09-b24d-44ff-97f0-7305278b3019\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"301\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/auth-reader.yaml\"" time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"auth-reader\", UID:\"aec48a09-b24d-44ff-97f0-7305278b3019\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"301\", FieldPath:\"\"}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/auth-reader.yaml\"" time="2022-02-11T11:22:36Z" level=info msg="Waiting for control-plane node k3d-foo-server-0 startup: nodes \"k3d-foo-server-0\" not found" time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"metrics-apiservice\", UID:\"62cde126-90f9-4c07-bf14-84aa6a1c4517\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"306\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/metrics-apiservice.yaml\"" time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"metrics-apiservice\", UID:\"62cde126-90f9-4c07-bf14-84aa6a1c4517\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"306\", FieldPath:\"\"}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/metrics-apiservice.yaml\"" I0211 11:22:36.570885 7 serving.go:354] Generated self-signed cert in-memory time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"metrics-server-deployment\", UID:\"442a2218-08e2-4808-879e-ddf40811aec7\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"312\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/metrics-server-deployment.yaml\"" time="2022-02-11T11:22:36Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"metrics-server-deployment\", UID:\"442a2218-08e2-4808-879e-ddf40811aec7\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"312\", FieldPath:\"\"}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/metrics-server-deployment.yaml\"" I0211 11:22:36.847736 7 controllermanager.go:142] Version: v1.22.2+k3s2 I0211 11:22:36.850074 7 requestheader_controller.go:169] Starting RequestHeaderAuthRequestController I0211 11:22:36.850078 7 configmap_cafile_content.go:201] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::client-ca-file" I0211 11:22:36.850087 7 shared_informer.go:240] Waiting for caches to sync for client-ca::kube-system::extension-apiserver-authentication::client-ca-file I0211 11:22:36.850088 7 shared_informer.go:240] Waiting for caches to sync for RequestHeaderAuthRequestController I0211 11:22:36.850078 7 configmap_cafile_content.go:201] "Starting controller" name="client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file" I0211 11:22:36.850101 7 shared_informer.go:240] Waiting for caches to sync for client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file I0211 11:22:36.850397 7 secure_serving.go:200] Serving securely on 127.0.0.1:10258 I0211 11:22:36.850409 7 tlsconfig.go:240] "Starting DynamicServingCertificateController" I0211 11:22:36.950961 7 shared_informer.go:247] Caches are synced for RequestHeaderAuthRequestController I0211 11:22:36.950968 7 shared_informer.go:247] Caches are synced for client-ca::kube-system::extension-apiserver-authentication::requestheader-client-ca-file I0211 11:22:36.950968 7 shared_informer.go:247] Caches are synced for client-ca::kube-system::extension-apiserver-authentication::client-ca-file time="2022-02-11T11:22:37Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" time="2022-02-11T11:22:37Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"metrics-server-service\", UID:\"5db84949-85e8-4b54-874b-ea2af2beaf00\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"320\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/metrics-server-service.yaml\"" time="2022-02-11T11:22:37Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"metrics-server-service\", UID:\"5db84949-85e8-4b54-874b-ea2af2beaf00\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"320\", FieldPath:\"\"}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/metrics-server-service.yaml\"" time="2022-02-11T11:22:37Z" level=info msg="Waiting for control-plane node k3d-foo-server-0 startup: nodes \"k3d-foo-server-0\" not found" time="2022-02-11T11:22:37Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"resource-reader\", UID:\"5c7d7b3a-32aa-4c82-9fe2-6e048d2e284b\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"327\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/resource-reader.yaml\"" time="2022-02-11T11:22:37Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"resource-reader\", UID:\"5c7d7b3a-32aa-4c82-9fe2-6e048d2e284b\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"327\", FieldPath:\"\"}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at \"/var/lib/rancher/k3s/server/manifests/metrics-server/resource-reader.yaml\"" W0211 11:22:37.832437 7 handler_proxy.go:104] no RequestInfo found in the context E0211 11:22:37.832471 7 controller.go:116] loading OpenAPI spec for "v1beta1.metrics.k8s.io" failed with: failed to retrieve openAPI spec, http error: ResponseCode: 503, Body: service unavailable , Header: map[Content-Type:[text/plain; charset=utf-8] X-Content-Type-Options:[nosniff]] I0211 11:22:37.832479 7 controller.go:129] OpenAPI AggregationController: action for item v1beta1.metrics.k8s.io: Rate Limited Requeue. time="2022-02-11T11:22:38Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"rolebindings\", UID:\"c88ae796-b809-40c3-bfe4-5b11503d12c8\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"333\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/var/lib/rancher/k3s/server/manifests/rolebindings.yaml\"" time="2022-02-11T11:22:38Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"rolebindings\", UID:\"c88ae796-b809-40c3-bfe4-5b11503d12c8\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"333\", FieldPath:\"\"}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at \"/var/lib/rancher/k3s/server/manifests/rolebindings.yaml\"" time="2022-02-11T11:22:38Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" I0211 11:22:38.156014 7 request.go:665] Waited for 1.048512208s due to client-side throttling, not priority and fairness, request: GET:https://127.0.0.1:6444/apis/k3s.cattle.io/v1?timeout=32s time="2022-02-11T11:22:38Z" level=info msg="Waiting for control-plane node k3d-foo-server-0 startup: nodes \"k3d-foo-server-0\" not found" time="2022-02-11T11:22:38Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"traefik\", UID:\"f7ba0309-4848-49e0-95e8-c931fab84dc7\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"340\", FieldPath:\"\"}): type: 'Normal' reason: 'ApplyingManifest' Applying manifest at \"/var/lib/rancher/k3s/server/manifests/traefik.yaml\"" I0211 11:22:38.430224 7 controller.go:611] quota admission added evaluator for: helmcharts.helm.cattle.io time="2022-02-11T11:22:38Z" level=info msg="Event(v1.ObjectReference{Kind:\"Addon\", Namespace:\"kube-system\", Name:\"traefik\", UID:\"f7ba0309-4848-49e0-95e8-c931fab84dc7\", APIVersion:\"k3s.cattle.io/v1\", ResourceVersion:\"340\", FieldPath:\"\"}): type: 'Normal' reason: 'AppliedManifest' Applied manifest at \"/var/lib/rancher/k3s/server/manifests/traefik.yaml\"" I0211 11:22:38.458578 7 controller.go:611] quota admission added evaluator for: jobs.batch E0211 11:22:38.657690 7 controllermanager.go:419] unable to get all supported resources from server: unable to retrieve the complete list of server APIs: metrics.k8s.io/v1beta1: the server is currently unable to handle the request I0211 11:22:38.658948 7 node_controller.go:115] Sending events to api server. I0211 11:22:38.659027 7 controllermanager.go:285] Started "cloud-node" I0211 11:22:38.659096 7 node_controller.go:154] Waiting for informer caches to sync I0211 11:22:38.660047 7 node_lifecycle_controller.go:76] Sending events to api server I0211 11:22:38.660071 7 controllermanager.go:285] Started "cloud-node-lifecycle" time="2022-02-11T11:22:39Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" time="2022-02-11T11:22:39Z" level=info msg="Waiting for control-plane node k3d-foo-server-0 startup: nodes \"k3d-foo-server-0\" not found" time="2022-02-11T11:22:40Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" time="2022-02-11T11:22:40Z" level=info msg="Waiting for control-plane node k3d-foo-server-0 startup: nodes \"k3d-foo-server-0\" not found" time="2022-02-11T11:22:41Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" time="2022-02-11T11:22:41Z" level=info msg="Waiting for control-plane node k3d-foo-server-0 startup: nodes \"k3d-foo-server-0\" not found" time="2022-02-11T11:22:42Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" time="2022-02-11T11:22:42Z" level=info msg="Waiting for control-plane node k3d-foo-server-0 startup: nodes \"k3d-foo-server-0\" not found" time="2022-02-11T11:22:43Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" time="2022-02-11T11:22:43Z" level=info msg="Waiting for control-plane node k3d-foo-server-0 startup: nodes \"k3d-foo-server-0\" not found" time="2022-02-11T11:22:44Z" level=info msg="Waiting for containerd startup: rpc error: code = Unimplemented desc = unknown service runtime.v1alpha2.RuntimeService" time="2022-02-11T11:22:44Z" level=info msg="Waiting for control-plane node k3d-foo-server-0 startup: nodes \"k3d-foo-server-0\" not found" ```To me, this suggests a version mismatch between the kubelet and the containerd, but that seems weird since I'd assume that k3d packages both of those together.
Which OS & Architecture
This problem seems to have started after I did a system upgrade (
pacman -Syu) at 2022-02-09, however no Docker-related packages (docker, runc, containerd) have been updated since way before then.Which version of
k3dInstalled from Nixpkgs, I have also confirmed against k3d 5.3.0 and 5.2.1
Which version of docker