search

apache / cloudstack

Apache CloudStack is an opensource Infrastructure as a Service (IaaS) cloud computing platform
https://cloudstack.apache.org/
Apache License 2.0
1.98k stars 1.09k forks source link

CSK Kubernetes cluster stuck in "Starting" mode #5999

Closed edikevich closed 2 years ago

edikevich commented 2 years ago
ISSUE TYPE
CLOUDSTACK VERSION
4.16.0
CONFIGURATION

XCP-NG 8.2 Advanced Zone

OS / ENVIRONMENT

Oracle Linux 8.4 - Management server, MYSQL 8.0.26 XCP-NG 8.2 - hypervisor

SUMMARY

Kubernetes cluster stuck in "Starting" state

STEPS TO REPRODUCE

Enable Kubernetes Service plugin in global setting: cloud.kubernetes.service.enabled = true Add Kubernetes ISOs: image

Create Kubernetes Cluster; image

EXPECTED RESULTS
Kubernetes Cluster is created
ACTUAL RESULTS

Deployment stuck in "Starting" state: image

After timeout it is state is Error. Instances are created: image

Firewall rules are added: image

Portforwarding rules too: image

And load balancing: image

But! Egress rules aren't added (should be?): image

Becouse we dont have egress rules we can't download kubernetesui from docker hub. But before that deploy-kube-system demon didn't start automaticaly (setup-kube-system started normaly). When I try to start deploy-kube-system demon manyaly and add egress rules in controle node all looks fine but in ACS UI Cluster steel in starting state.

Pearl1594 commented 2 years ago

@edikevich can you please share the list of docker images in your node using docker image ls & ctr images ls. Ideally, the image should be bundled/locally available, and hence there isn't a need to pull it from the registry.

edikevich commented 2 years ago

@Pearl1594

image

ctr images ls is empty

Pearl1594 commented 2 years ago

Thanks for sharing the details. It's quite odd that it's trying to pull the image when it's locally available. My best guess is that because the kubernetes-dashboard manifest / config has an image pull policy set to always. Can you please try editing the config by doing a: kubectl edit deployment kubernetes-dashboard -n kubernetes-dashboard and edit the imagePullPolicy to IfNotPresent instead of Always, just to rule out if that's causing an issue.

edikevich commented 2 years ago

@Pearl1594

Try to change imagePullPolicy image

Cluster is steel in starting state

Pearl1594 commented 2 years ago

But did the dashboard pods come up fine @edikevich?

edikevich commented 2 years ago

When I manually add egress rules in kubernetes cluster network kubernetes-dashboard was up and running. Now I have all running pods: image But in ACS UI Clustes still in starting state

Pearl1594 commented 2 years ago

Do you see any such messages in the Management server logs: Error while waiting for Kubernetes cluster: <cluster-name> API dashboard service to be available

Ideally there are 3 things that are checked -

  1. No of nodes are equal to what was initially configured when deploying the cluster (based on the fact that the nodes are up and running, I think this check should have passed)
  2. if the kubernetes config is available - You can verify if it is in the Access Tab (Since the nodes are up and running, I believe the kube config is available)
  3. If the dashboard service is up and running

If all these are good, then it would move to Running state, else for the configured period cloud.kubernetes.cluster.start.timeout - default: 3600 it tries to get the details and then enters Error state

edikevich commented 2 years ago

@Pearl1594

This is log via fresh install new kubernetes cluster:

job-6410.txt

nodes: image

kubernetes config isn't avaible: image

dashboard up:

image

cluster state in UI still starting:(

Pearl1594 commented 2 years ago

I see this at the end of the logs you shared: Waiting for Kubernetes cluster : kube1 control node VMs to be accessible

which indicated that the nodes aren't in ready state - by state of the nodes, it isn't the VMs in Running state but rather the output of kubectl get no can you check if that is returning the right result.

edikevich commented 2 years ago

image

and on previous screenshot

Pearl1594 commented 2 years ago

my apologies, I missed the screenshot in the previous message. I'll give it a try again, and get back to you.

vladimirpetrov commented 2 years ago

Hi @edikevich, I was able to successfully start a CKS kubernetes cluster (1.22.6) on ACS 4.16.0, hypervisor XCPNG 8.2 and CentOS 7 as management server.

image

edikevich commented 2 years ago

Hi @Pearl1594 and @vladimirpetrov

Can someone explain me how ACS get Cluster State? Now when I created Isolated network and add egress allow rules I can see on control plane that all work good - I have all ready nodes and pods but in UI Cluster State still "Starting". image

MB ACS don't get State from Cluster?

Pearl1594 commented 2 years ago

@edikevich The following code snippet : https://github.com/apache/cloudstack/blob/4.15.2.0/plugins/integrations/kubernetes-service/src/main/java/com/cloud/kubernetes/cluster/actionworkers/KubernetesClusterStartWorker.java#L565-L574 explains the 3 checks that are done before marking the cluster to be ready / puts it in Running state:

  1. No of nodes are equal to what was initially configured when deploying the cluster - using kubectl get nodes
  2. If the kubernetes config is available - It checks if cat /etc/kubernetes/admin.conf is available - if not it logs: Failed to retrieve kube-config file for Kubernetes cluster - It is worth checking in your logs if you see the following logs.
  3. If the dashboard service is up and running - using kubectl get pods

After about an hour the Kubernetes Cluster would have ended in Error state, could you please share what reason was logged for it to enter Error state. This might help us understand the issue.

edikevich commented 2 years ago

@Pearl1594 In log:

2022-02-16 17:33:23,054 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-6:ctx-05494fe3 job-6410) (logid:cdba81ce) Complete async job-6410, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":"530","errortext":"Failed to setup Kubernetes cluster : kube1 in usable state as unable to access control node VMs of the cluster"}

edikevich commented 2 years ago

On contol-plane: image

Pearl1594 commented 2 years ago

@edikevich can you telnet to the public IP of the CKS cluster via port 2222 from the management server?

edikevich commented 2 years ago

@Pearl1594 YES, problem was in firewall in our company. When we grant access from our management server to public IP pool via 2222 and 6443 ports cluster state is changed to Running.

BUT! Now I have anothe problem - when I deploy large cluster - about 9 worker nodes cluster stuck in Starting state again:( MB we need open some another ports or check something else?

edikevich commented 2 years ago

@Pearl1594

I am sorry to bother you but I have strange behaviour. Kubernetes cluster deploy success only if I create Isolated Network with default deny egress policy and add alloy egress rules manually:) With standart DefaultNetworkOfferingforKubernetesService deploy is failed:) No all nodes are deployed:)

Pearl1594 commented 2 years ago

Thanks for sharing these details. So, when you deploy the k8s cluster, you specify a pre-existing network deployed with an offering that has default egress policy as false or have set cloud.kubernetes.cluster.network.offering global setting to a network offering with deny egress policy?

I tried deploying a k8s cluster with an offering with deny policy, and was able to reproduce your issue which is opposite to the behavior you notice. Can you please share the details of the network offering that was used to successfully deploy a CKS cluster?

edikevich commented 2 years ago

@Pearl1594 I made many many tests and now I don't understand how it works) Some clusters are deployed on DefaultNetworkOfferingforKubernetesService with different Kubernetes ISOs. Clusters with more than 5 worker nodes cant be deployed on DefaultNetworkOfferingforKubernetesService in my case. In isolated network it depends on which Kubernetes ISO do you use. Often via "kubectl get no" I don't see all nodes - in UI all looks good. Sometimes deploy-kybe-system service didn't start automatically but when you start it manually cluster's deploy finished successfully:) I don't know how to debug it now:)

edikevich commented 2 years ago

Hi @Pearl1594

Sometimes in 'kubectl get node' I see that kubectl dont detect all nodes. How I can redeploy nodes?

Pearl1594 commented 2 years ago

@edikevich when you say that it doesn't detect the node, do you mean they are listed but are in an incorrect state, i.e., Not Ready? If so, before retrying to setup the node again, go to the specific nodes and verify:

if there's no such file, you can either stop and start the cluster again.. or, in the specific node, re-attach the cks iso, and run the setup-kube-system & deploy-kube-system scripts after running a kubeadm reset

edikevich commented 2 years ago

@Pearl1594 No. I mean that for example when I deploy 3 worker nodes in 'kubectl get node' I see 2 nodes:

image

Pearl1594 commented 2 years ago

And do you see any issues on the 3rd node? And is the CKS cluster in Error state?

edikevich commented 2 years ago

On 3rd node deploy-kube-system daemon didn't start automaticaly. After I started id manualy cluster started

edikevich commented 2 years ago

In daemon.log:

Feb 18 06:38:13 systemvm kubelet[1656]: E0218 06:38:13.283591 1656 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml" Feb 18 06:38:13 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE Feb 18 06:38:13 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'. Feb 18 06:38:23 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 1. Feb 18 06:38:23 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.

Pearl1594 commented 2 years ago

Based on the logs you've shared @edikevich , it seems like something went wrong during thesetup-kube-systemscript.

edikevich commented 2 years ago

On anothe system where deploy-kube-system didn't start:

image

edikevich commented 2 years ago

ls -la /etc/systemd/system/setup-kube-system.service : -rwxr-xr-x 1 root root 133 Feb 18 07:11 /etc/systemd/system/setup-kube-system.service

cat /var/log/daemon.log | grep deploy-kube-system : Feb 18 07:11:21 systemvm cloud-init[1196]: Failed to start deploy-kube-system.service: Unit deploy-kube-system.service not found.

ls -la /etc/systemd/system/deploy-kube-system.service -rwxr-xr-x 1 root root 205 Feb 18 07:11 /etc/systemd/system/deploy-kube-system.service

Pearl1594 commented 2 years ago

Ok, that seems very odd.. it seems like cloud-init created the file a bit later and the runcmd (for starting the deploy-kube-system service) was executed before

zap51 commented 2 years ago

I'm facing the similar issue as well. KVM in my case. Here's the configuration of the cluster.

image

Gets stuck at "Starting". It's the same even if the control plane is in HA as well as non-HA.

Control Plane readiness is very random. In case of HA Control plane, one of the nodes get ready while others don't, sometimes in HA-Control plane, Control plane nodes get ready while workers don't.

image

Bi-directional connectivity is present between the Management Server and the public network.

Most of the time, workers don't even get ready, looks like kubelet configuration is never received.

image

The daemon.log is as follows on the worker.

Feb 26 12:33:45 systemvm systemd-modules-load[224]: Inserted module 'nf_conntrack'
Feb 26 12:33:45 systemvm systemd-modules-load[224]: Inserted module 'nf_conntrack_ftp'
Feb 26 12:33:45 systemvm systemd-modules-load[224]: Inserted module 'nf_conntrack_pptp'
Feb 26 12:33:45 systemvm systemd-modules-load[224]: Failed to find module 'nf_conntrack_proto_gre'
Feb 26 12:33:45 systemvm systemd[1]: Starting Flush Journal to Persistent Storage...
Feb 26 12:33:45 systemvm systemd-modules-load[224]: Inserted module 'nf_nat_tftp'
Feb 26 12:33:45 systemvm systemd[1]: Finished Create System Users.
Feb 26 12:33:45 systemvm systemd-modules-load[224]: Inserted module 'nf_nat_ftp'
Feb 26 12:33:45 systemvm systemd[1]: Starting Create Static Device Nodes in /dev...
Feb 26 12:33:45 systemvm systemd[1]: Finished Load Kernel Modules.
Feb 26 12:33:45 systemvm systemd[1]: Finished Load/Save Random Seed.
Feb 26 12:33:45 systemvm systemd[1]: Condition check resulted in First Boot Complete being skipped.
Feb 26 12:33:45 systemvm systemd[1]: Starting Apply Kernel Variables...
Feb 26 12:33:45 systemvm systemd[1]: Finished Coldplug All udev Devices.
Feb 26 12:33:45 systemvm systemd[1]: Starting Helper to synchronize boot up for ifupdown...
Feb 26 12:33:45 systemvm systemd[1]: Finished Create Static Device Nodes in /dev.
Feb 26 12:33:45 systemvm systemd[1]: Starting Rule-based Manager for Device Events and Files...
Feb 26 12:33:45 systemvm systemd-udevd[250]: Network interface NamePolicy= disabled on kernel command line, ignoring.
Feb 26 12:33:45 systemvm systemd[1]: Finished Set the console keyboard layout.
Feb 26 12:33:45 systemvm systemd[1]: Reached target Local File Systems (Pre).
Feb 26 12:33:45 systemvm systemd[1]: Started Rule-based Manager for Device Events and Files.
Feb 26 12:33:45 systemvm systemd[1]: Finished Apply Kernel Variables.
Feb 26 12:33:45 systemvm systemd-udevd[265]: Using default interface naming scheme 'v247'.
Feb 26 12:33:45 systemvm systemd[1]: Finished Flush Journal to Persistent Storage.
Feb 26 12:33:45 systemvm systemd[1]: Found device /dev/ttyS0.
Feb 26 12:33:45 systemvm systemd-udevd[265]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Feb 26 12:33:45 systemvm systemd-udevd[275]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Feb 26 12:33:45 systemvm systemd[1]: Found device /dev/disk/by-uuid/bd6b0a44-e740-4ac8-a007-26d35290e8c7.
Feb 26 12:33:45 systemvm systemd[1]: Starting File System Check on /dev/disk/by-uuid/bd6b0a44-e740-4ac8-a007-26d35290e8c7...
Feb 26 12:33:45 systemvm systemd[1]: Found device /dev/disk/by-uuid/e32e87d2-6c3e-4b5d-8c95-d70bb23a9ed9.
Feb 26 12:33:45 systemvm systemd[1]: Activating swap /dev/disk/by-uuid/e32e87d2-6c3e-4b5d-8c95-d70bb23a9ed9...
Feb 26 12:33:45 systemvm systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
Feb 26 12:33:45 systemvm systemd[1]: Condition check resulted in File System Check on Root Device being skipped.
Feb 26 12:33:45 systemvm systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped.
Feb 26 12:33:45 systemvm systemd[1]: Condition check resulted in Platform Persistent Storage Archival being skipped.
Feb 26 12:33:45 systemvm systemd[1]: Started File System Check Daemon to report status.
Feb 26 12:33:45 systemvm systemd[1]: Activated swap /dev/disk/by-uuid/e32e87d2-6c3e-4b5d-8c95-d70bb23a9ed9.
Feb 26 12:33:45 systemvm systemd[1]: Reached target Swap.
Feb 26 12:33:45 systemvm systemd-fsck[297]: /dev/vda1: clean, 347/97536 files, 59663/389120 blocks (check in 2 mounts)
Feb 26 12:33:45 systemvm systemd[1]: Finished File System Check on /dev/disk/by-uuid/bd6b0a44-e740-4ac8-a007-26d35290e8c7.
Feb 26 12:33:45 systemvm systemd[1]: Mounting /boot...
Feb 26 12:33:45 systemvm systemd[1]: Mounted /boot.
Feb 26 12:33:45 systemvm systemd[1]: Reached target Local File Systems.
Feb 26 12:33:45 systemvm systemd[1]: Starting Load AppArmor profiles...
Feb 26 12:33:45 systemvm systemd[1]: Starting CloudStack post-boot patching service using cmdline...
Feb 26 12:33:45 systemvm systemd[1]: Starting netfilter persistent configuration...
Feb 26 12:33:45 systemvm systemd[1]: Starting Preprocess NFS configuration...
Feb 26 12:33:45 systemvm systemd[1]: Condition check resulted in Store a System Token in an EFI Variable being skipped.
Feb 26 12:33:45 systemvm systemd[1]: Condition check resulted in Commit a transient machine-id on disk being skipped.
Feb 26 12:33:45 systemvm systemd[1]: Starting Create Volatile Files and Directories...
Feb 26 12:33:45 systemvm netfilter-persistent[308]: run-parts: executing /usr/share/netfilter-persistent/plugins.d/15-ip4tables start
Feb 26 12:33:45 systemvm systemd[1]: nfs-config.service: Succeeded.
Feb 26 12:33:45 systemvm systemd[1]: Finished Preprocess NFS configuration.
Feb 26 12:33:45 systemvm systemd[1]: Condition check resulted in RPC security service for NFS client and server being skipped.
Feb 26 12:33:45 systemvm systemd[1]: Condition check resulted in RPC security service for NFS server being skipped.
Feb 26 12:33:45 systemvm systemd[1]: Reached target NFS client services.
Feb 26 12:33:45 systemvm systemd[1]: Reached target Remote File Systems (Pre).
Feb 26 12:33:45 systemvm systemd[1]: Reached target Remote File Systems.
Feb 26 12:33:45 systemvm apparmor.systemd[301]: Restarting AppArmor
Feb 26 12:33:45 systemvm apparmor.systemd[301]: Reloading AppArmor profiles
Feb 26 12:33:45 systemvm systemd[1]: Finished Create Volatile Files and Directories.
Feb 26 12:33:45 systemvm systemd[1]: Starting Update UTMP about System Boot/Shutdown...
Feb 26 12:33:45 systemvm cloud-early-config[302]: Executing cloud-early-config.
Feb 26 12:33:45 systemvm systemd[1]: Finished Update UTMP about System Boot/Shutdown.
Feb 26 12:33:45 systemvm systemd[1]: Finished Load AppArmor profiles.
Feb 26 12:33:45 systemvm systemd[1]: Started Entropy Daemon based on the HAVEGE algorithm.
Feb 26 12:33:45 systemvm systemd[1]: Reached target System Initialization.
Feb 26 12:33:45 systemvm systemd[1]: Started ACPI Events Check.
Feb 26 12:33:45 systemvm systemd[1]: Started Periodic ext4 Online Metadata Check for All Filesystems.
Feb 26 12:33:45 systemvm systemd[1]: Started Discard unused blocks once a week.
Feb 26 12:33:45 systemvm systemd[1]: Started Daily rotation of log files.
Feb 26 12:33:45 systemvm systemd[1]: Started Run system activity accounting tool every 10 minutes.
Feb 26 12:33:45 systemvm systemd[1]: Started Generate summary of yesterday's process accounting.
Feb 26 12:33:45 systemvm systemd[1]: Started Daily Cleanup of Temporary Directories.
Feb 26 12:33:45 systemvm systemd[1]: Reached target Paths.
Feb 26 12:33:45 systemvm systemd[1]: Reached target Timers.
Feb 26 12:33:45 systemvm systemd[1]: Listening on ACPID Listen Socket.
Feb 26 12:33:45 systemvm systemd[1]: Listening on D-Bus System Message Bus Socket.
Feb 26 12:33:45 systemvm systemd[1]: Reached target Sockets.
Feb 26 12:33:45 systemvm systemd[1]: Reached target Basic System.
Feb 26 12:33:45 systemvm systemd[1]: Started ACPI event daemon.
Feb 26 12:33:45 systemvm systemd[1]: Started Regular background program processing daemon.
Feb 26 12:33:45 systemvm systemd[1]: Started D-Bus System Message Bus.
Feb 26 12:33:45 systemvm systemd[1]: Starting Remove Stale Online ext4 Metadata Check Snapshots...
Feb 26 12:33:45 systemvm systemd[1]: Condition check resulted in getty on tty2-tty6 if dbus and logind are not available being skipped.
Feb 26 12:33:45 systemvm systemd[1]: Started irqbalance daemon.
Feb 26 12:33:45 systemvm systemd[1]: Started QEMU Guest Agent.
Feb 26 12:33:45 systemvm systemd[1]: Starting System Logging Service...
Feb 26 12:33:45 systemvm systemd[1]: Starting Resets System Activity Logs...
Feb 26 12:33:45 systemvm systemd[1]: Starting User Login Management...
Feb 26 12:33:45 systemvm haveged[345]: haveged: command socket is listening at fd 3
Feb 26 12:33:45 systemvm systemd[1]: Starting Rotate log files...
Feb 26 12:33:45 systemvm systemd[1]: Finished Resets System Activity Logs.
Feb 26 12:33:45 systemvm systemd[1]: e2scrub_reap.service: Succeeded.
Feb 26 12:33:45 systemvm systemd[1]: Finished Remove Stale Online ext4 Metadata Check Snapshots.
Feb 26 12:33:45 systemvm systemd[1]: Started System Logging Service.
Feb 26 12:33:45 systemvm logrotate[361]: error: Ignoring /etc/logrotate.conf because it is writable by group or others.
Feb 26 12:33:45 systemvm systemd[1]: logrotate.service: Succeeded.
Feb 26 12:33:45 systemvm systemd[1]: Finished Rotate log files.
Feb 26 12:33:45 systemvm systemd[1]: Started User Login Management.
Feb 26 12:33:45 systemvm netfilter-persistent[308]: run-parts: executing /usr/share/netfilter-persistent/plugins.d/25-ip6tables start
Feb 26 12:33:45 systemvm systemd[1]: Finished netfilter persistent configuration.
Feb 26 12:33:45 systemvm acpid: starting up with netlink and the input layer
Feb 26 12:33:45 systemvm acpid: 2 rules loaded
Feb 26 12:33:45 systemvm acpid: waiting for events: event logging is off
Feb 26 12:33:45 systemvm haveged[345]: haveged: ver: 1.9.14; arch: x86; vend: GenuineIntel; build: (gcc 10.2.1 ITV); collect: 128K
Feb 26 12:33:45 systemvm haveged[345]: haveged: cpu: (L4 VC); data: 32K (L2 L4 V); inst: 32K (L2 L4 V); idx: 24/40; sz: 32154/54019
Feb 26 12:33:45 systemvm haveged[345]: haveged: tot tests(BA8): A:1/1 B:1/1 continuous tests(B):  last entropy estimate 8.00141
Feb 26 12:33:45 systemvm haveged[345]: haveged: fills: 0, generated: 0
Feb 26 12:33:45 systemvm cloud-early-config[344]: CHANGED: partition=2 start=782334 old: size=7407618 end=8189952 new: size=41160673 end=41943007
Feb 26 12:33:45 systemvm systemd[1]: Finished Helper to synchronize boot up for ifupdown.
Feb 26 12:33:45 systemvm cloud-early-config[405]: CHANGED: partition=6 start=1282048 old: size=6907904 end=8189952 new: size=40660959 end=41943007
Feb 26 12:33:45 systemvm cloud-early-config[425]: resize2fs 1.46.2 (28-Feb-2021)
Feb 26 12:33:45 systemvm cloud-early-config[425]: Filesystem at /dev/vda6 is mounted on /; on-line resizing required
Feb 26 12:33:45 systemvm cloud-early-config[425]: old_desc_blocks = 1, new_desc_blocks = 3
Feb 26 12:33:45 systemvm cloud-early-config[425]: The filesystem on /dev/vda6 is now 5082619 (4k) blocks long.
Feb 26 12:33:46 systemvm cloud-early-config[428]: mount: /media/cdrom0: no medium found on /dev/sr0.
Feb 26 12:33:46 systemvm cloud-early-config[302]: Scripts checksum detected: oldmd5=a873c9a2e74802afe6758afcea47375b newmd5=.
Feb 26 12:33:46 systemvm cloud-early-config[432]: Bootstrapping systemvm appliance.
Feb 26 12:33:46 systemvm cloud-early-config[432]: Starting guest services for kvm.
Feb 26 12:33:46 systemvm systemd[1]: Reloading.
Feb 26 12:33:46 systemvm systemd[1]: Reloading.
Feb 26 12:33:46 systemvm cloud-early-config[516]: CONFIG_HOTPLUG_PCI=y
Feb 26 12:33:46 systemvm cloud-early-config[516]: CONFIG_HOTPLUG_PCI_ACPI=y
Feb 26 12:33:46 systemvm cloud-early-config[432]: acpiphp and pci_hotplug module already compiled in.
Feb 26 12:33:46 systemvm cloud-early-config[520]: Synchronizing state of qemu-guest-agent.service with SysV service script with /lib/systemd/systemd-sysv-install.
Feb 26 12:33:46 systemvm cloud-early-config[520]: Executing: /lib/systemd/systemd-sysv-install enable qemu-guest-agent
Feb 26 12:33:46 systemvm systemd[1]: Reloading.
Feb 26 12:33:46 systemvm systemd[1]: Reloading.
Feb 26 12:33:46 systemvm systemd[1]: Reloading.
Feb 26 12:33:46 systemvm cloud-early-config[520]: The unit files have no installation config (WantedBy=, RequiredBy=, Also=,
Feb 26 12:33:46 systemvm cloud-early-config[520]: Alias= settings in the [Install] section, and DefaultInstance= for template
Feb 26 12:33:46 systemvm cloud-early-config[520]: units). This means they are not meant to be enabled using systemctl.
Feb 26 12:33:46 systemvm cloud-early-config[520]:
Feb 26 12:33:46 systemvm cloud-early-config[520]: Possible reasons for having this kind of units are:
Feb 26 12:33:46 systemvm cloud-early-config[520]: • A unit may be statically enabled by being symlinked from another unit's
Feb 26 12:33:46 systemvm cloud-early-config[520]:   .wants/ or .requires/ directory.
Feb 26 12:33:46 systemvm cloud-early-config[520]: • A unit's purpose may be to act as a helper for some other unit which has
Feb 26 12:33:46 systemvm cloud-early-config[520]:   a requirement dependency on it.
Feb 26 12:33:46 systemvm cloud-early-config[520]: • A unit may be started when needed via activation (socket, path, timer,
Feb 26 12:33:46 systemvm cloud-early-config[520]:   D-Bus, udev, scripted systemctl call, ...).
Feb 26 12:33:46 systemvm cloud-early-config[520]: • In case of template units, the unit is meant to be enabled with someFeb 26 12:33:46 systemvm cloud-early-config[520]:   instance name specified.
Feb 26 12:33:46 systemvm cloud-early-config[432]: Received a new non-empty cmdline file from qemu-guest-agent.
Feb 26 12:33:46 systemvm cloud-early-config[432]: Booting from cloudstack, remove old configuration files in /etc/cloudstack/.
Feb 26 12:33:46 systemvm systemd[1]: Reloading.
Feb 26 12:33:47 systemvm cloud-early-config[599]: umount: /media/cdrom: not mounted.
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.ip_forward = 1
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.default.rp_filter = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.default.accept_source_route = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.default.arp_announce = 2
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.default.arp_ignore = 2
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.all.arp_announce = 2
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.all.arp_ignore = 2
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.all.accept_redirects = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.default.accept_redirects = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.all.send_redirects = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.default.send_redirects = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.all.secure_redirects = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.default.secure_redirects = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.all.promote_secondaries = 1
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.conf.default.promote_secondaries = 1
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.ip_nonlocal_bind = 1
Feb 26 12:33:47 systemvm cloud-early-config[605]: kernel.sysrq = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: kernel.core_uses_pid = 1
Feb 26 12:33:47 systemvm cloud-early-config[605]: kernel.panic = 10
Feb 26 12:33:47 systemvm cloud-early-config[605]: kernel.panic_on_oops = 1
Feb 26 12:33:47 systemvm cloud-early-config[605]: vm.panic_on_oom = 1
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.tcp_syncookies = 1
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.tcp_timestamps = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.tcp_tw_reuse = 1
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv4.tcp_max_tw_buckets = 1000000
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.core.somaxconn = 65535
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.nf_conntrack_max = 1000000
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.netfilter.nf_conntrack_max = 1000000
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv6.conf.all.disable_ipv6 = 1
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv6.conf.all.forwarding = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv6.conf.all.accept_ra = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv6.conf.all.accept_redirects = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: net.ipv6.conf.all.autoconf = 0
Feb 26 12:33:47 systemvm cloud-early-config[605]: vm.swappiness = 1
Feb 26 12:33:47 systemvm cloud-early-config[605]: vm.vfs_cache_pressure = 100
Feb 26 12:33:47 systemvm cloud-early-config[605]: vm.min_free_kbytes = 20480
Feb 26 12:33:47 systemvm cloud-early-config[432]: Configuring systemvm type=cksnode.
Feb 26 12:33:47 systemvm cloud-early-config[607]: Setting up k8s node.
Feb 26 12:33:47 systemvm cloud-early-config[681]: update-alternatives: using /usr/sbin/iptables-legacy to provide /usr/sbin/iptables (iptables) in manual mode
Feb 26 12:33:47 systemvm cloud-early-config[682]: update-alternatives: using /usr/sbin/ip6tables-legacy to provide /usr/sbin/ip6tables (ip6tables) in manual mode
Feb 26 12:33:47 systemvm cloud-early-config[683]: update-alternatives: error: alternative /usr/sbin/arptables-legacy for arptables not registered; not setting
Feb 26 12:33:47 systemvm cloud-early-config[684]: update-alternatives: error: alternative /usr/sbin/ebtables-legacy for ebtables not registered; not setting
Feb 26 12:33:47 systemvm cloud-early-config[686]: passwd: password expiry information changed.
Feb 26 12:33:47 systemvm systemd[1]: dev-disk-by\x2did-virtio\x2d9e0316b3c7be41a3b9fa\x2dpart5.swap: Succeeded.
Feb 26 12:33:47 systemvm systemd[1]: dev-disk-by\x2duuid-e32e87d2\x2d6c3e\x2d4b5d\x2d8c95\x2dd70bb23a9ed9.swap: Succeeded.
Feb 26 12:33:47 systemvm systemd[1]: dev-disk-by\x2dpath-virtio\x2dpci\x2d0000:00:05.0\x2dpart5.swap: Succeeded.
Feb 26 12:33:47 systemvm systemd[1]: dev-disk-by\x2dpath-pci\x2d0000:00:05.0\x2dpart5.swap: Succeeded.
Feb 26 12:33:47 systemvm systemd[1]: dev-disk-by\x2dpartuuid-0adaee36\x2d05.swap: Succeeded.
Feb 26 12:33:47 systemvm systemd[1]: dev-vda5.swap: Succeeded.
Feb 26 12:33:47 systemvm cloud-early-config[694]: sudo: unable to resolve host systemvm: Temporary failure in name resolution
Feb 26 12:33:47 systemvm cloud-early-config[607]: Swap disabled.
Feb 26 12:33:47 systemvm cloud-early-config[607]: Setting up interfaces.
Feb 26 12:33:47 systemvm cloud-early-config[699]: ifdown: interface eth0 not configured
Feb 26 12:33:47 systemvm cloud-early-config[725]: ifdown: /etc/network/interfaces:9: option with empty value
Feb 26 12:33:47 systemvm cloud-early-config[725]: ifdown: couldn't read interfaces file "/etc/network/interfaces"
Feb 26 12:33:47 systemvm cloud-early-config[726]: ifup: /etc/network/interfaces:9: option with empty value
Feb 26 12:33:47 systemvm cloud-early-config[726]: ifup: couldn't read interfaces file "/etc/network/interfaces"
Feb 26 12:33:47 systemvm dbus-daemon[349]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.2' (uid=0 pid=727 comm="hostnamectl set-hostname kubernetescluster-node-17")
Feb 26 12:33:47 systemvm systemd[1]: Starting Hostname Service...
Feb 26 12:33:47 systemvm dbus-daemon[349]: [system] Successfully activated service 'org.freedesktop.hostname1'
Feb 26 12:33:47 systemvm systemd[1]: Started Hostname Service.
Feb 26 12:33:47 systemvm systemd-hostnamed[728]: Changed hostname to 'kubernetescluster-node-17f3605b39a'
Feb 26 12:33:47 systemvm cloud-early-config[730]: sed: can't read /etc/dnsmasq-resolv.conf: No such file or directory
Feb 26 12:33:47 systemvm cloud-early-config[731]: RTNETLINK answers: No such process
Feb 26 12:33:47 systemvm cloud-early-config[607]: Setting up route of RFC1918 space to .
Feb 26 12:33:47 systemvm cloud-early-config[739]: Command line is not complete. Try option "help"
Feb 26 12:33:47 systemvm cloud-early-config[740]: Command line is not complete. Try option "help"
Feb 26 12:33:47 systemvm cloud-early-config[741]: Command line is not complete. Try option "help"
Feb 26 12:33:47 systemvm cloud-early-config[737]: PING 172.26.21.1 (172.26.21.1): 56 data bytes
Feb 26 12:33:47 systemvm cloud-early-config[737]: 64 bytes from 172.26.21.1: icmp_seq=0 ttl=64 time=0.226 ms
Feb 26 12:33:47 systemvm cloud-early-config[607]: Setting up entry in hosts.
Feb 26 12:33:47 systemvm cloud-early-config[607]: cloud: disable rp_filter.
Feb 26 12:33:47 systemvm cloud-early-config[607]: disable rpfilter.
Feb 26 12:33:47 systemvm cloud-early-config[607]: cloud: enable_fwding = 1.
Feb 26 12:33:47 systemvm cloud-early-config[607]: enable_fwding = 1.
Feb 26 12:33:47 systemvm cloud-early-config[607]: Processors = 4  Enable service  = 0.
Feb 26 12:33:47 systemvm cloud-early-config[607]: Setting up NTP.
Feb 26 12:33:47 systemvm cloud-early-config[758]: Synchronizing state of ntp.service with SysV service script with /lib/systemd/systemd-sysv-install.
Feb 26 12:33:47 systemvm cloud-early-config[758]: Executing: /lib/systemd/systemd-sysv-install enable ntp
Feb 26 12:33:47 systemvm systemd[1]: Reloading.
Feb 26 12:33:47 systemvm systemd[1]: Reloading.
Feb 26 12:33:47 systemvm systemd[1]: Reloading.
Feb 26 12:33:47 systemvm dhclient[814]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3
Feb 26 12:33:47 systemvm dhclient[814]: DHCPOFFER of 172.26.21.186 from 172.26.21.1
Feb 26 12:33:47 systemvm dhclient[814]: DHCPREQUEST for 172.26.21.186 on eth0 to 255.255.255.255 port 67
Feb 26 12:33:47 systemvm dhclient[814]: DHCPACK of 172.26.21.186 from 172.26.21.1
Feb 26 12:33:47 systemvm cloud-early-config[826]: RTNETLINK answers: File exists
Feb 26 12:33:47 systemvm dhclient[814]: Timeout too large reducing to: 2147483646 (TIME_MAX - 1)
Feb 26 12:33:47 systemvm dhclient[814]: bound to 172.26.21.186 -- renewal in 2147483648 seconds.
Feb 26 12:33:47 systemvm cloud-early-config[607]: Starting cloud-init services.
Feb 26 12:33:47 systemvm cloud-early-config[836]: Created symlink /etc/systemd/system/multi-user.target.wants/containerd.service → /lib/systemd/system/containerd.service.
Feb 26 12:33:47 systemvm systemd[1]: Reloading.
Feb 26 12:33:48 systemvm cloud-early-config[853]: Created symlink /etc/systemd/system/sockets.target.wants/docker.socket → /lib/systemd/system/docker.socket.
Feb 26 12:33:48 systemvm systemd[1]: Reloading.
Feb 26 12:33:48 systemvm systemd[1]: Starting Docker Socket for the API.
Feb 26 12:33:48 systemvm cloud-early-config[870]: Synchronizing state of docker.service with SysV service script with /lib/systemd/systemd-sysv-install.
Feb 26 12:33:48 systemvm cloud-early-config[870]: Executing: /lib/systemd/systemd-sysv-install enable docker
Feb 26 12:33:48 systemvm systemd[1]: Listening on Docker Socket for the API.
Feb 26 12:33:48 systemvm systemd[1]: Reloading.
Feb 26 12:33:48 systemvm cloud-early-config[737]: 64 bytes from 172.26.21.1: icmp_seq=1 ttl=64 time=0.186 ms
Feb 26 12:33:48 systemvm systemd[1]: Reloading.
Feb 26 12:33:48 systemvm cloud-early-config[870]: Created symlink /etc/systemd/system/multi-user.target.wants/docker.service → /lib/systemd/system/docker.service.
Feb 26 12:33:48 systemvm systemd[1]: Reloading.
Feb 26 12:33:48 systemvm systemd[1]: Starting Initial cloud-init job (pre-networking)...
Feb 26 12:33:48 systemvm cloud-early-config[432]: Finished setting up systemvm.
Feb 26 12:33:48 systemvm cloud-early-config[302]: Finished setting up systemvm.
Feb 26 12:33:48 systemvm systemd[1]: Finished CloudStack post-boot patching service using cmdline.
Feb 26 12:33:49 systemvm cloud-init[935]: Cloud-init v. 20.4.1 running 'init-local' at Sat, 26 Feb 2022 12:33:49 +0000. Up 6.52 seconds.
Feb 26 12:33:49 systemvm systemd[1]: Finished Initial cloud-init job (pre-networking).
Feb 26 12:33:49 systemvm systemd[1]: Reached target Network (Pre).
Feb 26 12:33:49 systemvm systemd[1]: Starting Raise network interfaces...
Feb 26 12:33:49 systemvm ifup[939]: ifup: /etc/network/interfaces:9: option with empty value
Feb 26 12:33:49 systemvm ifup[939]: ifup: couldn't read interfaces file "/etc/network/interfaces"
Feb 26 12:33:49 systemvm systemd[1]: networking.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:33:49 systemvm systemd[1]: networking.service: Failed with result 'exit-code'.
Feb 26 12:33:49 systemvm systemd[1]: Failed to start Raise network interfaces.
Feb 26 12:33:49 systemvm systemd[1]: Reached target Network.
Feb 26 12:33:49 systemvm systemd[1]: Starting Initial cloud-init job (metadata service crawler)...
Feb 26 12:33:49 systemvm systemd[1]: Starting CloudStack post-patching init script...
Feb 26 12:33:49 systemvm systemd[1]: Starting containerd container runtime...
Feb 26 12:33:49 systemvm systemd[1]: Starting Network Time Service...
Feb 26 12:33:49 systemvm systemd[1]: Condition check resulted in fast remote file copy program daemon being skipped.
Feb 26 12:33:49 systemvm systemd[1]: Stopping Flush Journal to Persistent Storage...
Feb 26 12:33:49 systemvm systemd-udevd[250]: Network interface NamePolicy= disabled on kernel command line, ignoring.
Feb 26 12:33:49 systemvm cloud-early-config[737]: 64 bytes from 172.26.21.1: icmp_seq=2 ttl=64 time=0.768 ms
Feb 26 12:33:49 systemvm cloud-early-config[737]: --- 172.26.21.1 ping statistics ---
Feb 26 12:33:49 systemvm cloud-early-config[737]: 3 packets transmitted, 3 packets received, 0% packet loss
Feb 26 12:33:49 systemvm cloud-early-config[737]: round-trip min/avg/max/stddev = 0.186/0.393/0.768/0.265 ms
Feb 26 12:33:49 systemvm systemd[1]: systemd-journal-flush.service: Succeeded.
Feb 26 12:33:49 systemvm systemd[1]: Stopped Flush Journal to Persistent Storage.
Feb 26 12:33:49 systemvm ntpd[943]: ntpd 4.2.8p15@1.3728-o Wed Sep 23 11:46:38 UTC 2020 (1): Starting
Feb 26 12:33:49 systemvm ntpd[943]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 106:112
Feb 26 12:33:49 systemvm ntpd[943]: ----------------------------------------------------
Feb 26 12:33:49 systemvm ntpd[943]: ntp-4 is maintained by Network Time Foundation,
Feb 26 12:33:49 systemvm ntpd[943]: Inc. (NTF), a non-profit 501(c)(3) public-benefit
Feb 26 12:33:49 systemvm ntpd[943]: corporation.  Support and training for ntp-4 are
Feb 26 12:33:49 systemvm ntpd[943]: available at https://www.nwtime.org/support
Feb 26 12:33:49 systemvm ntpd[943]: ----------------------------------------------------
Feb 26 12:33:49 systemvm ntpd[954]: proto: precision = 0.059 usec (-24)
Feb 26 12:33:49 systemvm ntpd[954]: basedate set to 2020-09-11
Feb 26 12:33:49 systemvm ntpd[954]: gps base set to 2020-09-13 (week 2123)
Feb 26 12:33:49 systemvm ntpd[954]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): stat failed: No such file or directory
Feb 26 12:33:49 systemvm ntpd[954]: Listen and drop on 0 v6wildcard [::]:123
Feb 26 12:33:49 systemvm ntpd[954]: Listen and drop on 1 v4wildcard 0.0.0.0:123
Feb 26 12:33:49 systemvm ntpd[954]: Listen normally on 2 lo 127.0.0.1:123
Feb 26 12:33:49 systemvm ntpd[954]: Listen normally on 3 eth0 172.26.21.186:123
Feb 26 12:33:49 systemvm ntpd[954]: Listening on routing socket on fd #20 for interface updates
Feb 26 12:33:49 systemvm ntpd[954]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
Feb 26 12:33:49 systemvm ntpd[954]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
Feb 26 12:33:49 systemvm systemd[1]: Starting Flush Journal to Persistent Storage...
Feb 26 12:33:49 systemvm systemd[1]: Finished Flush Journal to Persistent Storage.
Feb 26 12:33:49 systemvm systemd[1]: Reloading.
Feb 26 12:33:49 systemvm systemd[1]: Started containerd container runtime.
Feb 26 12:33:49 systemvm systemd[1]: Reloading.
Feb 26 12:33:49 systemvm systemd[1]: Reloading.
Feb 26 12:33:50 systemvm systemd[1]: Finished CloudStack post-patching init script.
Feb 26 12:33:50 systemvm systemd[1]: Finished Initial cloud-init job (metadata service crawler).
Feb 26 12:33:50 systemvm systemd[1]: Reached target Cloud-config availability.
Feb 26 12:33:50 systemvm systemd[1]: Reached target Network is Online.
Feb 26 12:33:50 systemvm systemd[1]: Starting Apply the settings specified in cloud-config...
Feb 26 12:33:50 systemvm systemd[1]: Starting Docker Application Container Engine...
Feb 26 12:33:50 systemvm systemd[1]: Starting LSB: ipvsadm daemon...
Feb 26 12:33:50 systemvm systemd[1]: Starting OpenBSD Secure Shell server...
Feb 26 12:33:50 systemvm systemd[1]: Starting Permit User Sessions...
Feb 26 12:33:50 systemvm systemd[1]: Finished Permit User Sessions.
Feb 26 12:33:50 systemvm systemd[1]: Started Getty on tty1.
Feb 26 12:33:50 systemvm systemd[1]: Started Serial Getty on ttyS0.
Feb 26 12:33:50 systemvm ipvsadm[1094]: ipvsadm is not configured to run. Please edit /etc/default/ipvsadm.
Feb 26 12:33:50 systemvm systemd[1]: Reached target Login Prompts.
Feb 26 12:33:50 systemvm systemd[1]: Started LSB: ipvsadm daemon.
Feb 26 12:33:50 systemvm systemd[1]: Started OpenBSD Secure Shell server.
Feb 26 12:33:50 systemvm ntpd[954]: Soliciting pool server 45.86.70.11
Feb 26 12:33:50 systemvm dockerd[1093]: time="2022-02-26T12:33:50.693989364Z" level=info msg="Starting up"
Feb 26 12:33:50 systemvm cloud-init[1115]: Cloud-init v. 20.4.1 running 'modules:config' at Sat, 26 Feb 2022 12:33:50 +0000. Up 7.87 seconds.
Feb 26 12:33:50 systemvm dockerd[1093]: time="2022-02-26T12:33:50.726638659Z" level=info msg="parsed scheme: \"unix\"" module=grpc
Feb 26 12:33:50 systemvm dockerd[1093]: time="2022-02-26T12:33:50.726662171Z" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc
Feb 26 12:33:50 systemvm dockerd[1093]: time="2022-02-26T12:33:50.726731097Z" level=info msg="ccResolverWrapper: sending update to cc: {[{unix:///run/containerd/containerd.sock  <nil> 0 <nil>}] <nil> <nil>}" module=grpc
Feb 26 12:33:50 systemvm dockerd[1093]: time="2022-02-26T12:33:50.726773607Z" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc
Feb 26 12:33:50 systemvm dockerd[1093]: time="2022-02-26T12:33:50.736442156Z" level=info msg="parsed scheme: \"unix\"" module=grpc
Feb 26 12:33:50 systemvm dockerd[1093]: time="2022-02-26T12:33:50.736462950Z" level=info msg="scheme \"unix\" not registered, fallback to default scheme" module=grpc
Feb 26 12:33:50 systemvm dockerd[1093]: time="2022-02-26T12:33:50.736478391Z" level=info msg="ccResolverWrapper: sending update to cc: {[{unix:///run/containerd/containerd.sock  <nil> 0 <nil>}] <nil> <nil>}" module=grpc
Feb 26 12:33:50 systemvm dockerd[1093]: time="2022-02-26T12:33:50.736492358Z" level=info msg="ClientConn switching balancer to \"pick_first\"" module=grpc
Feb 26 12:33:50 systemvm dockerd[1093]: time="2022-02-26T12:33:50.763479644Z" level=info msg="[graphdriver] using prior storage driver: overlay2"
Feb 26 12:33:50 systemvm dockerd[1093]: time="2022-02-26T12:33:50.776078430Z" level=info msg="Loading containers: start."
Feb 26 12:33:50 systemvm systemd-udevd[953]: Using default interface naming scheme 'v247'.
Feb 26 12:33:50 systemvm systemd-udevd[953]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Feb 26 12:33:50 systemvm dockerd[1093]: time="2022-02-26T12:33:50.940895929Z" level=info msg="Default bridge (docker0) is assigned with an IP address 172.17.0.0/16. Daemon option --bip can be used to set a preferred IP address"
Feb 26 12:33:50 systemvm dockerd[1093]: time="2022-02-26T12:33:50.983954334Z" level=info msg="Loading containers: done."Feb 26 12:33:51 systemvm systemd[1]: var-lib-docker-overlay2-opaque\x2dbug\x2dcheck363468339-merged.mount: Succeeded.
Feb 26 12:33:51 systemvm dockerd[1093]: time="2022-02-26T12:33:51.050007308Z" level=info msg="Docker daemon" commit=75249d8 graphdriver(s)=overlay2 version=20.10.8
Feb 26 12:33:51 systemvm dockerd[1093]: time="2022-02-26T12:33:51.050842748Z" level=info msg="Daemon has completed initialization"
Feb 26 12:33:51 systemvm systemd[1]: Started Docker Application Container Engine.
Feb 26 12:33:51 systemvm systemd[1]: Reached target Multi-User System.
Feb 26 12:33:51 systemvm systemd[1]: Reached target Graphical Interface.
Feb 26 12:33:51 systemvm dockerd[1093]: time="2022-02-26T12:33:51.075948655Z" level=info msg="API listen on /run/docker.sock"
Feb 26 12:33:51 systemvm systemd[1]: Starting Update UTMP about System Runlevel Changes...
Feb 26 12:33:51 systemvm systemd[1]: Finished Apply the settings specified in cloud-config.
Feb 26 12:33:51 systemvm systemd[1]: Starting Execute cloud user/final scripts...
Feb 26 12:33:51 systemvm systemd[1]: systemd-update-utmp-runlevel.service: Succeeded.
Feb 26 12:33:51 systemvm systemd[1]: Finished Update UTMP about System Runlevel Changes.
Feb 26 12:33:51 systemvm cloud-init[1265]: Cloud-init v. 20.4.1 running 'modules:final' at Sat, 26 Feb 2022 12:33:51 +0000. Up 8.54 seconds.
Feb 26 12:33:51 systemvm systemd[1]: Configuration file /etc/systemd/system/setup-kube-system.service is marked executable. Please remove executable permission bits. Proceeding anyway.
Feb 26 12:33:51 systemvm ntpd[954]: Soliciting pool server 162.159.200.1
Feb 26 12:33:51 systemvm ntpd[954]: Soliciting pool server 157.245.102.2
Feb 26 12:33:51 systemvm systemd[1]: Started setup-kube-system.service.
Feb 26 12:33:51 systemvm cloud-init[1265]: Failed to start deploy-kube-system.service: Unit deploy-kube-system.service not found.
Feb 26 12:33:51 systemvm cloud-init[1265]: 2022-02-26 12:33:51,448 - cc_scripts_user.py[WARNING]: Failed to run module scripts-user (scripts in /var/lib/cloud/instance/scripts)
Feb 26 12:33:51 systemvm cloud-init[1265]: 2022-02-26 12:33:51,449 - util.py[WARNING]: Running module scripts-user (<module 'cloudinit.config.cc_scripts_user' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_user.py'>) failed
Feb 26 12:33:51 systemvm setup-kube-system[1268]: Installing binaries from /mnt/k8sdisk/
Feb 26 12:33:51 systemvm cloud-init[1265]: Cloud-init v. 20.4.1 finished at Sat, 26 Feb 2022 12:33:51 +0000. Datasource DataSourceCloudStack.  Up 8.72 seconds
Feb 26 12:33:51 systemvm systemd[1]: cloud-final.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:33:51 systemvm systemd[1]: cloud-final.service: Failed with result 'exit-code'.
Feb 26 12:33:51 systemvm systemd[1]: Failed to start Execute cloud user/final scripts.
Feb 26 12:33:51 systemvm systemd[1]: Startup finished in 1.729s (kernel) + 7.034s (userspace) = 8.764s.
Feb 26 12:33:52 systemvm ntpd[954]: Soliciting pool server 192.46.210.39
Feb 26 12:33:52 systemvm ntpd[954]: Soliciting pool server 13.126.27.131
Feb 26 12:33:53 systemvm ntpd[954]: Soliciting pool server 162.159.200.123
Feb 26 12:33:53 systemvm ntpd[954]: Soliciting pool server 128.199.23.217
Feb 26 12:33:53 systemvm ntpd[954]: Soliciting pool server 193.203.3.170
Feb 26 12:33:54 systemvm ntpd[954]: Soliciting pool server 45.85.15.7
Feb 26 12:33:54 systemvm ntpd[954]: Soliciting pool server 95.216.192.15
Feb 26 12:33:54 systemvm setup-kube-system[1298]: Loaded image: shapeblue/cloudstack-k8s-autoscaler:v1.0.0
Feb 26 12:33:55 systemvm ntpd[954]: Soliciting pool server 138.197.15.27
Feb 26 12:33:55 systemvm ntpd[954]: Soliciting pool server 165.22.211.200
Feb 26 12:33:55 systemvm setup-kube-system[1328]: Loaded image: apache/cloudstack-kubernetes-provider:v1.0.0
Feb 26 12:33:56 systemvm setup-kube-system[1361]: Loaded image: k8s.gcr.io/coredns/coredns:v1.8.4
Feb 26 12:33:56 systemvm ntpd[954]: Soliciting pool server 188.125.64.6
Feb 26 12:33:56 systemvm ntpd[954]: Soliciting pool server 2001:6c8:110:c8::213
Feb 26 12:33:58 systemvm setup-kube-system[1394]: Loaded image: kubernetesui/dashboard:v2.3.1
Feb 26 12:33:59 systemvm ntpd[954]: receive: flip 0 KoD origin timestamp 0xe5c49cb7.6eec437e from 165.22.211.200 does not match 0000000000.00000000 - ignoring.
Feb 26 12:33:59 systemvm ntpd[954]: receive: Unexpected origin timestamp 0xe5c49cb7.6ef075cf does not match aorg 0000000000.00000000 from server@157.245.102.2 xmt 0xe5c49cb7.f8c52086
Feb 26 12:34:00 systemvm ntpd[954]: receive: Unexpected origin timestamp 0xe5c49cb7.6eed9e2a does not match aorg 0000000000.00000000 from server@162.159.200.123 xmt 0xe5c49cb7.ff02f10c
Feb 26 12:34:00 systemvm ntpd[954]: receive: Unexpected origin timestamp 0xe5c49cb7.6ee8fbdb does not match aorg 0000000000.00000000 from server@138.197.15.27 xmt 0xe5c49cb8.1ca9b996
Feb 26 12:34:00 systemvm ntpd[954]: receive: Unexpected origin timestamp 0xe5c49cb7.6eed1385 does not match aorg 0000000000.00000000 from server@45.85.15.7 xmt 0xe5c49cb8.2916ba8b
Feb 26 12:34:02 systemvm setup-kube-system[1426]: Loaded image: k8s.gcr.io/etcd:3.5.0-0
Feb 26 12:34:03 systemvm setup-kube-system[1470]: Loaded image: k8s.gcr.io/kube-apiserver:v1.22.2
Feb 26 12:34:04 systemvm setup-kube-system[1510]: Loaded image: k8s.gcr.io/kube-controller-manager:v1.22.2
Feb 26 12:34:06 systemvm setup-kube-system[1532]: Loaded image: k8s.gcr.io/kube-proxy:v1.22.2
Feb 26 12:34:06 systemvm setup-kube-system[1563]: Loaded image: k8s.gcr.io/kube-scheduler:v1.22.2
Feb 26 12:34:07 systemvm setup-kube-system[1588]: Loaded image: kubernetesui/metrics-scraper:v1.0.6
Feb 26 12:34:07 systemvm setup-kube-system[1620]: Loaded image: k8s.gcr.io/pause:3.5
Feb 26 12:34:08 systemvm setup-kube-system[1644]: Loaded image: weaveworks/weave-kube:latest
Feb 26 12:34:09 systemvm setup-kube-system[1704]: Loaded image: weaveworks/weave-npc:latest
Feb 26 12:34:09 systemvm systemd[1]: mnt-k8sdisk.mount: Succeeded.
Feb 26 12:34:09 systemvm systemd[1]: Starting Online ext4 Metadata Check for All Filesystems...
Feb 26 12:34:09 systemvm systemd[1]: e2scrub_all.service: Succeeded.
Feb 26 12:34:09 systemvm systemd[1]: Finished Online ext4 Metadata Check for All Filesystems.
Feb 26 12:34:09 systemvm setup-kube-system[1754]: Created symlink /etc/systemd/system/multi-user.target.wants/kubelet.service → /etc/systemd/system/kubelet.service.
Feb 26 12:34:09 systemvm systemd[1]: Reloading.
Feb 26 12:34:09 systemvm systemd[1]: Configuration file /etc/systemd/system/setup-kube-system.service is marked executable. Please remove executable permission bits. Proceeding anyway.
Feb 26 12:34:09 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:34:09 systemvm setup-kube-system[1774]: net.bridge.bridge-nf-call-iptables = 1
Feb 26 12:34:09 systemvm systemd[1]: setup-kube-system.service: Succeeded.
Feb 26 12:34:09 systemvm systemd[1]: setup-kube-system.service: Consumed 5.901s CPU time.
Feb 26 12:34:09 systemvm kubelet[1772]: E0226 12:34:09.598050    1772 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:34:09 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:34:09 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:34:15 systemvm systemd[1]: systemd-fsckd.service: Succeeded.
Feb 26 12:34:17 systemvm systemd[1]: systemd-hostnamed.service: Succeeded.
Feb 26 12:34:19 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 1.
Feb 26 12:34:19 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:34:19 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:34:19 systemvm kubelet[1786]: E0226 12:34:19.959422    1786 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:34:19 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:34:19 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:34:30 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 2.
Feb 26 12:34:30 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:34:30 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:34:30 systemvm kubelet[1794]: E0226 12:34:30.332657    1794 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:34:30 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:34:30 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:34:40 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 3.
Feb 26 12:34:40 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:34:40 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:34:40 systemvm kubelet[1803]: E0226 12:34:40.621914    1803 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:34:40 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:34:40 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:34:50 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 4.
Feb 26 12:34:50 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:34:50 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:34:50 systemvm kubelet[1811]: E0226 12:34:50.864893    1811 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:34:50 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:34:50 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:35:01 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 5.
Feb 26 12:35:01 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:35:01 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:35:01 systemvm kubelet[1819]: E0226 12:35:01.118538    1819 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:35:01 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:35:01 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:35:09 systemvm systemd[1]: Created slice User Slice of UID 1001.
Feb 26 12:35:09 systemvm systemd[1]: Starting User Runtime Directory /run/user/1001...
Feb 26 12:35:09 systemvm systemd[1]: Finished User Runtime Directory /run/user/1001.
Feb 26 12:35:09 systemvm systemd[1]: Starting User Manager for UID 1001...
Feb 26 12:35:09 systemvm systemd[1833]: PAM failed: Critical error - immediate abort
Feb 26 12:35:09 systemvm systemd[1833]: user@1001.service: Failed to set up PAM session: Operation not permitted
Feb 26 12:35:09 systemvm systemd[1833]: user@1001.service: Failed at step PAM spawning /lib/systemd/systemd: Operation not permitted
Feb 26 12:35:09 systemvm systemd[1]: user@1001.service: Main process exited, code=exited, status=224/PAM
Feb 26 12:35:09 systemvm systemd[1]: user@1001.service: Failed with result 'exit-code'.
Feb 26 12:35:09 systemvm systemd[1]: Failed to start User Manager for UID 1001.
Feb 26 12:35:09 systemvm systemd[1]: Started Session 2 of user core.
Feb 26 12:35:11 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 6.
Feb 26 12:35:11 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:35:11 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:35:11 systemvm kubelet[1846]: E0226 12:35:11.384016    1846 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:35:11 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:35:11 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:35:21 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 7.
Feb 26 12:35:21 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:35:21 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:35:21 systemvm kubelet[1855]: E0226 12:35:21.632872    1855 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:35:21 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:35:21 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:35:31 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 8.
Feb 26 12:35:31 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:35:31 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:35:31 systemvm kubelet[1863]: E0226 12:35:31.864335    1863 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:35:31 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:35:31 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:35:42 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 9.
Feb 26 12:35:42 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:35:42 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:35:42 systemvm kubelet[1872]: E0226 12:35:42.123207    1872 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:35:42 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:35:42 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:35:52 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 10.
Feb 26 12:35:52 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:35:52 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:35:52 systemvm kubelet[1882]: E0226 12:35:52.364229    1882 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:35:52 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:35:52 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:36:02 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 11.
Feb 26 12:36:02 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:36:02 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:36:02 systemvm kubelet[1902]: E0226 12:36:02.622287    1902 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:36:02 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:36:02 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:36:12 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 12.
Feb 26 12:36:12 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:36:12 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:36:12 systemvm kubelet[1910]: E0226 12:36:12.872266    1910 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:36:12 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:36:12 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:36:23 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 13.
Feb 26 12:36:23 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:36:23 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:36:23 systemvm kubelet[1921]: E0226 12:36:23.122647    1921 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:36:23 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:36:23 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:36:25 systemvm systemd[1]: session-2.scope: Succeeded.
Feb 26 12:36:25 systemvm systemd[1]: Stopping User Runtime Directory /run/user/1001...
Feb 26 12:36:25 systemvm systemd[1]: run-user-1001.mount: Succeeded.
Feb 26 12:36:25 systemvm systemd[1]: user-runtime-dir@1001.service: Succeeded.
Feb 26 12:36:25 systemvm systemd[1]: Stopped User Runtime Directory /run/user/1001.
Feb 26 12:36:25 systemvm systemd[1]: Removed slice User Slice of UID 1001.
Feb 26 12:36:33 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 14.
Feb 26 12:36:33 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:36:33 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:36:33 systemvm kubelet[1932]: E0226 12:36:33.366425    1932 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:36:33 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:36:33 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:36:43 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 15.
Feb 26 12:36:43 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:36:43 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:36:43 systemvm kubelet[1941]: E0226 12:36:43.630466    1941 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:36:43 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:36:43 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:36:53 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 16.
Feb 26 12:36:53 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:36:53 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:36:53 systemvm kubelet[1949]: E0226 12:36:53.875525    1949 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:36:53 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:36:53 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:37:04 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 17.
Feb 26 12:37:04 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:37:04 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:37:04 systemvm kubelet[1957]: E0226 12:37:04.120658    1957 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:37:04 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:37:04 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:37:12 systemvm systemd[1]: Created slice User Slice of UID 1001.
Feb 26 12:37:12 systemvm systemd[1]: Starting User Runtime Directory /run/user/1001...
Feb 26 12:37:12 systemvm systemd[1]: Finished User Runtime Directory /run/user/1001.
Feb 26 12:37:12 systemvm systemd[1]: Starting User Manager for UID 1001...
Feb 26 12:37:12 systemvm systemd[1968]: PAM failed: Critical error - immediate abort
Feb 26 12:37:12 systemvm systemd[1968]: user@1001.service: Failed to set up PAM session: Operation not permitted
Feb 26 12:37:12 systemvm systemd[1968]: user@1001.service: Failed at step PAM spawning /lib/systemd/systemd: Operation not permitted
Feb 26 12:37:12 systemvm systemd[1]: user@1001.service: Main process exited, code=exited, status=224/PAM
Feb 26 12:37:12 systemvm systemd[1]: user@1001.service: Failed with result 'exit-code'.
Feb 26 12:37:12 systemvm systemd[1]: Failed to start User Manager for UID 1001.
Feb 26 12:37:12 systemvm systemd[1]: Started Session 3 of user core.
Feb 26 12:37:14 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 18.
Feb 26 12:37:14 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:37:14 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:37:14 systemvm kubelet[1981]: E0226 12:37:14.385746    1981 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:37:14 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:37:14 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:37:24 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 19.
Feb 26 12:37:24 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:37:24 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:37:24 systemvm kubelet[1991]: E0226 12:37:24.621143    1991 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:37:24 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:37:24 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.
Feb 26 12:37:30 systemvm systemd[1]: session-3.scope: Succeeded.
Feb 26 12:37:30 systemvm systemd[1]: Stopping User Runtime Directory /run/user/1001...
Feb 26 12:37:30 systemvm systemd[1]: run-user-1001.mount: Succeeded.
Feb 26 12:37:30 systemvm systemd[1]: user-runtime-dir@1001.service: Succeeded.
Feb 26 12:37:30 systemvm systemd[1]: Stopped User Runtime Directory /run/user/1001.
Feb 26 12:37:30 systemvm systemd[1]: Removed slice User Slice of UID 1001.
Feb 26 12:37:34 systemvm systemd[1]: kubelet.service: Scheduled restart job, restart counter is at 20.
Feb 26 12:37:34 systemvm systemd[1]: Stopped kubelet: The Kubernetes Node Agent.
Feb 26 12:37:34 systemvm systemd[1]: Started kubelet: The Kubernetes Node Agent.
Feb 26 12:37:34 systemvm kubelet[2001]: E0226 12:37:34.869933    2001 server.go:206] "Failed to load kubelet config file" err="failed to load Kubelet config file /var/lib/kubelet/config.yaml, error failed to read kubelet config file \"/var/lib/kubelet/config.yaml\", error: open /var/lib/kubelet/config.yaml: no such file or directory" path="/var/lib/kubelet/config.yaml"
Feb 26 12:37:34 systemvm systemd[1]: kubelet.service: Main process exited, code=exited, status=1/FAILURE
Feb 26 12:37:34 systemvm systemd[1]: kubelet.service: Failed with result 'exit-code'.

On /var/log/auth.log, I don't see the management server performing SSH connection towards the worker node.

And finally the cluster state after Cluster creation timeout,

image

The first 2 Kubernetes clusters which I spun up with HA as well as non-HA control plane were successful in the creation and for some reason subsequent ones don't.

UPDATE:

I tried to start the services setup-kube-system.service and deploy-kube-system.services manually one by one on the nodes which were failing to, and now the cluster state is "Running".

image

A fix would be highly appreciated!

davidjumani commented 2 years ago

Looks like the issue is caused by trying to start the setup-kube-system && deploy-kube-system services which may not yet have been detected / have the .service files created Adding a potential fix to rerun the generators in https://github.com/apache/cloudstack/pull/6076 If needed, can add a fix to wait until the .service files have been created

nvazquez commented 2 years ago

Hi @edikevich can you please test the fix in #6076?

edikevich commented 2 years ago

Hi @nvazquez I don't have test environment now. I think this should help. I think it's worth adding a check for creating .service files.

davidjumani commented 2 years ago

I've made the changes, will run tests to confirm it works

nvazquez commented 2 years ago

Fixed on PR #6076