Hey Serge, We cannot see the screenshots because the mailing group protection strips them. However you can provide a link to a hosted image. If you doubt networking disable firewalls/iptables. Cloudstack VM communicates with the hypervisor host through management. Public network are required by SSVMs to access external sources such internet or as a entry/exit point for NAT-ed user networks.
Next go to ACS GUI and check if Zone is enabled? Then go to pod -> clusters -> hosts and check if any of those has any red alert instead of a green dot. If such exists around cluster level and below β make sure you configured the network traffic labels correct. I have not played with ACS + KVM so I cannot give specifics here. Best regards, Jordan From: Serge Byishimo <sergebyish...@gmail.com> Sent: Thursday, May 20, 2021 11:02 AM To: users@cloudstack.apache.org Subject: Re: I Need Help ππΌ [X]This message came from outside your organization This is the Host Information [Screenshot 2021-05-20 at 10-01-32 Hosts - CloudStack.png] On Thu, May 20, 2021 at 9:48 AM Serge Byishimo <sergebyish...@gmail.com<mailto:sergebyish...@gmail.com>> wrote: I mounted the secondary storage on the management server /export/secondary from 192.168.1.7:/export/secondary [root@srvr1 secondary]# ll total 20 drwx------. 2 root root 16384 May 18 16:18 lost+found drwxr-xr-x. 3 root root 4096 May 19 11:56 template [root@srvr1 secondary]# there is a template directory with template files [root@srvr1 secondary]# ll template/tmpl/1/3 total 365536 -rw-r--r--. 1 root root 374303744 May 19 11:58 1e6e90ea-c7e8-421f-b403-7a5e4bce848c.qcow2 -rw-r--r--. 1 root root 287 May 19 11:58 template.properties [root@srvr1 secondary]# It is downloaded as you can see on the attached screenshots I think it might be a networking issue coz I got confused with the public IP range and I put one IP that I have 209.150.129β, but it doesnβt have anything to do with this set up, except that I use it to access resources on the outside by port forwarding them Attached also is the console proxy and secondary storage VM, they are all stuck starting as shown in another screenshot [Screenshot 2021-05-20 at 09-39-43 Templates - CloudStack.png] [Screenshot 2021-05-20 at 09-41-25 System VMs - CloudStack.png] [Screenshot 2021-05-20 at 09-41-41 System VMs - CloudStack.png] [Screen Shot 2021-05-20 at 09.47.20.png] On Thu, May 20, 2021 at 9:31 AM Yordan Kostov <yord...@nsogroup.com<mailto:yord...@nsogroup.com>> wrote: Did you by any chance download and update the system vm templates? http://docs.cloudstack.apache.org/en/latest/installguide/management-server/index.html#prepare-the-system-vm-template<https://urldefense.com/v3/__http:/docs.cloudstack.apache.org/en/latest/installguide/management-server/index.html*prepare-the-system-vm-template__;Iw!!A6UyJA!xdMOpDgufOBL1WXIgUcUxgTcbsdp8WmZnpUB-DBK4ReGRx8n17VhUmhYJTvKy6me5hqQCYLdQ3Ow$> That is another reason for the SSVM not starting. Regards, Jordan From: Serge Byishimo <sergebyish...@gmail.com<mailto:sergebyish...@gmail.com>> Sent: Thursday, May 20, 2021 10:14 AM To: users@cloudstack.apache.org<mailto:users@cloudstack.apache.org> Subject: Re: I Need Help ππΌ [X]This message came from outside your organization Another thing I forgot to mention is : On the dashboard, it shows 0.00GB of Secondary Storage I mounted a partition on the Host and used NFS to connect it with the management server : [root@srvr1 ~]# showmount -e 192.168.1.7 Export list for 192.168.1.7<https://urldefense.com/v3/__http:/192.168.1.7__;!!A6UyJA!0q19bVFm1wSBf0d9m2u4EiU0ugEkSxsNy6ecVs3JXSIhmsTYAZ3IpQrFxJf0SHRqggbVrSdyvvvt$>: /export/primary * /export/primary2 * /export/secondary * and then added it on the UI [Screen Shot 2021-05-20 at 09.05.30.png] On Thu, May 20, 2021 at 9:12 AM Serge Byishimo <sergebyish...@gmail.com<mailto:sergebyish...@gmail.com><mailto:sergebyish...@gmail.com<mailto:sergebyish...@gmail.com>>> wrote: This is the message I get when the Host 192.168.1.7 is trying to SSH in System VM Link Local IP [root@srvr2 ~]# ssh -i /root/.ssh/id_rsa.cloud 169.254.51.113 -p 3922 ssh: connect to host 169.254.51.113 port 3922: No route to host [root@srvr2 ~]# On the host 192.168.1.7, there is no /var/log/cloud There is only /var/log/cloudstack/agent/agent.log, let me show you its logs [root@srvr2 log]# ls /var/log anaconda btmp cron-20210509 dnf.log hawkey.log-20210502 maillog-20210502 messages-20210516 secure-20210516 swtpm audit btmp-20210501 cron-20210516 dnf.log.1 hawkey.log-20210509 maillog-20210509 private spooler tuned boot.log chrony dnf.librepo.log dnf.rpm.log hawkey.log-20210516 maillog-20210516 samba spooler-20210425 wtmp boot.log-20210411 cloudstack dnf.librepo.log-20210425 firewalld lastlog messages secure spooler-20210502 boot.log-20210413 cron dnf.librepo.log-20210502 glusterfs libvirt messages-20210425 secure-20210425 spooler-20210509 boot.log-20210414 cron-20210425 dnf.librepo.log-20210509 hawkey.log maillog messages-20210502 secure-20210502 spooler-20210516 boot.log-20210519 cron-20210502 dnf.librepo.log-20210516 hawkey.log-20210425 maillog-20210425 messages-20210509 secure-20210509 sssd /var/log/cloudstack/agent/agent.log 2021-05-20 03:03:06,046 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:54ec623b) Trying to fetch storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 from libvirt 2021-05-20 03:03:06,047 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:54ec623b) Asking libvirt to refresh storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 2021-05-20 03:03:10,696 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:17b8f397) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:03:40,713 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:17b8f397) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:04:06,158 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:2d39f098) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:04:06,171 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:2d39f098) Asking libvirt to refresh storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d 2021-05-20 03:04:06,225 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:2d39f098) Trying to fetch storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 from libvirt 2021-05-20 03:04:06,226 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:2d39f098) Asking libvirt to refresh storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 2021-05-20 03:04:10,729 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:17b8f397) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:04:40,749 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:0934a268) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:04:40,764 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:0934a268) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:04:43,916 INFO [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:17b8f397) No existing libvirtd connection found. Opening a new one 2021-05-20 03:04:43,917 WARN [kvm.resource.LibvirtConnection] (agentRequest-Handler-2:null) (logid:17b8f397) Can not find a connection for Instance s-551-VM. Assuming the default connection. 2021-05-20 03:04:44,003 WARN [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-2:null) (logid:17b8f397) Groovy script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.groovy' is not available. Transformations will not be applied. 2021-05-20 03:04:44,003 WARN [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-2:null) (logid:17b8f397) Groovy scripting engine is not initialized. Data transformation skipped. 2021-05-20 03:05:06,350 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:e938fa29) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:05:06,364 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:e938fa29) Asking libvirt to refresh storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d 2021-05-20 03:05:06,421 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:e938fa29) Trying to fetch storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 from libvirt 2021-05-20 03:05:06,423 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:e938fa29) Asking libvirt to refresh storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 2021-05-20 03:05:10,768 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:0934a268) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:05:40,785 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:0934a268) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:06:06,534 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:73bd25a9) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:06:06,549 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:73bd25a9) Asking libvirt to refresh storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d 2021-05-20 03:06:06,613 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:73bd25a9) Trying to fetch storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 from libvirt 2021-05-20 03:06:06,614 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:73bd25a9) Asking libvirt to refresh storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 2021-05-20 03:06:10,802 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:0934a268) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:06:40,818 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:0934a268) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:07:06,725 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) (logid:7d3174ae) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:07:06,738 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) (logid:7d3174ae) Asking libvirt to refresh storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d 2021-05-20 03:07:06,792 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:7d3174ae) Trying to fetch storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 from libvirt 2021-05-20 03:07:06,794 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) (logid:7d3174ae) Asking libvirt to refresh storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 2021-05-20 03:07:10,835 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:0934a268) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:07:40,851 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:0934a268) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:08:06,910 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:194fac89) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:08:06,925 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:194fac89) Asking libvirt to refresh storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d 2021-05-20 03:08:06,979 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) (logid:194fac89) Trying to fetch storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 from libvirt 2021-05-20 03:08:06,980 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) (logid:194fac89) Asking libvirt to refresh storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 2021-05-20 03:08:10,867 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:0934a268) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:08:40,883 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:0934a268) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:09:07,105 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:e74f962b) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:09:07,120 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) (logid:e74f962b) Asking libvirt to refresh storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d 2021-05-20 03:09:07,174 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:e74f962b) Trying to fetch storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 from libvirt 2021-05-20 03:09:07,176 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:e74f962b) Asking libvirt to refresh storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 2021-05-20 03:09:10,900 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:0934a268) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:09:40,921 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) (logid:17b8f397) Trying to fetch storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 from libvirt 2021-05-20 03:09:40,935 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) (logid:17b8f397) Trying to fetch storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 from libvirt 2021-05-20 03:09:44,076 INFO [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:0934a268) No existing libvirtd connection found. Opening a new one 2021-05-20 03:09:44,078 WARN [kvm.resource.LibvirtConnection] (agentRequest-Handler-5:null) (logid:0934a268) Can not find a connection for Instance v-550-VM. Assuming the default connection. 2021-05-20 03:09:44,161 WARN [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-5:null) (logid:0934a268) Groovy script '/etc/cloudstack/agent/hooks/libvirt-vm-state-change.groovy' is not available. Transformations will not be applied. 2021-05-20 03:09:44,161 WARN [kvm.resource.LibvirtKvmAgentHook] (agentRequest-Handler-5:null) (logid:0934a268) Groovy scripting engine is not initialized. Data transformation skipped. 2021-05-20 03:10:07,275 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:0e198ea0) Trying to fetch storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d from libvirt 2021-05-20 03:10:07,277 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) (logid:0e198ea0) Asking libvirt to refresh storage pool 26a9efbf-fb80-3f0d-a292-43bd0a3eec9d 2021-05-20 03:10:07,371 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:0e198ea0) Trying to fetch storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 from libvirt 2021-05-20 03:10:07,372 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) (logid:0e198ea0) Asking libvirt to refresh storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 2021-05-20 03:10:10,939 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) (logid:17b8f397) Trying to fetch storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 from libvirt 2021-05-20 03:10:40,955 INFO [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) (logid:17b8f397) Trying to fetch storage pool 39e1d532-590f-3d17-9b5a-10c1644e09f6 from libvirt Thank you Regards, On Thu, May 20, 2021 at 9:05 AM Yordan Kostov <yord...@nsogroup.com<mailto:yord...@nsogroup.com><mailto:yord...@nsogroup.com<mailto:yord...@nsogroup.com>>> wrote: System VMs SSH available only through the hypervisor. You can read more about it here -> http://docs.cloudstack.apache.org/en/latest/adminguide/systemvm.html#accessing-system-vms<https://urldefense.com/v3/__http:/docs.cloudstack.apache.org/en/latest/adminguide/systemvm.html*accessing-system-vms__;Iw!!A6UyJA!xdMOpDgufOBL1WXIgUcUxgTcbsdp8WmZnpUB-DBK4ReGRx8n17VhUmhYJTvKy6me5hqQCWJy88EM$><https://urldefense.com/v3/__http:/docs.cloudstack.apache.org/en/latest/adminguide/systemvm.html*accessing-system-vms__;Iw!!A6UyJA!0q19bVFm1wSBf0d9m2u4EiU0ugEkSxsNy6ecVs3JXSIhmsTYAZ3IpQrFxJf0SHRqggbVrbQdEv7i$> On the hypervisor host 192.168.1.7 what do you see in /var/log/cloud/cloud.log Any issues reported? Regards, Jordan From: Serge Byishimo <sergebyish...@gmail.com<mailto:sergebyish...@gmail.com><mailto:sergebyish...@gmail.com<mailto:sergebyish...@gmail.com>>> Sent: Thursday, May 20, 2021 9:55 AM To: users@cloudstack.apache.org<mailto:users@cloudstack.apache.org><mailto:users@cloudstack.apache.org<mailto:users@cloudstack.apache.org>> Subject: Re: I Need Help ππΌ [X]This message came from outside your organization Thank you Yordan, I have 6TB of primary storage available on the dashboard, But one of the problem I have is I canβt SSH through the SystemVMs to see that log, Iβm thinking It might a networking Issue, so let me show you my configuration : I have 2 computers : 1st management server, 2nd Host They are on a private network, they donβt have public IP addresses, so I was confused when cloudstack kept asking me about public IP addresses 1st computer : ifconfig : [root@srvr1 ~]# ifconfig eno1: flags=4163<UP,BROADCAST,RUNNING,MULTICAST> mtu 1500 inet 192.168.1.8 netmask 255.255.255.0 broadcast 192.168.1.255 inet6 fe80::7a31:44f5:6cbd:f97e prefixlen 64 scopeid 0x20<link> ether 68:1d:ef:24:d2:bb txqueuelen 1000 (Ethernet) RX packets 683346 bytes 450075162 (429.2 MiB) RX errors 0 dropped 31958 overruns 0 frame 0 TX packets 483540 bytes 464984616 (443.4 MiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 lo: flags=73<UP,LOOPBACK,RUNNING> mtu 65536 inet 127.0.0.1 netmask 255.0.0.0 inet6 ::1 prefixlen 128 scopeid 0x10<host> loop txqueuelen 1000 (Local Loopback) RX packets 11164675 bytes 2804166400 (2.6 GiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 11164675 bytes 2804166400 (2.6 GiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 [root@srvr1 ~]# [root@srvr1 ~]# cat /etc/sysconfig/network-scripts/ifcfg-cloudbr0 DEVICE=cloudbr0 TYPE=Bridge ONBOOT=yes BOOTPROTO=static IPV6INIT=no IPV6_AUTOCONF=no DELAY=5 IPADDR=192.168.1.8 GATEWAY=192.168.1.1 NETMASK=255.255.255.0 DNS1=8.8.8.8 DNS2=8.8.4.4 STP=yes USERCTL=no NM_CONTROLLED=no [root@srvr1 ~]# [root@srvr1 ~]# cat /etc/sysconfig/network-scripts/ifcfg-eno1 TYPE=Ethernet BOOTPRO=static NAME=eno1 UUID=7dad60c5-e259-4fb9-9f5a-aac0ec29435f DEVICE=eno1 ONBOOT=yes IPADDR-192.168.1.8 PREFIX=24 GATEWAY=192.168.1.1 USRCTL=no BRIDGE=cloudbr0 [root@srvr1 ~]# 2nd computer : The 2nd computer has 2 NICs : [root@srvr2 ~]# ifconfig cloud0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST> mtu 1500 inet 169.254.0.1 netmask 255.255.0.0 broadcast 0.0.0.0 inet6 fe80::f89d:edff:fe9c:e90b prefixlen 64 scopeid 0x20<link> ether fa:9d:ed:9c:e9:0b txqueuelen 1000 (Ethernet) RX packets 0 bytes 0 (0.0 B) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 1401 bytes 59862 (58.4 KiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 cloudbr0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST> mtu 1500 inet 192.168.1.7 netmask 255.255.255.0 broadcast 192.168.1.255 inet6 fe80::8040:8dff:fe57:4eb8 prefixlen 64 scopeid 0x20<link> ether d0:50:99:81:89:f5 txqueuelen 1000 (Ethernet) RX packets 220463 bytes 19759124 (18.8 MiB) RX errors 0 dropped 22054 overruns 0 frame 0 TX packets 620 bytes 55228 (53.9 KiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 cloudbr1: flags=4099<UP,BROADCAST,MULTICAST> mtu 1500 ether 32:7c:82:bc:0f:ce txqueuelen 1000 (Ethernet) RX packets 0 bytes 0 (0.0 B) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 0 bytes 0 (0.0 B) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 enp0s25: flags=4163<UP,BROADCAST,RUNNING,MULTICAST> mtu 1500 ether d0:50:99:81:89:f5 txqueuelen 1000 (Ethernet) RX packets 250164 bytes 33642066 (32.0 MiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 37371 bytes 2409704 (2.2 MiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 device interrupt 20 memory 0xfb200000-fb220000 enp3s0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST> mtu 1500 inet 192.168.1.60 netmask 255.255.255.0 broadcast 192.168.1.255 inet6 fe80::6a1a:9d26:8975:480c prefixlen 64 scopeid 0x20<link> ether 68:05:ca:c6:6e:9d txqueuelen 1000 (Ethernet) RX packets 618625 bytes 444641389 (424.0 MiB) RX errors 0 dropped 22070 overruns 0 frame 0 TX packets 178295 bytes 28986719 (27.6 MiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 device interrupt 18 memory 0xfb1c0000-fb1e0000 lo: flags=73<UP,LOOPBACK,RUNNING> mtu 65536 inet 127.0.0.1 netmask 255.0.0.0 inet6 ::1 prefixlen 128 scopeid 0x10<host> loop txqueuelen 1000 (Local Loopback) RX packets 88970 bytes 20756782 (19.7 MiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 88970 bytes 20756782 (19.7 MiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 [root@srvr2 ~]# [root@srvr2 ~]# cat /etc/sysconfig/network-scripts/ifcfg-cloudbr0 DEVICE=cloudbr0 TYPE=Bridge ONBOOT=yes BOOTPROTO=none IPV6INIT=no DELAY=5 IPADDR=192.168.1.7 GATEWAY=192.168.1.1 NETMASK=255.255.255.0 STP=yes BRIDGING_OPTS=priority=32768 PROXY_METHOD=none BROWSER_ONLY=no PREFIX=24 DEFROUTE=yes IPV4_FAILURE_FATAL=no NAME="Bridge cloudbr0" UUID=d4b789ba-7321-548d-dabd-5c4150da0266 [root@srvr2 ~]# [root@srvr2 ~]# [root@srvr2 ~]# cat /etc/sysconfig/network-scripts/ifcfg-cloudbr1 DEVICE=cloudbr1 TYPE=Bridge ONBOOT=yes BOOTPROTO=none IPV6INIT=no IPV6_AUTOCONF=no DELAY=5 STP=yes [root@srvr2 ~]# [root@srvr2 ~]# cat /etc/sysconfig/network-scripts/ifcfg-enp0s25 TYPE=Ethernet NAME=enp0s25 UUID=93380612-3b97-4a34-ab9f-042b751cc468 DEVICE=enp0s25 ONBOOT=yes BRIDGE=cloudbr0 # cat /etc/sysconfig/network-scripts/enp0s25.200 DEVICE=enp0s25.200 ONBOOT=yes HOTPLUG=no BOOTPROTO=none TYPE=Ethernet VLAN=yes BRIDGE=cloudbr1 [Screen Shot 2021-05-20 at 08.52.21.png] [Screen Shot 2021-05-20 at 08.52.47.png] [Screen Shot 2021-05-20 at 08.53.12.png] [Screen Shot 2021-05-20 at 08.53.18.png] I need help figuring out what I did wrong! On Thu, May 20, 2021 at 8:30 AM Yordan Kostov <yord...@nsogroup.com<mailto:yord...@nsogroup.com><mailto:yord...@nsogroup.com<mailto:yord...@nsogroup.com>><mailto:yord...@nsogroup.com<mailto:yord...@nsogroup.com><mailto:yord...@nsogroup.com<mailto:yord...@nsogroup.com>>>> wrote: Hello Serge, Check these snippets from your logs. Line 61: com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-454-VM]Scope=interface Line 66: com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-454-VM]Scope=interface Line 72: (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115) (logid:a9f8cbaf) Unable to complete AsyncJobVO {id:1115, userId: 1, accountId: 1, Line 80: com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-454-VM]Scope=interface Line 134: com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-454-VM]Scope=interface Line 175: (secstorage-1:ctx-694f5c71) (logid:a34366a8) Unable to start secondary storage vm for standby capacity, vm id : 454, will recycle it and start a new one It seems the system cannot create the secondary VM thus the zone/pods/clusters are not functional. Check the hypervisor logs at "/var/log/cloud/cloud.log and let us know what you see there. Usually the cause of this issue is that primary storage cannot utilized (either not mounted or something else) on the hypervisor for usage. Best regards, Jordan -----Original Message----- From: Serge Byishimo <sergebyish...@gmail.com<mailto:sergebyish...@gmail.com><mailto:sergebyish...@gmail.com<mailto:sergebyish...@gmail.com>><mailto:sergebyish...@gmail.com<mailto:sergebyish...@gmail.com><mailto:sergebyish...@gmail.com<mailto:sergebyish...@gmail.com>>>> Sent: Wednesday, May 19, 2021 6:49 PM To: users@cloudstack.apache.org<mailto:users@cloudstack.apache.org><mailto:users@cloudstack.apache.org<mailto:users@cloudstack.apache.org>><mailto:users@cloudstack.apache.org<mailto:users@cloudstack.apache.org><mailto:users@cloudstack.apache.org<mailto:users@cloudstack.apache.org>>> Subject: I Need Help ππΌ [X] This message came from outside your organization Cloudstack: 4.15 OS: Centos 8 Two computers: one for the Management Server and the other for the Host Primary and Secondary storage is on the host and connected to the management through NFS, 2021-05-19 11:20:39,924 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8 FirstFitRoutingAllocator) (logid:a9f8cbaf) Found 1 hosts for allocation after prioritization: [Host[-1-Routing]] 2021-05-19 11:20:39,924 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8 FirstFitRoutingAllocator) (logid:a9f8cbaf) Looking for speed=500Mhz, Ram=512 MB 2021-05-19 11:20:39,924 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8 FirstFitRoutingAllocator) (logid:a9f8cbaf) Host name: srvr2.cloud.priv, hostId: 1 is in avoid set, skipping this and trying other available hosts 2021-05-19 11:20:39,924 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8 FirstFitRoutingAllocator) (logid:a9f8cbaf) Host Allocator returning 0 suitable hosts 2021-05-19 11:20:39,924 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) No suitable hosts found 2021-05-19 11:20:39,924 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) No suitable hosts found under this Cluster: 1 2021-05-19 11:20:39,927 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) Could not find suitable Deployment Destination for this VM under any clusters, returning. 2021-05-19 11:20:39,930 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) Searching resources only under specified Pod: 1 2021-05-19 11:20:39,934 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) Listing clusters in order of aggregate capacity, that have (at least one host with) enough CPU and RAM capacity under this Pod: 1 2021-05-19 11:20:39,942 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) Removing from the clusterId list these clusters from avoid set: [1] 2021-05-19 11:20:39,947 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) No clusters found after removing disabled clusters and clusters in avoid list, returning. 2021-05-19 11:20:39,974 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id: null host id before state transition: 1 2021-05-19 11:20:39,997 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) Hosts's actual total CPU: 43200 and CPU after applying overprovisioning: 43200 2021-05-19 11:20:39,997 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) Hosts's actual total RAM: (61.57 GB) 66114236416 and RAM after applying overprovisioning: (61.57 GB) 66114236416 2021-05-19 11:20:39,997 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) release cpu from host: 1, old used: 1000,reserved: 0, actual total: 43200, total with overprovisioning: 43200; new used: 500,reserved:0; movedfromreserved: false,moveToReserveredfalse 2021-05-19 11:20:39,998 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) release mem from host: 1, old used: (1.50 GB) 1610612736,reserved: (0 bytes) 0, total: (61.57 GB) 66114236416; new used: (1.00 GB) 1073741824,reserved:(0 bytes) 0; movedfromreserved: false,moveToReserveredfalse 2021-05-19 11:20:40,011 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) Invocation exception, caused by: com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-454-VM]Scope=interface com.cloud.dc.DataCenter; id=1 2021-05-19 11:20:40,012 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115 ctx-9c8114c8) (logid:a9f8cbaf) Rethrow exception com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-454-VM]Scope=interface com.cloud.dc.DataCenter; id=1 2021-05-19 11:20:40,012 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115) (logid:a9f8cbaf) Done with run of VM work job: com.cloud.vm.VmWorkStart for VM 454, job origin: 1107 2021-05-19 11:20:40,012 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115) (logid:a9f8cbaf) Unable to complete AsyncJobVO {id:1115, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAABxnQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 114477775508155, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed May 19 11:10:39 EDT 2021, removed: null}, job origin:1107 com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-454-VM]Scope=interface com.cloud.dc.DataCenter; id=1 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1110) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5464) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5631) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:620) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52) at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829) 2021-05-19 11:20:40,028 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115) (logid:a9f8cbaf) Publish async job-1115 complete on message bus 2021-05-19 11:20:40,029 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115) (logid:a9f8cbaf) Wake up jobs related to job-1115 2021-05-19 11:20:40,029 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115) (logid:a9f8cbaf) Update db status for job-1115 2021-05-19 11:20:40,032 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115) (logid:a9f8cbaf) Wake up jobs joined with job-1115 and disjoin all subjobs created from job- 1115 2021-05-19 11:20:40,052 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115) (logid:a9f8cbaf) Done executing com.cloud.vm.VmWorkStart for job-1115 2021-05-19 11:20:40,061 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-8:ctx-e9ad7a77 job-1107/job-1115) (logid:a9f8cbaf) Remove job-1115 from job monitoring 2021-05-19 11:20:40,076 WARN [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Exception while trying to start secondary storage vm com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[SecondaryStorageVm|s-454-VM]Scope=interface com.cloud.dc.DataCenter; id=1 at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1110) at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5464) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107) at com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5631) at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:620) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:48) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:102) at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52) at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:45) at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:568) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829) 2021-05-19 11:20:40,078 INFO [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Unable to start secondary storage vm for standby capacity, vm id : 454, will recycle it and start a new one 2021-05-19 11:20:40,107 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Sync job-1118 execution on object VmWorkJobQueue.454 2021-05-19 11:20:40,831 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-e4f9bd44) (logid:7bc61078) Execute sync-queue item: SyncQueueItemVO {id:1061, queueId: 1056, contentType: AsyncJob, contentId: 1118, lastProcessMsid: 114477775508155, lastprocessNumber: 3, lastProcessTime: Wed May 19 11:20:40 EDT 2021, created: Wed May 19 11:20:40 EDT 2021} 2021-05-19 11:20:40,833 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-e4f9bd44) (logid:7bc61078) Schedule queued job-1118 2021-05-19 11:20:40,848 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118) (logid:e7375fc2) Add job-1118 into job monitoring 2021-05-19 11:20:40,859 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118) (logid:a9f8cbaf) Executing AsyncJobVO {id:1118, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStop, cmdInfo: rO0ABXNyABdjb20uY2xvdWQudm0uVm1Xb3JrU3RvcALQ4GymiWjjAgABWgAHY2xlYW51cHhyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAABxnQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 114477775508155, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed May 19 11:20:40 EDT 2021, removed: null} 2021-05-19 11:20:40,860 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118) (logid:a9f8cbaf) Run VM work job: com.cloud.vm.VmWorkStop for VM 454, job origin: 1107 2021-05-19 11:20:40,865 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118 ctx-53c5dc81) (logid:a9f8cbaf) Execute VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":1,"accountId":1,"vmId":454,"handlerName":"VirtualMachineManagerImpl"} 2021-05-19 11:20:40,872 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118 ctx-53c5dc81) (logid:a9f8cbaf) VM is already stopped: VM[SecondaryStorageVm|s-454-VM] 2021-05-19 11:20:40,872 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118 ctx-53c5dc81) (logid:a9f8cbaf) Done executing VM work job: com.cloud.vm.VmWorkStop{"cleanup":false,"userId":1,"accountId":1,"vmId":454,"handlerName":"VirtualMachineManagerImpl"} 2021-05-19 11:20:40,875 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118 ctx-53c5dc81) (logid:a9f8cbaf) Complete async job-1118, jobStatus: SUCCEEDED, resultCode: 0, result: null 2021-05-19 11:20:40,877 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118 ctx-53c5dc81) (logid:a9f8cbaf) Publish async job-1118 complete on message bus 2021-05-19 11:20:40,877 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118 ctx-53c5dc81) (logid:a9f8cbaf) Wake up jobs related to job-1118 2021-05-19 11:20:40,877 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118 ctx-53c5dc81) (logid:a9f8cbaf) Update db status for job-1118 2021-05-19 11:20:40,880 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118 ctx-53c5dc81) (logid:a9f8cbaf) Wake up jobs joined with job-1118 and disjoin all subjobs created from job- 1118 2021-05-19 11:20:40,902 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118) (logid:a9f8cbaf) Done with run of VM work job: com.cloud.vm.VmWorkStop for VM 454, job origin: 1107 2021-05-19 11:20:40,902 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118) (logid:a9f8cbaf) Done executing com.cloud.vm.VmWorkStop for job-1118 2021-05-19 11:20:40,907 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-11:ctx-fad73038 job-1107/job-1118) (logid:a9f8cbaf) Remove job-1118 from job monitoring 2021-05-19 11:20:40,942 DEBUG [c.c.c.CapacityManagerImpl] (secstorage-1:ctx-694f5c71) (logid:a34366a8) VM state transitted from :Stopped to Expunging with event: ExpungeOperationvm's original host id: null new host id: null host id before state transition: null 2021-05-19 11:20:40,953 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Destroying vm VM[SecondaryStorageVm|s-454-VM] 2021-05-19 11:20:40,953 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Cleaning up NICS 2021-05-19 11:20:40,953 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Cleaning network for vm: 454 2021-05-19 11:20:40,977 DEBUG [c.c.n.g.PublicNetworkGuru] (secstorage-1:ctx-694f5c71) (logid:a34366a8) public network deallocate network: networkId: 200, ip: 209.150.129.37 2021-05-19 11:20:40,996 DEBUG [c.c.n.g.PublicNetworkGuru] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Deallocated nic: NicProfile[442-454-null-null-null] 2021-05-19 11:20:41,004 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Removed nic id=442 2021-05-19 11:20:41,007 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Revoving nic secondary ip entry ... 2021-05-19 11:20:41,031 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Removed nic id=443 2021-05-19 11:20:41,033 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Revoving nic secondary ip entry ... 2021-05-19 11:20:41,061 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Removed nic id=444 2021-05-19 11:20:41,063 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Revoving nic secondary ip entry ... 2021-05-19 11:20:41,065 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage 2021-05-19 11:20:41,067 DEBUG [o.a.c.e.o.VolumeOrchestrator] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Cleaning storage for vm: 454 2021-05-19 11:20:41,125 DEBUG [o.a.c.s.v.VolumeServiceImpl] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Marking volume that was never created as destroyed: Vol[148|vm=454|ROOT] 2021-05-19 11:20:41,151 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Expunged VM[SecondaryStorageVm|s-454-VM] 2021-05-19 11:20:41,164 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-694f5c71) (logid:a34366a8) received secondary storage vm alert 2021-05-19 11:20:41,167 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Secondary Storage Vm creation failure, zone: Zone1 2021-05-19 11:20:41,169 WARN [c.c.a.AlertManagerImpl] (secstorage-1:ctx-694f5c71) (logid:a34366a8) AlertType:: 19 | dataCenterId:: 1 | podId:: null | clusterId:: null | message:: Secondary Storage Vm creation failure. zone: Zone1, error details: null 2021-05-19 11:20:41,184 INFO [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-694f5c71) (logid:a34366a8) Primary secondary storage is not even started, wait until next turn 2021-05-19 11:20:41,223 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Zone 1 is ready to launch secondary storage VM 2021-05-19 11:20:41,231 INFO [o.a.c.s.PremiumSecondaryStorageManagerImpl] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) No running secondary storage vms found in datacenter id=1, starting one 2021-05-19 11:20:41,240 INFO [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) No stopped secondary storage vm is available, need to allocate a new secondary storage vm 2021-05-19 11:20:41,246 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Assign secondary storage vm from a newly started instance for request from data center : 1 2021-05-19 11:20:41,282 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Found existing network configuration for offering [Network Offering [1-Public-System-Public-Network]: Ntwk[200|Public|1] 2021-05-19 11:20:41,282 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Releasing lock for Acct[5c42e60b-b7b3-11eb-b5c5-681def24d2bb-system] 2021-05-19 11:20:41,306 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Found existing network configuration for offering [Network Offering [3-Control-System-Control-Network]: Ntwk[202|Control|3] 2021-05-19 11:20:41,306 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Releasing lock for Acct[5c42e60b-b7b3-11eb-b5c5-681def24d2bb-system] 2021-05-19 11:20:41,328 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Found existing network configuration for offering [Network Offering [2-Management-System-Management-Network]: Ntwk[201|Management|2] 2021-05-19 11:20:41,329 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Releasing lock for Acct[5c42e60b-b7b3-11eb-b5c5-681def24d2bb-system] 2021-05-19 11:20:41,368 INFO [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) allocating virtual machine from template:7ed2a89e-9cac-492c-b252-3bffd238c898 with hostname:s-456-VM and 3 networks 2021-05-19 11:20:41,374 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Allocating entries for VM: VM[SecondaryStorageVm|s-456-VM] 2021-05-19 11:20:41,378 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Allocating nics for VM[SecondaryStorageVm|s-456-VM] 2021-05-19 11:20:41,382 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Allocating nic for vm VM[SecondaryStorageVm|s-456-VM] in network Ntwk[200|Public|1] with requested profile NicProfile[0-0-null-null-null] 2021-05-19 11:20:41,443 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Allocating nic for vm VM[SecondaryStorageVm|s-456-VM] in network Ntwk[202|Control|3] with requested profile null 2021-05-19 11:20:41,459 DEBUG [o.a.c.e.o.NetworkOrchestrator] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Allocating nic for vm VM[SecondaryStorageVm|s-456-VM] in network Ntwk[201|Management|2] with requested profile null 2021-05-19 11:20:41,479 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Allocating disks for VM[SecondaryStorageVm|s-456-VM] 2021-05-19 11:20:41,479 INFO [o.a.c.e.o.VolumeOrchestrator] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) adding disk object ROOT-456 to s-456-VM 2021-05-19 11:20:41,498 DEBUG [c.c.v.VirtualMachineManagerImpl] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Allocation completed for VM: VM[SecondaryStorageVm|s-456-VM] 2021-05-19 11:20:41,504 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) received secondary storage vm alert 2021-05-19 11:20:41,507 DEBUG [c.c.a.SecondaryStorageVmAlertAdapter] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) New secondary storage vm created, zone: Zone1, secStorageVm: s-456-VM, public IP: null, private IP: null 2021-05-19 11:20:41,536 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (secstorage-1:ctx-03019fb4) (logid:d8dc459d) Sync job-1119 execution on object VmWorkJobQueue.456 2021-05-19 11:20:42,297 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-8e6bdaef) (logid:6494d66f) StorageCollector is running... 2021-05-19 11:20:42,311 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-8e6bdaef) (logid:6494d66f) There is no secondary storage VM for secondary storage host Secondary1 2021-05-19 11:20:42,317 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (StatsCollector-2:ctx-8e6bdaef) (logid:6494d66f) getCommandHostDelegation: class com.cloud.agent.api.GetStorageStatsCommand 2021-05-19 11:20:42,317 DEBUG [c.c.h.XenServerGuru] (StatsCollector-2:ctx-8e6bdaef) (logid:6494d66f) We are returning the default host to execute commands because the command is not of Copy type. 2021-05-19 11:20:42,383 DEBUG [c.c.a.t.Request] (StatsCollector-2:ctx-8e6bdaef) (logid:6494d66f) Seq 1-4873457746768298101: Received: { Ans: , MgmtId: 114477775508155, via: 1(srvr2.cloud.priv), Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2021-05-19 11:20:42,388 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (StatsCollector-2:ctx-8e6bdaef) (logid:6494d66f) getCommandHostDelegation: class com.cloud.agent.api.GetStorageStatsCommand 2021-05-19 11:20:42,388 DEBUG [c.c.h.XenServerGuru] (StatsCollector-2:ctx-8e6bdaef) (logid:6494d66f) We are returning the default host to execute commands because the command is not of Copy type. 2021-05-19 11:20:42,482 DEBUG [c.c.a.t.Request] (StatsCollector-2:ctx-8e6bdaef) (logid:6494d66f) Seq 1-4873457746768298102: Received: { Ans: , MgmtId: 114477775508155, via: 1(srvr2.cloud.priv), Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2021-05-19 11:20:42,836 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-d8a66dc4) (logid:f85fb5ce) Execute sync-queue item: SyncQueueItemVO {id:1062, queueId: 1062, contentType: AsyncJob, contentId: 1119, lastProcessMsid: 114477775508155, lastprocessNumber: 1, lastProcessTime: Wed May 19 11:20:42 EDT 2021, created: Wed May 19 11:20:41 EDT 2021} 2021-05-19 11:20:42,840 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-d8a66dc4) (logid:f85fb5ce) Schedule queued job-1119 2021-05-19 11:20:42,857 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119) (logid:432ff131) Add job-1119 into job monitoring 2021-05-19 11:20:42,869 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119) (logid:a9f8cbaf) Executing AsyncJobVO {id:1119, userId: 1, accountId: 1, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkStart, cmdInfo: rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAABAAAAAAAAAAEAAAAAAAAByHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwcHA, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 114477775508155, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed May 19 11:20:41 EDT 2021, removed: null} 2021-05-19 11:20:42,870 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119) (logid:a9f8cbaf) Run VM work job: com.cloud.vm.VmWorkStart for VM 456, job origin: 1107 2021-05-19 11:20:42,877 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Execute VM work job: com.cloud.vm.VmWorkStart{"dcId":0,"userId":1,"accountId":1,"vmId":456,"handlerName":"VirtualMachineManagerImpl"} 2021-05-19 11:20:42,904 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) VM state transitted from :Stopped to Starting with event: StartRequestedvm's original host id: null new host id: null host id before state transition: null 2021-05-19 11:20:42,904 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Successfully transitioned to start state for VM[SecondaryStorageVm|s-456-VM] reservation id = cd31b3d1-30e6-49a2-b27c-3e2983fda982 2021-05-19 11:20:42,921 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Deploy avoids pods: null, clusters: null, hosts: null 2021-05-19 11:20:42,932 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) DeploymentPlanner allocation algorithm: null 2021-05-19 11:20:42,932 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Trying to allocate a host and storage pools from dc:1, pod:null,cluster:null, requested cpu: 500, requested ram: (512.00 MB) 536870912 2021-05-19 11:20:42,932 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Is ROOT volume READY (pool already allocated)?: No 2021-05-19 11:20:42,935 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Deploy avoids pods: null, clusters: null, hosts: null 2021-05-19 11:20:42,942 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Searching all possible resources under this Zone: 1 2021-05-19 11:20:42,950 DEBUG [c.c.d.FirstFitPlanner] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Listing clusters in order of aggregate capacity, that have (at least one host with) enough CPU and RAM capacity under this Zone: 1 2021-05-19 11:20:42,988 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Checking resources in Cluster: 1 under Pod: 1 2021-05-19 11:20:42,995 INFO [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) Guest VM is requested with Cusotm[UEFI] Boot Type false 2021-05-19 11:20:42,995 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) Looking for hosts in dc: 1 pod:1 cluster:1 2021-05-19 11:20:43,004 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]] 2021-05-19 11:20:43,023 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) Found 1 hosts for allocation after prioritization: [Host[-1-Routing]] 2021-05-19 11:20:43,023 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) Looking for speed=500Mhz, Ram=512 MB 2021-05-19 11:20:43,049 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) Host: 1 has cpu capability (cpu:12, speed:3600) to support requested CPU: 1 and requested speed: 500 2021-05-19 11:20:43,050 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) Checking if host: 1 has enough capacity for requested CPU: 500 and requested RAM: (512.00 MB) 536870912 , cpuOverprovisioningFactor: 1.0 2021-05-19 11:20:43,058 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) Hosts's actual total CPU: 43200 and CPU after applying overprovisioning: 43200 2021-05-19 11:20:43,058 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) Free CPU: 42700 , Requested CPU: 500 2021-05-19 11:20:43,058 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) Free RAM: (60.57 GB) 65040494592 , Requested RAM: (512.00 MB) 536870912 2021-05-19 11:20:43,058 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) Host has enough CPU and RAM available 2021-05-19 11:20:43,058 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) STATS: Can alloc CPU from host: 1, used: 500, reserved: 0, actual total: 43200, total with overprovisioning: 43200; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true 2021-05-19 11:20:43,059 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) STATS: Can alloc MEM from host: 1, used: (1.00 GB) 1073741824, reserved: (0 bytes) 0, total: (61.57 GB) 66114236416; requested mem: (512.00 MB) 536870912, alloc_from_last_host?: false , considerReservedCapacity?: true 2021-05-19 11:20:43,059 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) Found a suitable host, adding to list: 1 2021-05-19 11:20:43,059 DEBUG [c.c.a.m.a.i.FirstFitAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d FirstFitRoutingAllocator) (logid:a9f8cbaf) Host Allocator returning 1 suitable hosts 2021-05-19 11:20:43,065 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Checking suitable pools for volume (Id, Type): (150,ROOT) 2021-05-19 11:20:43,065 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) We need to allocate new storagepool for this volume 2021-05-19 11:20:43,067 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Calling StoragePoolAllocators to find suitable pools 2021-05-19 11:20:43,074 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) System VMs will use shared storage for zone id=1 2021-05-19 11:20:43,075 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) LocalStoragePoolAllocator trying to find storage pool to fit the vm 2021-05-19 11:20:43,075 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) ClusterScopeStoragePoolAllocator looking for storage pool 2021-05-19 11:20:43,075 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Looking for pools in dc: 1 pod:1 cluster:1. Disabled pools will be ignored. 2021-05-19 11:20:43,077 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Found pools matching tags: [Pool[3|NetworkFilesystem], Pool[5|NetworkFilesystem]] 2021-05-19 11:20:43,081 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Checking if storage pool is suitable, name: null ,poolId: 3 2021-05-19 11:20:43,085 INFO [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Storage pool null (3) does not supply IOPS capacity, assuming enough capacity 2021-05-19 11:20:43,088 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Checking pool 3 for storage, totalSize: 75125227520, usedBytes: 5206179840, usedPct: 0.06930002093656222, disable threshold: 0.85 2021-05-19 11:20:43,088 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Destination pool id: 3 2021-05-19 11:20:43,127 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Pool ID for the volume with ID 150 is null 2021-05-19 11:20:43,142 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Found storage pool Primary1 of type NetworkFilesystem with over-provisioning factor 2 2021-05-19 11:20:43,142 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Total over-provisioned capacity calculated is 2 * (69.97 GB) 75125227520 2021-05-19 11:20:43,142 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Total capacity of the pool Primary1 with ID 3 is (139.93 GB) 150250455040 2021-05-19 11:20:43,145 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Checking pool: 3 for storage allocation , maxSize : (139.93 GB) 150250455040, totalAllocatedSize : (192.04 KB) 196648, askingSize : (0 bytes) 0, allocated disable threshold: 0.85 2021-05-19 11:20:43,147 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Checking if storage pool is suitable, name: null ,poolId: 5 2021-05-19 11:20:43,152 INFO [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Storage pool null (5) does not supply IOPS capacity, assuming enough capacity 2021-05-19 11:20:43,156 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Checking pool 5 for storage, totalSize: 1278522425344, usedBytes: 79691776, usedPct: 6.233115228976768E-5, disable threshold: 0.85 2021-05-19 11:20:43,156 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Destination pool id: 5 2021-05-19 11:20:43,194 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Pool ID for the volume with ID 150 is null 2021-05-19 11:20:43,209 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Found storage pool Primary2 of type NetworkFilesystem with over-provisioning factor 2 2021-05-19 11:20:43,209 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Total over-provisioned capacity calculated is 2 * (1.1628 TB) 1278522425344 2021-05-19 11:20:43,209 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Total capacity of the pool Primary2 with ID 5 is (2.3256 TB) 2557044850688 2021-05-19 11:20:43,212 DEBUG [c.c.s.StorageManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Checking pool: 5 for storage allocation , maxSize : (2.3256 TB) 2557044850688, totalAllocatedSize : (192.04 KB) 196648, askingSize : (0 bytes) 0, allocated disable threshold: 0.85 2021-05-19 11:20:43,212 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) ClusterScopeStoragePoolAllocator returning 2 suitable storage pools 2021-05-19 11:20:43,213 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM 2021-05-19 11:20:43,214 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Checking if host: 1 can access any suitable storage pool for volume: ROOT 2021-05-19 11:20:43,217 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Host: 1 can access pool: 3 2021-05-19 11:20:43,219 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Found a potential host id: 1 name: srvr2.cloud.priv and associated storage pools for this VM 2021-05-19 11:20:43,222 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(150|ROOT-->Pool(3))] 2021-05-19 11:20:43,222 DEBUG [c.c.v.VirtualMachineManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Deployment found - P0=VM[SecondaryStorageVm|s-456-VM], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(150|ROOT-->Pool(3))] 2021-05-19 11:20:43,248 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 1 host id before state transition: null 2021-05-19 11:20:43,273 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Hosts's actual total CPU: 43200 and CPU after applying overprovisioning: 43200 2021-05-19 11:20:43,273 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) We are allocating VM, increasing the used capacity of this host:1 2021-05-19 11:20:43,273 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Current Used CPU: 500 , Free CPU:42700 ,Requested CPU: 500 2021-05-19 11:20:43,273 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Current Used RAM: (1.00 GB) 1073741824 , Free RAM:(60.57 GB) 65040494592 ,Requested RAM: (512.00 MB) 536870912 2021-05-19 11:20:43,273 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) CPU STATS after allocation: for host: 1, old used: 500, old reserved: 0, actual total: 43200, total with overprovisioning: 43200; new used:1000, reserved:0; requested cpu:500,alloc_from_last:false 2021-05-19 11:20:43,274 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) RAM STATS after allocation: for host: 1, old used: (1.00 GB) 1073741824, old reserved: (0 bytes) 0, total: (61.57 GB) 66114236416; new used: (1.50 GB) 1610612736, reserved: (0 bytes) 0; requested mem: (512.00 MB) 536870912,alloc_from_last:false 2021-05-19 11:20:43,279 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Host: 1 has cpu capability (cpu:12, speed:3600) to support requested CPU: 1 and requested speed: 500 2021-05-19 11:20:43,279 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Checking if host: 1 has enough capacity for requested CPU: 500 and requested RAM: (512.00 MB) 536870912 , cpuOverprovisioningFactor: 1.0 2021-05-19 11:20:43,283 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Hosts's actual total CPU: 43200 and CPU after applying overprovisioning: 43200 2021-05-19 11:20:43,283 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) We need to allocate to the last host again, so checking if there is enough reserved capacity 2021-05-19 11:20:43,283 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Reserved CPU: 0 , Requested CPU: 500 2021-05-19 11:20:43,284 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Reserved RAM: (0 bytes) 0 , Requested RAM: (512.00 MB) 536870912 2021-05-19 11:20:43,284 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) STATS: Failed to alloc resource from host: 1 reservedCpu: 0, requested cpu: 500, reservedMem: (0 bytes) 0, requested mem: (512.00 MB) 536870912 2021-05-19 11:20:43,284 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Host does not have enough reserved CPU available, cannot allocate to this host. 2021-05-19 11:20:43,284 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Checking if host: 1 has enough capacity for requested CPU: 500 and requested RAM: (512.00 MB) 536870912 , cpuOverprovisioningFactor: 1.0 2021-05-19 11:20:43,288 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Hosts's actual total CPU: 43200 and CPU after applying overprovisioning: 43200 2021-05-19 11:20:43,288 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Free CPU: 42700 , Requested CPU: 500 2021-05-19 11:20:43,288 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Free RAM: (60.57 GB) 65040494592 , Requested RAM: (512.00 MB) 536870912 2021-05-19 11:20:43,288 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Host has enough CPU and RAM available 2021-05-19 11:20:43,288 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) STATS: Can alloc CPU from host: 1, used: 500, reserved: 0, actual total: 43200, total with overprovisioning: 43200; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true 2021-05-19 11:20:43,288 DEBUG [c.c.c.CapacityManagerImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) STATS: Can alloc MEM from host: 1, used: (1.00 GB) 1073741824, reserved: (0 bytes) 0, total: (61.57 GB) 66114236416; requested mem: (512.00 MB) 536870912, alloc_from_last_host?: false , considerReservedCapacity?: true 2021-05-19 11:20:43,314 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Network id=200 is already implemented 2021-05-19 11:20:43,361 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Network id=202 is already implemented 2021-05-19 11:20:43,876 DEBUG [c.c.n.g.ControlNetworkGuru] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Reserved NIC for s-456-VM [ipv4:169.254.24.222 netmask:255.255.0.0 gateway:169.254.0.1] 2021-05-19 11:20:43,900 DEBUG [o.a.c.e.o.NetworkOrchestrator] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Network id=201 is already implemented 2021-05-19 11:20:43,929 DEBUG [c.c.d.d.DataCenterIpAddressDaoImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Releasing ip address for instance=450 2021-05-19 11:20:43,946 DEBUG [c.c.n.g.PodBasedNetworkGuru] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) Allocated a nic NicProfile[450-456-cd31b3d1-30e6-49a2-b27c-3e2983fda982-192.168.1.110-null] for VM[SecondaryStorageVm|s-456-VM] 2021-05-19 11:20:44,005 DEBUG [o.a.c.s.i.TemplateDataFactoryImpl] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) template 3 is already in store:3, type:Image 2021-05-19 11:20:44,093 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type VOLUME 2021-05-19 11:20:44,188 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] (Work-Job-Executor-12:ctx-4ea8304f job-1107/job-1119 ctx-9a34e22d) (logid:a9f8cbaf) getCommandHostDelegation: class org.apache.cloudstack.storage.command.CopyCommand -- Byishimo Shema Serge Kigali, Rwanda Tel: +250 786 076 106 www.serge.works<https://urldefense.com/v3/__http:/www.serge.works__;!!A6UyJA!1fIpYgsV56uJuSScO5lKRMmbQoBUqNIhFAFn2Wv56QmGWGyiD2Ox2kmqZIl_d1MtJjNNpvr8ImTg$> -- Byishimo Shema Serge Kigali, Rwanda Tel: +250 786 076 106 www.serge.works<https://urldefense.com/v3/__http:/www.serge.works__;!!A6UyJA!0q19bVFm1wSBf0d9m2u4EiU0ugEkSxsNy6ecVs3JXSIhmsTYAZ3IpQrFxJf0SHRqggbVrc7Ghn1M$> -- Byishimo Shema Serge Kigali, Rwanda Tel: +250 786 076 106 www.serge.works<https://urldefense.com/v3/__http:/www.serge.works__;!!A6UyJA!0q19bVFm1wSBf0d9m2u4EiU0ugEkSxsNy6ecVs3JXSIhmsTYAZ3IpQrFxJf0SHRqggbVrc7Ghn1M$> -- Byishimo Shema Serge Kigali, Rwanda Tel: +250 786 076 106 www.serge.works<https://urldefense.com/v3/__http:/www.serge.works__;!!A6UyJA!xdMOpDgufOBL1WXIgUcUxgTcbsdp8WmZnpUB-DBK4ReGRx8n17VhUmhYJTvKy6me5hqQCdy_YHqJ$> -- Byishimo Shema Serge Kigali, Rwanda Tel: +250 786 076 106 www.serge.works<https://urldefense.com/v3/__http:/www.serge.works__;!!A6UyJA!xdMOpDgufOBL1WXIgUcUxgTcbsdp8WmZnpUB-DBK4ReGRx8n17VhUmhYJTvKy6me5hqQCdy_YHqJ$>