Any idea? I have also already managed devpts issue which causes issues on CentOS 8. I have copied devpts line from /etc/fstab from another host. Also SELinux is already disabled
On Wed, Aug 28, 2019 at 9:31 PM Fariborz Navidan <[email protected]> wrote: > This is agent log at debug log level: > > [root@fr-kvm1 primary1]# cat /var/log/cloudstack/agent/agent.log > > 2019-08-28 18:59:16,273 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) > (logid:) Received response: Seq 1-1: { Ans: , MgmtId: 157082893985413, > via: -1, Ver: v1, Flags: 100000, > [{"com.cloud.agent.api.StartupAnswer":{"hostId":0,"pingInterval":60,"result":true,"wait":0}}] > } > 2019-08-28 18:59:16,273 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) > (logid:) Startup task cancelled > 2019-08-28 18:59:16,273 INFO [cloud.agent.Agent] (Agent-Handler-2:null) > (logid:) Proccess agent startup answer, agent id = 0 > 2019-08-28 18:59:16,273 INFO [cloud.agent.Agent] (Agent-Handler-2:null) > (logid:) Set agent id 0 > 2019-08-28 18:59:16,276 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) > (logid:) Adding a watch list > 2019-08-28 18:59:16,277 INFO [cloud.agent.Agent] (Agent-Handler-2:null) > (logid:) Startup Response Received: agent id = 0 > 2019-08-28 18:59:16,277 DEBUG [kvm.resource.LibvirtComputingResource] > (UgentTask-1:null) (logid:) Executing: > /usr/share/cloudstack-common/scripts/vm/network/security_group.py > get_rule_logs_for_vms > 2019-08-28 18:59:16,277 DEBUG [kvm.resource.LibvirtComputingResource] > (UgentTask-1:null) (logid:) Executing while with timeout : 1800000 > 2019-08-28 18:59:16,283 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-2:null) (logid:1f7ef831) Request:Seq > 1-4941856166108987393: { Cmd , MgmtId: 157082893985413, via: 1, Ver: v1, > Flags: 100011, > [{"com.cloud.agent.api.CleanupNetworkRulesCmd":{"interval":2473,"wait":0}}] > } > 2019-08-28 18:59:16,283 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-2:null) (logid:1f7ef831) Processing command: > com.cloud.agent.api.CleanupNetworkRulesCmd > 2019-08-28 18:59:16,283 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-2:null) (logid:1f7ef831) Adding a watch list > 2019-08-28 18:59:16,283 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-2:null) (logid:1f7ef831) Seq 1-4941856166108987393: > { Ans: , MgmtId: 157082893985413, via: 1, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } > 2019-08-28 18:59:16,284 DEBUG [org.reflections.Reflections] > (Agent-Handler-4:null) (logid:1f7ef831) going to scan these urls: > > jar:file:/usr/share/cloudstack-agent/lib/cloud-plugin-hypervisor-kvm-4.12.0.0.jar!/ > 2019-08-28 18:59:16,295 INFO [org.reflections.Reflections] > (Agent-Handler-4:null) (logid:1f7ef831) Reflections took 9 ms to scan 1 > urls, producing 5 keys and 147 values > 2019-08-28 18:59:16,296 DEBUG [org.reflections.Reflections] > (Agent-Handler-4:null) (logid:1f7ef831) expanded subtype > java.lang.Comparable -> java.lang.Enum > 2019-08-28 18:59:16,296 DEBUG [org.reflections.Reflections] > (Agent-Handler-4:null) (logid:1f7ef831) expanded subtype > java.io.Serializable -> java.lang.Enum > 2019-08-28 18:59:16,326 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-3:null) (logid:1f7ef831) Request:Seq > 1-4941856166108987394: { Cmd , MgmtId: 157082893985413, via: 1, Ver: v1, > Flags: 100111, > [{"com.cloud.agent.api.CheckNetworkCommand":{"networkInfoList":[{"physicalNetworkId":200,"privateNetworkName":"cloudbr0","guestNetworkName":"cloudbr1","storageNetworkName":"cloudbr0"}],"wait":0}}] > } > 2019-08-28 18:59:16,326 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-3:null) (logid:1f7ef831) Processing command: > com.cloud.agent.api.CheckNetworkCommand > 2019-08-28 18:59:16,327 DEBUG [kvm.resource.LibvirtComputingResource] > (UgentTask-1:null) (logid:) Execution is successful. > 2019-08-28 18:59:16,328 DEBUG [kvm.resource.LibvirtConnection] > (UgentTask-1:null) (logid:) Looking for libvirtd connection at: > qemu:///system > 2019-08-28 18:59:16,329 DEBUG [cloud.agent.Agent] (UgentTask-1:null) > (logid:) Sending ping: Seq 0-2: { Cmd , MgmtId: -1, via: 0, Ver: v1, > Flags: 11, > [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"_hostVmStateReport":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":0,"wait":0}}] > } > 2019-08-28 18:59:16,334 DEBUG [kvm.resource.LibvirtComputingResource] > (Agent-Handler-4:null) (logid:1f7ef831) Executing: > /usr/share/cloudstack-common/scripts/vm/network/security_group.py > cleanup_rules > 2019-08-28 18:59:16,335 DEBUG [kvm.resource.LibvirtComputingResource] > (agentRequest-Handler-3:null) (logid:1f7ef831) matchPifFileInDirectory: > file name 'eth1.100' > 2019-08-28 18:59:16,335 DEBUG [kvm.resource.LibvirtComputingResource] > (Agent-Handler-4:null) (logid:1f7ef831) Executing while with timeout : > 1800000 > 2019-08-28 18:59:16,335 DEBUG [kvm.resource.LibvirtComputingResource] > (agentRequest-Handler-3:null) (logid:1f7ef831) matchPifFileInDirectory: > file name 'eth1' > 2019-08-28 18:59:16,335 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-3:null) (logid:1f7ef831) Seq 1-4941856166108987394: > { Ans: , MgmtId: 157082893985413, via: 1, Ver: v1, Flags: 110, > [{"com.cloud.agent.api.CheckNetworkAnswer":{"_reconnect":false,"result":true,"wait":0}}] > } > 2019-08-28 18:59:16,396 DEBUG [kvm.resource.LibvirtComputingResource] > (Agent-Handler-4:null) (logid:1f7ef831) Execution is successful. > 2019-08-28 18:59:16,397 DEBUG [cloud.agent.Agent] (Agent-Handler-4:null) > (logid:1f7ef831) Watch Sent: Seq 1-4941856166108987393: { Ans: , MgmtId: > 157082893985413, via: 1, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.Answer":{"result":true,"details":"","wait":0}}] } > 2019-08-28 18:59:16,398 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) > (logid:) Received response: Seq 0-2: { Ans: , MgmtId: 157082893985413, > via: 1, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":0,"wait":0},"result":true,"wait":0}}] > } > 2019-08-28 18:59:16,399 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-4:null) (logid:1f7ef831) Request:Seq > 1-4941856166108987395: { Cmd , MgmtId: 157082893985413, via: 1, Ver: v1, > Flags: 100011, > [{"com.cloud.agent.api.ModifyStoragePoolCommand":{"add":true,"pool":{"id":3,"uuid":"5ea00099-5b91-3787-b948-8a18c40f3a88","host":"192.168.0.2","path":"/home/primary1","port":2049,"type":"NetworkFilesystem"},"localPath":"/mnt//5ea00099-5b91-3787-b948-8a18c40f3a88","wait":0}}] > } > 2019-08-28 18:59:16,399 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-4:null) (logid:1f7ef831) Processing command: > com.cloud.agent.api.ModifyStoragePoolCommand > 2019-08-28 18:59:16,399 INFO [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-4:null) (logid:1f7ef831) Attempting to create storage > pool 5ea00099-5b91-3787-b948-8a18c40f3a88 (NetworkFilesystem) in libvirt > 2019-08-28 18:59:16,399 DEBUG [kvm.resource.LibvirtConnection] > (agentRequest-Handler-4:null) (logid:1f7ef831) Looking for libvirtd > connection at: qemu:///system > 2019-08-28 18:59:16,400 INFO [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-4:null) (logid:1f7ef831) Found existing defined > storage pool 5ea00099-5b91-3787-b948-8a18c40f3a88, using it. > 2019-08-28 18:59:16,400 INFO [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-4:null) (logid:1f7ef831) Trying to fetch storage pool > 5ea00099-5b91-3787-b948-8a18c40f3a88 from libvirt > 2019-08-28 18:59:16,400 DEBUG [kvm.resource.LibvirtConnection] > (agentRequest-Handler-4:null) (logid:1f7ef831) Looking for libvirtd > connection at: qemu:///system > 2019-08-28 18:59:16,402 DEBUG [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-4:null) (logid:1f7ef831) Succesfully refreshed pool > 5ea00099-5b91-3787-b948-8a18c40f3a88 Capacity: 984895979520 Used: 727711744 > Available: 984168267776 > 2019-08-28 18:59:16,403 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-4:null) (logid:1f7ef831) Seq 1-4941856166108987395: > { Ans: , MgmtId: 157082893985413, via: 1, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.ModifyStoragePoolAnswer":{"poolInfo":{"host":"192.168.0.2","localPath":"/mnt//5ea00099-5b91-3787-b948-8a18c40f3a88","hostPath":"/home/primary1","poolType":"NetworkFilesystem","capacityBytes":984895979520,"availableBytes":984168267776},"templateInfo":{},"result":true,"wait":0}}] > } > 2019-08-28 18:59:16,523 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-1:null) (logid:1f7ef831) Request:Seq > 1-4941856166108987397: { Cmd , MgmtId: 157082893985413, via: 1, Ver: v1, > Flags: 100111, > [{"com.cloud.agent.api.SetHostParamsCommand":{"params":{"router.aggregation.command.each.timeout":"600"},"wait":0}}] > } > 2019-08-28 18:59:16,523 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-5:null) (logid:1f7ef831) Request:Seq > 1-4941856166108987396: { Cmd , MgmtId: 157082893985413, via: 1, Ver: v1, > Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] } > 2019-08-28 18:59:16,524 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-5:null) (logid:1f7ef831) Processing command: > com.cloud.agent.api.ModifySshKeysCommand > 2019-08-28 18:59:16,523 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-1:null) (logid:1f7ef831) Processing command: > com.cloud.agent.api.SetHostParamsCommand > 2019-08-28 18:59:16,525 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-1:null) (logid:1f7ef831) Seq 1-4941856166108987397: > { Ans: , MgmtId: 157082893985413, via: 1, Ver: v1, Flags: 110, > [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } > 2019-08-28 18:59:16,525 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-2:null) (logid:1f7ef831) Request:Seq > 1-4941856166108987398: { Cmd , MgmtId: 157082893985413, via: 1, Ver: v1, > Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] } > 2019-08-28 18:59:16,525 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-2:null) (logid:1f7ef831) Processing command: > com.cloud.agent.api.ModifySshKeysCommand > 2019-08-28 18:59:16,529 DEBUG > [resource.wrapper.LibvirtModifySshKeysCommandWrapper] > (agentRequest-Handler-5:null) (logid:1f7ef831) Executing: chmod 600 > /root/.ssh/id_rsa.cloud > 2019-08-28 18:59:16,529 DEBUG > [resource.wrapper.LibvirtModifySshKeysCommandWrapper] > (agentRequest-Handler-2:null) (logid:1f7ef831) Executing: chmod 600 > /root/.ssh/id_rsa.cloud > 2019-08-28 18:59:16,531 DEBUG > [resource.wrapper.LibvirtModifySshKeysCommandWrapper] > (agentRequest-Handler-5:null) (logid:1f7ef831) Executing while with timeout > : 1800000 > 2019-08-28 18:59:16,532 DEBUG > [resource.wrapper.LibvirtModifySshKeysCommandWrapper] > (agentRequest-Handler-2:null) (logid:1f7ef831) Executing while with timeout > : 1800000 > 2019-08-28 18:59:16,534 DEBUG > [resource.wrapper.LibvirtModifySshKeysCommandWrapper] > (agentRequest-Handler-5:null) (logid:1f7ef831) Execution is successful. > 2019-08-28 18:59:16,534 DEBUG > [resource.wrapper.LibvirtModifySshKeysCommandWrapper] > (agentRequest-Handler-2:null) (logid:1f7ef831) Execution is successful. > 2019-08-28 18:59:16,536 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-2:null) (logid:1f7ef831) Seq 1-4941856166108987398: > { Ans: , MgmtId: 157082893985413, via: 1, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } > 2019-08-28 18:59:16,537 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-5:null) (logid:1f7ef831) Seq 1-4941856166108987396: > { Ans: , MgmtId: 157082893985413, via: 1, Ver: v1, Flags: 10, > [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] } > 2019-08-28 18:59:16,542 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-3:null) (logid:1f7ef831) Request:Seq > 1-4941856166108987399: { Cmd , MgmtId: 157082893985413, via: 1, Ver: v1, > Flags: 100111, > [{"com.cloud.agent.api.ReadyCommand":{"dcId":1,"hostId":1,"wait":0}}] } > 2019-08-28 18:59:16,542 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-3:null) (logid:1f7ef831) Processing command: > com.cloud.agent.api.ReadyCommand > 2019-08-28 18:59:16,542 INFO [cloud.agent.Agent] > (agentRequest-Handler-3:null) (logid:1f7ef831) Processing agent ready > command, agent id = 1 > 2019-08-28 18:59:16,542 INFO [cloud.agent.Agent] > (agentRequest-Handler-3:null) (logid:1f7ef831) Set agent id 1 > 2019-08-28 18:59:16,551 INFO [cloud.agent.Agent] > (agentRequest-Handler-3:null) (logid:1f7ef831) Ready command is processed > for agent id = 1 > 2019-08-28 18:59:16,553 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-3:null) (logid:1f7ef831) Seq 1-4941856166108987399: > { Ans: , MgmtId: 157082893985413, via: 1, Ver: v1, Flags: 110, > [{"com.cloud.agent.api.ReadyAnswer":{"result":true,"wait":0}}] } > 2019-08-28 18:59:16,641 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-4:null) (logid:1f7ef831) Request:Seq > 1-4941856166108987400: { Cmd , MgmtId: 157082893985413, via: 1, Ver: v1, > Flags: 100111, > [{"com.cloud.agent.api.ReadyCommand":{"dcId":1,"hostId":1,"wait":0}}] } > 2019-08-28 18:59:16,641 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-4:null) (logid:1f7ef831) Processing command: > com.cloud.agent.api.ReadyCommand > 2019-08-28 18:59:16,641 INFO [cloud.agent.Agent] > (agentRequest-Handler-4:null) (logid:1f7ef831) Processing agent ready > command, agent id = 1 > 2019-08-28 18:59:16,641 INFO [cloud.agent.Agent] > (agentRequest-Handler-4:null) (logid:1f7ef831) Set agent id 1 > 2019-08-28 18:59:16,642 INFO [cloud.agent.Agent] > (agentRequest-Handler-4:null) (logid:1f7ef831) Ready command is processed > for agent id = 1 > 2019-08-28 18:59:16,643 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-4:null) (logid:1f7ef831) Seq 1-4941856166108987400: > { Ans: , MgmtId: 157082893985413, via: 1, Ver: v1, Flags: 110, > [{"com.cloud.agent.api.ReadyAnswer":{"result":true,"wait":0}}] } > 2019-08-28 18:59:25,626 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-1:null) (logid:9391b96b) Processing command: > com.cloud.agent.api.GetHostStatsCommand > 2019-08-28 18:59:27,984 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-2:null) (logid:2fe46c5c) Processing command: > com.cloud.agent.api.GetStorageStatsCommand > 2019-08-28 18:59:27,985 INFO [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-2:null) (logid:2fe46c5c) Trying to fetch storage pool > 5ea00099-5b91-3787-b948-8a18c40f3a88 from libvirt > 2019-08-28 18:59:27,985 DEBUG [kvm.resource.LibvirtConnection] > (agentRequest-Handler-2:null) (logid:2fe46c5c) Looking for libvirtd > connection at: qemu:///system > 2019-08-28 18:59:27,989 INFO [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-2:null) (logid:2fe46c5c) Asking libvirt to refresh > storage pool 5ea00099-5b91-3787-b948-8a18c40f3a88 > 2019-08-28 18:59:27,992 DEBUG [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-2:null) (logid:2fe46c5c) Succesfully refreshed pool > 5ea00099-5b91-3787-b948-8a18c40f3a88 Capacity: 984895979520 Used: 727711744 > Available: 984168267776 > 2019-08-28 19:00:04,730 DEBUG [kvm.resource.LibvirtConnection] > (Thread-8:null) (logid:) Looking for libvirtd connection at: qemu:///system > 2019-08-28 19:00:04,733 DEBUG [kvm.resource.KVMHAMonitor] (Thread-8:null) > (logid:) Found NFS storage pool 5ea00099-5b91-3787-b948-8a18c40f3a88 in > libvirt, continuing > 2019-08-28 19:00:04,734 DEBUG [kvm.resource.KVMHAMonitor] (Thread-8:null) > (logid:) Executing: > /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i > 192.168.0.2 -p /home/primary1 -m /mnt/5ea00099-5b91-3787-b948-8a18c40f3a88 > -h 192.168.0.2 > 2019-08-28 19:00:04,735 DEBUG [kvm.resource.KVMHAMonitor] (Thread-8:null) > (logid:) Executing while with timeout : 60000 > 2019-08-28 19:00:04,741 DEBUG [kvm.resource.KVMHAMonitor] (Thread-8:null) > (logid:) Execution is successful. > 2019-08-28 19:00:16,278 DEBUG [kvm.resource.LibvirtComputingResource] > (UgentTask-2:null) (logid:) Executing: > /usr/share/cloudstack-common/scripts/vm/network/security_group.py > get_rule_logs_for_vms > 2019-08-28 19:00:16,281 DEBUG [kvm.resource.LibvirtComputingResource] > (UgentTask-2:null) (logid:) Executing while with timeout : 1800000 > 2019-08-28 19:00:16,331 DEBUG [kvm.resource.LibvirtComputingResource] > (UgentTask-2:null) (logid:) Execution is successful. > 2019-08-28 19:00:16,331 DEBUG [kvm.resource.LibvirtConnection] > (UgentTask-2:null) (logid:) Looking for libvirtd connection at: > qemu:///system > 2019-08-28 19:00:16,332 DEBUG [cloud.agent.Agent] (UgentTask-2:null) > (logid:) Sending ping: Seq 1-3: { Cmd , MgmtId: -1, via: 1, Ver: v1, > Flags: 11, > [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"_hostVmStateReport":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":1,"wait":0}}] > } > 2019-08-28 19:00:16,377 DEBUG [cloud.agent.Agent] (Agent-Handler-4:null) > (logid:1f7ef831) Received response: Seq 1-3: { Ans: , MgmtId: > 157082893985413, via: 1, Ver: v1, Flags: 100010, > [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":1,"wait":0},"result":true,"wait":0}}] > } > 2019-08-28 19:00:25,663 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-5:null) (logid:919a0a37) Processing command: > com.cloud.agent.api.GetHostStatsCommand > 2019-08-28 19:00:28,053 DEBUG [cloud.agent.Agent] > (agentRequest-Handler-3:null) (logid:79632973) Processing command: > com.cloud.agent.api.GetStorageStatsCommand > 2019-08-28 19:00:28,053 INFO [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-3:null) (logid:79632973) Trying to fetch storage pool > 5ea00099-5b91-3787-b948-8a18c40f3a88 from libvirt > 2019-08-28 19:00:28,053 DEBUG [kvm.resource.LibvirtConnection] > (agentRequest-Handler-3:null) (logid:79632973) Looking for libvirtd > connection at: qemu:///system > 2019-08-28 19:00:28,058 INFO [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-3:null) (logid:79632973) Asking libvirt to refresh > storage pool 5ea00099-5b91-3787-b948-8a18c40f3a88 > 2019-08-28 19:00:28,061 DEBUG [kvm.storage.LibvirtStorageAdaptor] > (agentRequest-Handler-3:null) (logid:79632973) Succesfully refreshed pool > 5ea00099-5b91-3787-b948-8a18c40f3a88 Capacity: 984895979520 Used: 727711744 > Available: 984168267776 > [root@fr-kvm1 primary1]# > > On Wed, Aug 28, 2019 at 8:43 PM Andrija Panic <[email protected]> > wrote: > >> I Don't see anything attached from agent.log? Make sure to put agent in >> debug mode before posting logs (google for "cloudstack agent debug mode", >> there is a simple sed command, restart agent afterwards). >> >> Andrija >> >> On Wed, Aug 28, 2019, 17:44 Fariborz Navidan <[email protected]> >> wrote: >> >> > Hi, >> > >> > Also this is agent log >> > >> > On Wed, Aug 28, 2019 at 6:41 PM Fariborz Navidan <[email protected] >> > >> > wrote: >> > >> > > Any idea? >> > > >> > > On Wed, Aug 28, 2019 at 5:09 PM Fariborz Navidan < >> [email protected]> >> > > wrote: >> > > >> > >> Thanks. I changed VLAN ID and now they are kept starting for along >> time. >> > >> Latest logs: >> > >> >> > >> >> > >> 2019-08-28 14:34:04,851 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-e4b25970) (logid:4ca3d1a2) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:34:04,859 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-e4b25970) (logid:4ca3d1a2) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:34:10,577 WARN [o.a.c.f.j.i.AsyncJobMonitor] >> > >> (Timer-0:ctx-b00ab490) (logid:c9e4081e) Task (job-318) has been >> pending >> > for >> > >> 959 seconds >> > >> 2019-08-28 14:34:10,577 WARN [o.a.c.f.j.i.AsyncJobMonitor] >> > >> (Timer-0:ctx-b00ab490) (logid:c9e4081e) Task (job-320) has been >> pending >> > for >> > >> 357 seconds >> > >> 2019-08-28 14:34:14,851 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-665ba8c1) (logid:07ce74f8) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:34:14,852 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-1d77361c) (logid:9bc2f8a4) Found 0 >> routers to >> > >> update status. >> > >> 2019-08-28 14:34:14,854 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-1d77361c) (logid:9bc2f8a4) Found 0 VPC >> > networks >> > >> to update Redundant State. >> > >> 2019-08-28 14:34:14,857 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-1d77361c) (logid:9bc2f8a4) Found 0 >> networks >> > to >> > >> update RvR status. >> > >> 2019-08-28 14:34:14,859 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-665ba8c1) (logid:07ce74f8) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:34:17,628 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-267:ctx-7f61f42c) (logid:69ceb90d) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listInfrastructure&response=json&_=1566995598229 >> > >> 2019-08-28 14:34:17,637 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-267:ctx-7f61f42c ctx-c6adb54b) (logid:69ceb90d) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:17,659 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-267:ctx-7f61f42c ctx-c6adb54b) (logid:69ceb90d) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listInfrastructure&response=json&_=1566995598229 >> > >> 2019-08-28 14:34:19,922 DEBUG [c.c.h.d.HostDaoImpl] >> > >> (ClusteredAgentManager Timer:ctx-e1f47dc0) (logid:c0c93cd1) Resetting >> > hosts >> > >> suitable for reconnect >> > >> 2019-08-28 14:34:19,924 DEBUG [c.c.h.d.HostDaoImpl] >> > >> (ClusteredAgentManager Timer:ctx-e1f47dc0) (logid:c0c93cd1) Completed >> > >> resetting hosts suitable for reconnect >> > >> 2019-08-28 14:34:19,924 DEBUG [c.c.h.d.HostDaoImpl] >> > >> (ClusteredAgentManager Timer:ctx-e1f47dc0) (logid:c0c93cd1) Acquiring >> > hosts >> > >> for clusters already owned by this management server >> > >> 2019-08-28 14:34:19,925 DEBUG [c.c.h.d.HostDaoImpl] >> > >> (ClusteredAgentManager Timer:ctx-e1f47dc0) (logid:c0c93cd1) Completed >> > >> acquiring hosts for clusters already owned by this management server >> > >> 2019-08-28 14:34:19,925 DEBUG [c.c.h.d.HostDaoImpl] >> > >> (ClusteredAgentManager Timer:ctx-e1f47dc0) (logid:c0c93cd1) Acquiring >> > hosts >> > >> for clusters not owned by any management server >> > >> 2019-08-28 14:34:19,926 DEBUG [c.c.h.d.HostDaoImpl] >> > >> (ClusteredAgentManager Timer:ctx-e1f47dc0) (logid:c0c93cd1) Completed >> > >> acquiring hosts for clusters not owned by any management server >> > >> 2019-08-28 14:34:20,494 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-51d12c34) (logid:f8b01d6e) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listZones&page=1&pagesize=20&response=json&_=1566995598230 >> > >> 2019-08-28 14:34:20,500 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-540:ctx-51d12c34 ctx-6814b565) (logid:f8b01d6e) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:20,504 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-51d12c34 ctx-6814b565) (logid:f8b01d6e) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listZones&page=1&pagesize=20&response=json&_=1566995598230 >> > >> 2019-08-28 14:34:24,857 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-5b6871f5) (logid:01bd640f) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:34:24,865 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-5b6871f5) (logid:01bd640f) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:34:24,974 DEBUG [c.c.a.m.AgentManagerImpl] >> > >> (AgentManager-Handler-15:null) (logid:) Ping from 1( >> fr-kvm1.r9host.com) >> > >> 2019-08-28 14:34:24,974 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-15:null) (logid:) Process host VM state report >> > from >> > >> ping process. host: 1 >> > >> 2019-08-28 14:34:24,975 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-15:null) (logid:) Process VM state report. >> host: >> > 1, >> > >> number of records in report: 1 >> > >> 2019-08-28 14:34:24,975 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-15:null) (logid:) VM state report. host: 1, vm >> id: >> > >> 103, power state: PowerOn >> > >> 2019-08-28 14:34:24,976 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-15:null) (logid:) VM state report is updated. >> > host: >> > >> 1, vm id: 103, power state: PowerOn >> > >> 2019-08-28 14:34:24,977 INFO [c.c.v.VirtualMachineManagerImpl] >> > >> (AgentManager-Handler-15:null) (logid:) There is pending job or HA >> tasks >> > >> working on the VM. vm id: 103, postpone power-change report by >> resetting >> > >> power-change counters >> > >> 2019-08-28 14:34:24,980 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-15:null) (logid:) Run missing VM report. >> current >> > >> time: 1566995664980 >> > >> 2019-08-28 14:34:24,980 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-15:null) (logid:) Detected missing VM. host: >> 1, vm >> > >> id: 101, power state: PowerReportMissing, last state update: >> > 1566995544000 >> > >> 2019-08-28 14:34:24,980 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-15:null) (logid:) vm id: 101 - time since last >> > state >> > >> update(120980ms) has passed graceful period >> > >> 2019-08-28 14:34:24,982 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-15:null) (logid:) VM state report is updated. >> > host: >> > >> 1, vm id: 101, power state: PowerReportMissing >> > >> 2019-08-28 14:34:24,982 INFO [c.c.v.VirtualMachineManagerImpl] >> > >> (AgentManager-Handler-15:null) (logid:) There is pending job or HA >> tasks >> > >> working on the VM. vm id: 101, postpone power-change report by >> resetting >> > >> power-change counters >> > >> 2019-08-28 14:34:24,984 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-15:null) (logid:) Detected missing VM. host: >> 1, vm >> > >> id: 102, power state: PowerReportMissing, last state update: >> > 1566995544000 >> > >> 2019-08-28 14:34:24,984 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-15:null) (logid:) vm id: 102 - time since last >> > state >> > >> update(120980ms) has passed graceful period >> > >> 2019-08-28 14:34:24,986 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-15:null) (logid:) VM state report is updated. >> > host: >> > >> 1, vm id: 102, power state: PowerReportMissing >> > >> 2019-08-28 14:34:24,986 INFO [c.c.v.VirtualMachineManagerImpl] >> > >> (AgentManager-Handler-15:null) (logid:) There is pending job or HA >> tasks >> > >> working on the VM. vm id: 102, postpone power-change report by >> resetting >> > >> power-change counters >> > >> 2019-08-28 14:34:24,987 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-15:null) (logid:) Done with process of VM state >> > >> report. host: 1 >> > >> 2019-08-28 14:34:26,012 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-72cb5770) (logid:d2576b2d) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listInfrastructure&response=json&_=1566995598231 >> > >> 2019-08-28 14:34:26,020 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-72cb5770 ctx-67029176) (logid:d2576b2d) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:26,044 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-72cb5770 ctx-67029176) (logid:d2576b2d) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listInfrastructure&response=json&_=1566995598231 >> > >> 2019-08-28 14:34:29,854 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-61e00b9c) (logid:6a21df96) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listZones&page=1&pagesize=20&response=json&_=1566995598232 >> > >> 2019-08-28 14:34:29,860 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-540:ctx-61e00b9c ctx-416ae397) (logid:6a21df96) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:29,864 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-61e00b9c ctx-416ae397) (logid:6a21df96) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listZones&page=1&pagesize=20&response=json&_=1566995598232 >> > >> 2019-08-28 14:34:30,176 DEBUG [c.c.s.StatsCollector] >> > >> (StatsCollector-2:ctx-fb2716cb) (logid:0d4c72ca) AutoScaling Monitor >> is >> > >> running... >> > >> 2019-08-28 14:34:33,240 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-3062efb0) (logid:17ce85f1) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598233 >> > >> 2019-08-28 14:34:33,249 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-3062efb0 ctx-2dfc105f) (logid:17ce85f1) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:33,267 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-3062efb0 ctx-2dfc105f) (logid:17ce85f1) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598233 >> > >> 2019-08-28 14:34:33,396 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-e40e8ed5) (logid:579437b8) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listDedicatedZones&response=json&zoneid=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598234 >> > >> 2019-08-28 14:34:33,404 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-540:ctx-e40e8ed5 ctx-1610f3df) (logid:579437b8) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:33,415 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-e40e8ed5 ctx-1610f3df) (logid:579437b8) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listDedicatedZones&response=json&zoneid=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598234 >> > >> 2019-08-28 14:34:33,532 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-4f090298) (logid:1929ff2c) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listApis&response=json&name=listVmwareDcs&_=1566995598235 >> > >> 2019-08-28 14:34:33,540 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-4f090298 ctx-edba44a4) (logid:1929ff2c) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:33,546 INFO [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-4f090298 ctx-edba44a4) (logid:1929ff2c) Api >> > >> Discovery plugin was unable to find an api by that name or process >> any >> > apis >> > >> 2019-08-28 14:34:33,546 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-4f090298 ctx-edba44a4) (logid:1929ff2c) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listApis&response=json&name=listVmwareDcs&_=1566995598235 >> > >> 2019-08-28 14:34:34,851 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-3db42e00) (logid:4d8db73d) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:34:34,861 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-3db42e00) (logid:4d8db73d) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:34:35,481 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-e9a1d962) (logid:12e0b85c) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=updateZone&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&allocationstate=Disabled&response=json&_=1566995598236 >> > >> 2019-08-28 14:34:35,487 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-540:ctx-e9a1d962 ctx-88b9d315) (logid:12e0b85c) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:35,494 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-e9a1d962 ctx-88b9d315) (logid:12e0b85c) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=updateZone&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&allocationstate=Disabled&response=json&_=1566995598236 >> > >> 2019-08-28 14:34:37,341 DEBUG [c.c.s.StatsCollector] >> > >> (StatsCollector-3:ctx-4c48013d) (logid:6aaadd07) HostStatsCollector >> is >> > >> running... >> > >> 2019-08-28 14:34:37,398 DEBUG [c.c.a.t.Request] >> > >> (StatsCollector-3:ctx-4c48013d) (logid:6aaadd07) Seq >> > 1-5778962746846479041: >> > >> Received: { Ans: , MgmtId: 205425461278937, via: 1( >> fr-kvm1.r9host.com >> > ), >> > >> Ver: v1, Flags: 10, { GetHostStatsAnswer } } >> > >> 2019-08-28 14:34:38,526 DEBUG [c.c.s.StatsCollector] >> > >> (StatsCollector-6:ctx-1caf1bfa) (logid:21e40ccc) StorageCollector is >> > >> running... >> > >> 2019-08-28 14:34:38,536 DEBUG [c.c.s.StatsCollector] >> > >> (StatsCollector-6:ctx-1caf1bfa) (logid:21e40ccc) There is no >> secondary >> > >> storage VM for secondary storage host Secondary1 >> > >> 2019-08-28 14:34:38,539 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] >> > >> (StatsCollector-6:ctx-1caf1bfa) (logid:21e40ccc) >> > getCommandHostDelegation: >> > >> class com.cloud.agent.api.GetStorageStatsCommand >> > >> 2019-08-28 14:34:38,539 DEBUG [c.c.h.XenServerGuru] >> > >> (StatsCollector-6:ctx-1caf1bfa) (logid:21e40ccc) We are returning the >> > >> default host to execute commands because the command is not of Copy >> > type. >> > >> 2019-08-28 14:34:38,592 DEBUG [c.c.a.t.Request] >> > >> (StatsCollector-6:ctx-1caf1bfa) (logid:21e40ccc) Seq >> > 1-5778962746846479042: >> > >> Received: { Ans: , MgmtId: 205425461278937, via: 1( >> fr-kvm1.r9host.com >> > ), >> > >> Ver: v1, Flags: 10, { GetStorageStatsAnswer } } >> > >> 2019-08-28 14:34:38,732 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-b742baaf) (logid:fd475e73) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598237 >> > >> 2019-08-28 14:34:38,740 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-b742baaf ctx-e306b339) (logid:fd475e73) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:38,759 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-b742baaf ctx-e306b339) (logid:fd475e73) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598237 >> > >> 2019-08-28 14:34:38,876 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-78a2ea0b) (logid:53245a8d) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listDedicatedZones&response=json&zoneid=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598238 >> > >> 2019-08-28 14:34:38,884 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-540:ctx-78a2ea0b ctx-54546774) (logid:53245a8d) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:38,894 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-78a2ea0b ctx-54546774) (logid:53245a8d) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listDedicatedZones&response=json&zoneid=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598238 >> > >> 2019-08-28 14:34:39,017 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-dc6ad71d) (logid:a29f4b7b) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listApis&response=json&name=listVmwareDcs&_=1566995598239 >> > >> 2019-08-28 14:34:39,025 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-dc6ad71d ctx-d9671a26) (logid:a29f4b7b) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:39,031 INFO [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-dc6ad71d ctx-d9671a26) (logid:a29f4b7b) Api >> > >> Discovery plugin was unable to find an api by that name or process >> any >> > apis >> > >> 2019-08-28 14:34:39,032 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-dc6ad71d ctx-d9671a26) (logid:a29f4b7b) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listApis&response=json&name=listVmwareDcs&_=1566995598239 >> > >> 2019-08-28 14:34:42,577 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-40d2ea6d) (logid:087bc8bb) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listInfrastructure&response=json&_=1566995598240 >> > >> 2019-08-28 14:34:42,585 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-540:ctx-40d2ea6d ctx-82e1d1f7) (logid:087bc8bb) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:42,610 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-40d2ea6d ctx-82e1d1f7) (logid:087bc8bb) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listInfrastructure&response=json&_=1566995598240 >> > >> 2019-08-28 14:34:44,850 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-61ce445a) (logid:21c23d72) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:34:44,852 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-45ec83d0) (logid:b2c00ab6) Found 0 >> routers to >> > >> update status. >> > >> 2019-08-28 14:34:44,855 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-45ec83d0) (logid:b2c00ab6) Found 0 VPC >> > networks >> > >> to update Redundant State. >> > >> 2019-08-28 14:34:44,857 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-45ec83d0) (logid:b2c00ab6) Found 0 >> networks >> > to >> > >> update RvR status. >> > >> 2019-08-28 14:34:44,859 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-61ce445a) (logid:21c23d72) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:34:48,198 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-4b52ed63) (logid:6e637323) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&response=json&listAll=true&page=1&pagesize=20&_=1566995598241 >> > >> 2019-08-28 14:34:48,207 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-4b52ed63 ctx-4d66e47d) (logid:6e637323) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:48,215 WARN [c.c.a.d.ParamGenericValidationWorker] >> > >> (qtp2114650936-535:ctx-4b52ed63 ctx-4d66e47d) (logid:6e637323) >> Received >> > >> unknown parameters for command listSystemVms. Unknown parameters : >> > listall >> > >> 2019-08-28 14:34:48,268 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-4b52ed63 ctx-4d66e47d) (logid:6e637323) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&response=json&listAll=true&page=1&pagesize=20&_=1566995598241 >> > >> 2019-08-28 14:34:48,462 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-4f0ef9bc) (logid:1065f9c5) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listHosts&response=json&details=min&_=1566995598242 >> > >> 2019-08-28 14:34:48,470 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-540:ctx-4f0ef9bc ctx-ec0ccd73) (logid:1065f9c5) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:48,478 DEBUG [c.c.a.q.QueryManagerImpl] >> > >> (qtp2114650936-540:ctx-4f0ef9bc ctx-ec0ccd73) (logid:1065f9c5) >> > >>>Searching >> > >> for hosts>>> >> > >> 2019-08-28 14:34:48,484 DEBUG [c.c.a.q.QueryManagerImpl] >> > >> (qtp2114650936-540:ctx-4f0ef9bc ctx-ec0ccd73) (logid:1065f9c5) >> > >> >>>Generating Response>>> >> > >> 2019-08-28 14:34:48,485 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-4f0ef9bc ctx-ec0ccd73) (logid:1065f9c5) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listHosts&response=json&details=min&_=1566995598242 >> > >> 2019-08-28 14:34:54,843 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-51f8dd11) (logid:1ac9f638) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:34:54,845 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-51f8dd11) (logid:1ac9f638) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:34:55,209 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-d366af14) (logid:3489b330) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598243 >> > >> 2019-08-28 14:34:55,217 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-d366af14 ctx-893fb42c) (logid:3489b330) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:55,235 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-d366af14 ctx-893fb42c) (logid:3489b330) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598243 >> > >> 2019-08-28 14:34:55,388 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-a73c5049) (logid:2b550fd0) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598244 >> > >> 2019-08-28 14:34:55,395 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-540:ctx-a73c5049 ctx-1a77bfde) (logid:2b550fd0) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:34:55,448 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-a73c5049 ctx-1a77bfde) (logid:2b550fd0) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598244 >> > >> 2019-08-28 14:35:03,782 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-7e0bc117) (logid:50c19de5) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listInfrastructure&response=json&_=1566995598245 >> > >> 2019-08-28 14:35:03,789 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-7e0bc117 ctx-575e2882) (logid:50c19de5) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:03,814 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-7e0bc117 ctx-575e2882) (logid:50c19de5) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listInfrastructure&response=json&_=1566995598245 >> > >> 2019-08-28 14:35:04,849 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-21aa8d2e) (logid:1547d462) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:35:04,851 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-21aa8d2e) (logid:1547d462) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:35:06,808 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-41662f1f) (logid:2682bbeb) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listZones&page=1&pagesize=20&response=json&_=1566995598246 >> > >> 2019-08-28 14:35:06,816 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-540:ctx-41662f1f ctx-38769150) (logid:2682bbeb) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:06,834 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-41662f1f ctx-38769150) (logid:2682bbeb) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listZones&page=1&pagesize=20&response=json&_=1566995598246 >> > >> 2019-08-28 14:35:08,838 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-77636d90) (logid:a415b9a3) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598247 >> > >> 2019-08-28 14:35:08,845 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-77636d90 ctx-b8571a42) (logid:a415b9a3) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:08,857 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-77636d90 ctx-b8571a42) (logid:a415b9a3) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598247 >> > >> 2019-08-28 14:35:08,982 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-409e3da6) (logid:00800f6e) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listDedicatedZones&response=json&zoneid=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598248 >> > >> 2019-08-28 14:35:08,990 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-540:ctx-409e3da6 ctx-29f8f704) (logid:00800f6e) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:09,001 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-409e3da6 ctx-29f8f704) (logid:00800f6e) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listDedicatedZones&response=json&zoneid=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598248 >> > >> 2019-08-28 14:35:09,126 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-67630fc0) (logid:eca6e20c) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listApis&response=json&name=listVmwareDcs&_=1566995598249 >> > >> 2019-08-28 14:35:09,134 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-67630fc0 ctx-fcea72b5) (logid:eca6e20c) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:09,142 INFO [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-67630fc0 ctx-fcea72b5) (logid:eca6e20c) Api >> > >> Discovery plugin was unable to find an api by that name or process >> any >> > apis >> > >> 2019-08-28 14:35:09,142 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-67630fc0 ctx-fcea72b5) (logid:eca6e20c) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listApis&response=json&name=listVmwareDcs&_=1566995598249 >> > >> 2019-08-28 14:35:10,578 WARN [o.a.c.f.j.i.AsyncJobMonitor] >> > >> (Timer-0:ctx-dfc811d7) (logid:9c5404b2) Task (job-318) has been >> pending >> > for >> > >> 1019 seconds >> > >> 2019-08-28 14:35:10,578 WARN [o.a.c.f.j.i.AsyncJobMonitor] >> > >> (Timer-0:ctx-dfc811d7) (logid:9c5404b2) Task (job-320) has been >> pending >> > for >> > >> 417 seconds >> > >> 2019-08-28 14:35:13,609 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-0bb9da2a) (logid:185d38c3) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=updateZone&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&allocationstate=Enabled&response=json&_=1566995598250 >> > >> 2019-08-28 14:35:13,617 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-540:ctx-0bb9da2a ctx-7cf333f4) (logid:185d38c3) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:13,657 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-0bb9da2a ctx-7cf333f4) (logid:185d38c3) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=updateZone&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&allocationstate=Enabled&response=json&_=1566995598250 >> > >> 2019-08-28 14:35:14,844 INFO [c.c.r.ResourceLimitManagerImpl] >> > >> (ResourceCountChecker-1:ctx-2fb83b01) (logid:bd4a6195) Started >> resource >> > >> counters recalculation periodic task. >> > >> 2019-08-28 14:35:14,848 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl] >> > >> (ExternalNetworkMonitor-1:ctx-c5fc84e6) (logid:094caf32) External >> > devices >> > >> are not used. Skipping external device usage collection >> > >> 2019-08-28 14:35:14,851 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-43ce8c2a) (logid:82ac4d0c) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:35:14,852 DEBUG [c.c.s.s.SnapshotSchedulerImpl] >> > >> (SnapshotPollTask:ctx-30a5293f) (logid:17a7f1d7) Snapshot >> > scheduler.poll is >> > >> being called at 2019-08-28 12:35:14 GMT >> > >> 2019-08-28 14:35:14,857 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-43ce8c2a) (logid:82ac4d0c) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:35:14,857 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-50ce53ae) (logid:56e39189) Found 0 >> routers to >> > >> update status. >> > >> 2019-08-28 14:35:14,857 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > (RouterMonitor-1:ctx-7cb475c8) >> > >> (logid:cc3e421d) Found 0 running routers. >> > >> 2019-08-28 14:35:14,858 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-50ce53ae) (logid:56e39189) Found 0 VPC >> > networks >> > >> to update Redundant State. >> > >> 2019-08-28 14:35:14,858 DEBUG [c.c.s.s.SnapshotSchedulerImpl] >> > >> (SnapshotPollTask:ctx-30a5293f) (logid:17a7f1d7) Got 0 snapshots to >> be >> > >> executed at 2019-08-28 12:35:14 GMT >> > >> 2019-08-28 14:35:14,858 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-50ce53ae) (logid:56e39189) Found 0 >> networks >> > to >> > >> update RvR status. >> > >> 2019-08-28 14:35:14,906 INFO [o.a.c.e.o.NetworkOrchestrator] >> > >> (Network-Scavenger-1:ctx-d8aa24b5) (logid:d725dea4) >> > NetworkGarbageCollector >> > >> uses '600' seconds for GC interval. >> > >> 2019-08-28 14:35:14,925 INFO [c.c.h.HighAvailabilityManagerImpl] >> > >> (HA-2:ctx-0d95eac6) (logid:b56447b5) checking health of usage server >> > >> 2019-08-28 14:35:14,928 DEBUG [c.c.h.HighAvailabilityManagerImpl] >> > >> (HA-2:ctx-0d95eac6) (logid:b56447b5) usage server running? true, >> > heartbeat: >> > >> Wed Aug 28 14:35:12 CEST 2019 >> > >> 2019-08-28 14:35:16,891 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-17ae8067) (logid:d2ff137a) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598251 >> > >> 2019-08-28 14:35:16,899 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-17ae8067 ctx-97328468) (logid:d2ff137a) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:16,917 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-17ae8067 ctx-97328468) (logid:d2ff137a) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598251 >> > >> 2019-08-28 14:35:17,380 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-c9973280) (logid:8c0fb627) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listDedicatedZones&response=json&zoneid=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598252 >> > >> 2019-08-28 14:35:17,388 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-540:ctx-c9973280 ctx-43947030) (logid:8c0fb627) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:17,398 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-c9973280 ctx-43947030) (logid:8c0fb627) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listDedicatedZones&response=json&zoneid=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598252 >> > >> 2019-08-28 14:35:17,899 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-d990bce3) (logid:b31fa0e8) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listApis&response=json&name=listVmwareDcs&_=1566995598253 >> > >> 2019-08-28 14:35:17,905 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-d990bce3 ctx-43fdfc37) (logid:b31fa0e8) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:17,906 INFO [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-d990bce3 ctx-43fdfc37) (logid:b31fa0e8) Api >> > >> Discovery plugin was unable to find an api by that name or process >> any >> > apis >> > >> 2019-08-28 14:35:17,906 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-d990bce3 ctx-43fdfc37) (logid:b31fa0e8) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listApis&response=json&name=listVmwareDcs&_=1566995598253 >> > >> 2019-08-28 14:35:20,040 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-49453fa9) (logid:c0fd2ac6) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listInfrastructure&response=json&_=1566995598254 >> > >> 2019-08-28 14:35:20,048 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-540:ctx-49453fa9 ctx-e7ed0e9f) (logid:c0fd2ac6) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:20,071 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-540:ctx-49453fa9 ctx-e7ed0e9f) (logid:c0fd2ac6) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listInfrastructure&response=json&_=1566995598254 >> > >> 2019-08-28 14:35:24,852 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-1dca0b93) (logid:6288c36f) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:35:24,860 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-1dca0b93) (logid:6288c36f) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:35:24,889 DEBUG [c.c.n.l.LBHealthCheckManagerImpl] >> > >> (LBHealthCheck-1:ctx-9111e5e6) (logid:482454fb) LB HealthCheck >> Manager >> > is >> > >> running and getting the updates from LB providers and updating >> service >> > >> status >> > >> 2019-08-28 14:35:24,906 DEBUG [c.c.n.l.LBHealthCheckManagerImpl] >> > >> (LBHealthCheck-1:ctx-9111e5e6) (logid:482454fb) LB HealthCheck >> Manager >> > is >> > >> running and getting the updates from LB providers and updating >> service >> > >> status >> > >> 2019-08-28 14:35:25,005 DEBUG [c.c.a.m.AgentManagerImpl] >> > >> (AgentManager-Handler-1:null) (logid:) Ping from 1( >> fr-kvm1.r9host.com) >> > >> 2019-08-28 14:35:25,005 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-1:null) (logid:) Process host VM state report >> from >> > >> ping process. host: 1 >> > >> 2019-08-28 14:35:25,006 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-1:null) (logid:) Process VM state report. >> host: 1, >> > >> number of records in report: 1 >> > >> 2019-08-28 14:35:25,006 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-1:null) (logid:) VM state report. host: 1, vm >> id: >> > >> 103, power state: PowerOn >> > >> 2019-08-28 14:35:25,007 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-1:null) (logid:) VM state report is updated. >> > host: 1, >> > >> vm id: 103, power state: PowerOn >> > >> 2019-08-28 14:35:25,008 INFO [c.c.v.VirtualMachineManagerImpl] >> > >> (AgentManager-Handler-1:null) (logid:) There is pending job or HA >> tasks >> > >> working on the VM. vm id: 103, postpone power-change report by >> resetting >> > >> power-change counters >> > >> 2019-08-28 14:35:25,011 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-1:null) (logid:) Run missing VM report. current >> > time: >> > >> 1566995725011 >> > >> 2019-08-28 14:35:25,012 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-1:null) (logid:) Detected missing VM. host: 1, >> vm >> > id: >> > >> 101, power state: PowerReportMissing, last state update: >> 1566995664000 >> > >> 2019-08-28 14:35:25,012 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-1:null) (logid:) vm id: 101 - time since last >> > state >> > >> update(61011ms) has not passed graceful period yet >> > >> 2019-08-28 14:35:25,012 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-1:null) (logid:) Detected missing VM. host: 1, >> vm >> > id: >> > >> 102, power state: PowerReportMissing, last state update: >> 1566995664000 >> > >> 2019-08-28 14:35:25,012 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-1:null) (logid:) vm id: 102 - time since last >> > state >> > >> update(61011ms) has not passed graceful period yet >> > >> 2019-08-28 14:35:25,012 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-1:null) (logid:) Done with process of VM state >> > >> report. host: 1 >> > >> 2019-08-28 14:35:26,374 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-8a924b4d) (logid:411683a9) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&response=json&listAll=true&page=1&pagesize=20&_=1566995598255 >> > >> 2019-08-28 14:35:26,383 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-8a924b4d ctx-f05d2ed4) (logid:411683a9) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:26,390 WARN [c.c.a.d.ParamGenericValidationWorker] >> > >> (qtp2114650936-535:ctx-8a924b4d ctx-f05d2ed4) (logid:411683a9) >> Received >> > >> unknown parameters for command listSystemVms. Unknown parameters : >> > listall >> > >> 2019-08-28 14:35:26,447 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-8a924b4d ctx-f05d2ed4) (logid:411683a9) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&response=json&listAll=true&page=1&pagesize=20&_=1566995598255 >> > >> 2019-08-28 14:35:26,639 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-549:ctx-9b77d72a) (logid:093d0fcb) ===START=== >> > >> 137.74.35.102 -- GET >> > >> command=listHosts&response=json&details=min&_=1566995598256 >> > >> 2019-08-28 14:35:26,646 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-549:ctx-9b77d72a ctx-b9a96d1b) (logid:093d0fcb) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:26,654 DEBUG [c.c.a.q.QueryManagerImpl] >> > >> (qtp2114650936-549:ctx-9b77d72a ctx-b9a96d1b) (logid:093d0fcb) >> > >>>Searching >> > >> for hosts>>> >> > >> 2019-08-28 14:35:26,665 DEBUG [c.c.a.q.QueryManagerImpl] >> > >> (qtp2114650936-549:ctx-9b77d72a ctx-b9a96d1b) (logid:093d0fcb) >> > >> >>>Generating Response>>> >> > >> 2019-08-28 14:35:26,672 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-549:ctx-9b77d72a ctx-b9a96d1b) (logid:093d0fcb) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> command=listHosts&response=json&details=min&_=1566995598256 >> > >> 2019-08-28 14:35:29,918 DEBUG [c.c.a.t.Request] >> > >> (StatsCollector-1:ctx-4918121d) (logid:33bb5737) Seq >> > 1-5778962746846479043: >> > >> Received: { Ans: , MgmtId: 205425461278937, via: 1( >> fr-kvm1.r9host.com >> > ), >> > >> Ver: v1, Flags: 10, { GetVolumeStatsAnswer } } >> > >> 2019-08-28 14:35:29,918 DEBUG [c.c.a.m.AgentManagerImpl] >> > >> (StatsCollector-1:ctx-4918121d) (logid:33bb5737) Details from >> executing >> > >> class com.cloud.agent.api.GetVolumeStatsCommand: >> > >> 2019-08-28 14:35:30,179 DEBUG [c.c.s.StatsCollector] >> > >> (StatsCollector-4:ctx-319b4822) (logid:1b54b3f1) AutoScaling Monitor >> is >> > >> running... >> > >> 2019-08-28 14:35:32,307 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-cb8db901) (logid:522feec5) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598257 >> > >> 2019-08-28 14:35:32,316 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-cb8db901 ctx-9388c3db) (logid:522feec5) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:32,335 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-cb8db901 ctx-9388c3db) (logid:522feec5) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566995598257 >> > >> 2019-08-28 14:35:32,519 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-549:ctx-db417a94) (logid:29f44323) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598258 >> > >> 2019-08-28 14:35:32,527 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-549:ctx-db417a94 ctx-b7f6ada6) (logid:29f44323) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:32,575 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-549:ctx-db417a94 ctx-b7f6ada6) (logid:29f44323) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598258 >> > >> 2019-08-28 14:35:34,852 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-14a7b726) (logid:2d7cb685) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:35:34,861 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-14a7b726) (logid:2d7cb685) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:35:37,400 DEBUG [c.c.s.StatsCollector] >> > >> (StatsCollector-5:ctx-cd7b3e15) (logid:764cc325) HostStatsCollector >> is >> > >> running... >> > >> 2019-08-28 14:35:37,456 DEBUG [c.c.a.t.Request] >> > >> (StatsCollector-5:ctx-cd7b3e15) (logid:764cc325) Seq >> > 1-5778962746846479044: >> > >> Received: { Ans: , MgmtId: 205425461278937, via: 1( >> fr-kvm1.r9host.com >> > ), >> > >> Ver: v1, Flags: 10, { GetHostStatsAnswer } } >> > >> 2019-08-28 14:35:38,593 DEBUG [c.c.s.StatsCollector] >> > >> (StatsCollector-3:ctx-c946fd6f) (logid:01b19d42) StorageCollector is >> > >> running... >> > >> 2019-08-28 14:35:38,604 DEBUG [c.c.s.StatsCollector] >> > >> (StatsCollector-3:ctx-c946fd6f) (logid:01b19d42) There is no >> secondary >> > >> storage VM for secondary storage host Secondary1 >> > >> 2019-08-28 14:35:38,607 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] >> > >> (StatsCollector-3:ctx-c946fd6f) (logid:01b19d42) >> > getCommandHostDelegation: >> > >> class com.cloud.agent.api.GetStorageStatsCommand >> > >> 2019-08-28 14:35:38,608 DEBUG [c.c.h.XenServerGuru] >> > >> (StatsCollector-3:ctx-c946fd6f) (logid:01b19d42) We are returning the >> > >> default host to execute commands because the command is not of Copy >> > type. >> > >> 2019-08-28 14:35:38,660 DEBUG [c.c.a.t.Request] >> > >> (StatsCollector-3:ctx-c946fd6f) (logid:01b19d42) Seq >> > 1-5778962746846479045: >> > >> Received: { Ans: , MgmtId: 205425461278937, via: 1( >> fr-kvm1.r9host.com >> > ), >> > >> Ver: v1, Flags: 10, { GetStorageStatsAnswer } } >> > >> 2019-08-28 14:35:41,548 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-f65bf333) (logid:4ec07b47) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598259 >> > >> 2019-08-28 14:35:41,556 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-f65bf333 ctx-10900b36) (logid:4ec07b47) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:41,611 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-f65bf333 ctx-10900b36) (logid:4ec07b47) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598259 >> > >> 2019-08-28 14:35:42,313 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-549:ctx-6b516c08) (logid:4673a9cc) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598260 >> > >> 2019-08-28 14:35:42,321 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-549:ctx-6b516c08 ctx-1a2a1533) (logid:4673a9cc) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:42,377 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-549:ctx-6b516c08 ctx-1a2a1533) (logid:4673a9cc) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598260 >> > >> 2019-08-28 14:35:42,859 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-eaed2e53) (logid:c4337d08) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598261 >> > >> 2019-08-28 14:35:42,867 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-eaed2e53 ctx-99eba050) (logid:c4337d08) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:42,920 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-eaed2e53 ctx-99eba050) (logid:c4337d08) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598261 >> > >> 2019-08-28 14:35:44,845 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >> > >> (HostReservationReleaseChecker:ctx-812a784d) (logid:ece06f8f) >> Checking >> > if >> > >> any host reservation can be released ... >> > >> 2019-08-28 14:35:44,852 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-7c21bde8) (logid:86429daa) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:35:44,852 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-a5613af1) (logid:61a8bf76) Found 0 >> routers to >> > >> update status. >> > >> 2019-08-28 14:35:44,854 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-a5613af1) (logid:61a8bf76) Found 0 VPC >> > networks >> > >> to update Redundant State. >> > >> 2019-08-28 14:35:44,856 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-a5613af1) (logid:61a8bf76) Found 0 >> networks >> > to >> > >> update RvR status. >> > >> 2019-08-28 14:35:44,856 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >> > >> (HostReservationReleaseChecker:ctx-812a784d) (logid:ece06f8f) Cannot >> > >> release reservation, Found 3 VMs Running on host 1 >> > >> 2019-08-28 14:35:44,856 DEBUG [c.c.d.DeploymentPlanningManagerImpl] >> > >> (HostReservationReleaseChecker:ctx-812a784d) (logid:ece06f8f) Done >> > running >> > >> HostReservationReleaseChecker ... >> > >> 2019-08-28 14:35:44,859 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-7c21bde8) (logid:86429daa) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:35:44,887 DEBUG [c.c.a.AlertManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Running Capacity >> Checker >> > >> ... >> > >> 2019-08-28 14:35:44,887 DEBUG [c.c.a.AlertManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) recalculating system >> > >> capacity >> > >> 2019-08-28 14:35:44,887 DEBUG [c.c.a.AlertManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Executing cpu/ram >> > capacity >> > >> update >> > >> 2019-08-28 14:35:44,896 DEBUG [c.c.c.CapacityManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Found 3 VMs on host 1 >> > >> 2019-08-28 14:35:44,904 DEBUG [c.c.c.CapacityManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Found 0 VM, not >> running >> > on >> > >> host 1 >> > >> 2019-08-28 14:35:44,907 DEBUG [c.c.c.CapacityManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) No need to calibrate >> cpu >> > >> capacity, host:1 usedCpuCore: 3 reservedCpuCore: 0 >> > >> 2019-08-28 14:35:44,908 DEBUG [c.c.c.CapacityManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) No need to calibrate >> cpu >> > >> capacity, host:1 usedCpu: 1500 reservedCpu: 0 >> > >> 2019-08-28 14:35:44,908 DEBUG [c.c.c.CapacityManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) No need to calibrate >> > memory >> > >> capacity, host:1 usedMem: 1879048192 reservedMem: 0 >> > >> 2019-08-28 14:35:44,910 DEBUG [c.c.a.AlertManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Done executing >> cpu/ram >> > >> capacity update >> > >> 2019-08-28 14:35:44,910 DEBUG [c.c.a.AlertManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Executing storage >> > capacity >> > >> update >> > >> 2019-08-28 14:35:44,918 DEBUG [c.c.s.StorageManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Found storage pool >> > Primary1 >> > >> of type SharedMountPoint >> > >> 2019-08-28 14:35:44,918 DEBUG [c.c.s.StorageManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Total over >> provisioned >> > >> capacity of the pool Primary1 id: 1 is 984895062016 >> > >> 2019-08-28 14:35:44,920 DEBUG [c.c.s.StorageManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Successfully set >> > Capacity - >> > >> 984895062016 for capacity type - 3 , DataCenterId - 1, HostOrPoolId >> - 1, >> > >> PodId 1 >> > >> 2019-08-28 14:35:44,920 DEBUG [c.c.a.AlertManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Done executing >> storage >> > >> capacity update >> > >> 2019-08-28 14:35:44,920 DEBUG [c.c.a.AlertManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Executing capacity >> > updates >> > >> for public ip and Vlans >> > >> 2019-08-28 14:35:44,938 DEBUG [c.c.a.AlertManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Done capacity updates >> > for >> > >> public ip and Vlans >> > >> 2019-08-28 14:35:44,938 DEBUG [c.c.a.AlertManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Executing capacity >> > updates >> > >> for private ip >> > >> 2019-08-28 14:35:44,944 DEBUG [c.c.a.AlertManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Done executing >> capacity >> > >> updates for private ip >> > >> 2019-08-28 14:35:44,944 DEBUG [c.c.a.AlertManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Done recalculating >> > system >> > >> capacity >> > >> 2019-08-28 14:35:44,982 DEBUG [c.c.a.AlertManagerImpl] >> > >> (CapacityChecker:ctx-305972aa) (logid:95391fc9) Done running Capacity >> > >> Checker ... >> > >> 2019-08-28 14:35:49,922 DEBUG [c.c.h.d.HostDaoImpl] >> > >> (ClusteredAgentManager Timer:ctx-7f369e38) (logid:88e96986) Resetting >> > hosts >> > >> suitable for reconnect >> > >> 2019-08-28 14:35:49,925 DEBUG [c.c.h.d.HostDaoImpl] >> > >> (ClusteredAgentManager Timer:ctx-7f369e38) (logid:88e96986) Completed >> > >> resetting hosts suitable for reconnect >> > >> 2019-08-28 14:35:49,925 DEBUG [c.c.h.d.HostDaoImpl] >> > >> (ClusteredAgentManager Timer:ctx-7f369e38) (logid:88e96986) Acquiring >> > hosts >> > >> for clusters already owned by this management server >> > >> 2019-08-28 14:35:49,926 DEBUG [c.c.h.d.HostDaoImpl] >> > >> (ClusteredAgentManager Timer:ctx-7f369e38) (logid:88e96986) Completed >> > >> acquiring hosts for clusters already owned by this management server >> > >> 2019-08-28 14:35:49,926 DEBUG [c.c.h.d.HostDaoImpl] >> > >> (ClusteredAgentManager Timer:ctx-7f369e38) (logid:88e96986) Acquiring >> > hosts >> > >> for clusters not owned by any management server >> > >> 2019-08-28 14:35:49,926 DEBUG [c.c.h.d.HostDaoImpl] >> > >> (ClusteredAgentManager Timer:ctx-7f369e38) (logid:88e96986) Completed >> > >> acquiring hosts for clusters not owned by any management server >> > >> 2019-08-28 14:35:49,953 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-549:ctx-5e476ef2) (logid:be235fb1) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598262 >> > >> 2019-08-28 14:35:49,961 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-549:ctx-5e476ef2 ctx-6c8ae13e) (logid:be235fb1) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:50,014 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-549:ctx-5e476ef2 ctx-6c8ae13e) (logid:be235fb1) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598262 >> > >> 2019-08-28 14:35:50,633 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-3f36683f) (logid:7cc15823) ===START=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598263 >> > >> 2019-08-28 14:35:50,643 DEBUG [c.c.a.ApiServer] >> > >> (qtp2114650936-535:ctx-3f36683f ctx-cf77b110) (logid:7cc15823) CIDRs >> > from >> > >> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > allowed >> > >> to perform API calls: 0.0.0.0/0,::/0 >> > >> 2019-08-28 14:35:50,698 DEBUG [c.c.a.ApiServlet] >> > >> (qtp2114650936-535:ctx-3f36683f ctx-cf77b110) (logid:7cc15823) >> ===END=== >> > >> 137.74.35.102 -- GET >> > >> >> > >> command=listSystemVms&id=ca6c6e69-2961-43a8-adbc-a03abd9e60d6&response=json&_=1566995598263 >> > >> 2019-08-28 14:35:54,843 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-697625ef) (logid:545f2600) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:35:54,844 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-697625ef) (logid:545f2600) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:36:04,852 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-0a07f4c9) (logid:a32b421b) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:36:04,860 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-0a07f4c9) (logid:a32b421b) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:36:10,577 WARN [o.a.c.f.j.i.AsyncJobMonitor] >> > >> (Timer-0:ctx-6c737611) (logid:5dbd71f1) Task (job-318) has been >> pending >> > for >> > >> 1079 seconds >> > >> 2019-08-28 14:36:10,577 WARN [o.a.c.f.j.i.AsyncJobMonitor] >> > >> (Timer-0:ctx-6c737611) (logid:5dbd71f1) Task (job-320) has been >> pending >> > for >> > >> 477 seconds >> > >> 2019-08-28 14:36:14,855 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-90061a14) (logid:d64d012e) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:36:14,855 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-78190b56) (logid:75dfcd2c) Found 0 >> routers to >> > >> update status. >> > >> 2019-08-28 14:36:14,857 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-78190b56) (logid:75dfcd2c) Found 0 VPC >> > networks >> > >> to update Redundant State. >> > >> 2019-08-28 14:36:14,859 DEBUG >> > >> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >> (RouterStatusMonitor-1:ctx-78190b56) (logid:75dfcd2c) Found 0 >> networks >> > to >> > >> update RvR status. >> > >> 2019-08-28 14:36:14,864 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-90061a14) (logid:d64d012e) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:36:24,850 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-2f779805) (logid:45a1c5bd) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:36:24,859 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-2f779805) (logid:45a1c5bd) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:36:24,972 DEBUG [c.c.a.m.AgentManagerImpl] >> > >> (AgentManager-Handler-7:null) (logid:) Ping from 1( >> fr-kvm1.r9host.com) >> > >> 2019-08-28 14:36:24,972 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-7:null) (logid:) Process host VM state report >> from >> > >> ping process. host: 1 >> > >> 2019-08-28 14:36:24,973 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-7:null) (logid:) Process VM state report. >> host: 1, >> > >> number of records in report: 1 >> > >> 2019-08-28 14:36:24,973 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-7:null) (logid:) VM state report. host: 1, vm >> id: >> > >> 103, power state: PowerOn >> > >> 2019-08-28 14:36:24,975 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-7:null) (logid:) VM state report is updated. >> > host: 1, >> > >> vm id: 103, power state: PowerOn >> > >> 2019-08-28 14:36:24,976 INFO [c.c.v.VirtualMachineManagerImpl] >> > >> (AgentManager-Handler-7:null) (logid:) There is pending job or HA >> tasks >> > >> working on the VM. vm id: 103, postpone power-change report by >> resetting >> > >> power-change counters >> > >> 2019-08-28 14:36:24,978 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-7:null) (logid:) Run missing VM report. current >> > time: >> > >> 1566995784978 >> > >> 2019-08-28 14:36:24,979 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-7:null) (logid:) Detected missing VM. host: 1, >> vm >> > id: >> > >> 101, power state: PowerReportMissing, last state update: >> 1566995664000 >> > >> 2019-08-28 14:36:24,979 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-7:null) (logid:) vm id: 101 - time since last >> > state >> > >> update(120978ms) has passed graceful period >> > >> 2019-08-28 14:36:24,981 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-7:null) (logid:) VM state report is updated. >> > host: 1, >> > >> vm id: 101, power state: PowerReportMissing >> > >> 2019-08-28 14:36:24,981 INFO [c.c.v.VirtualMachineManagerImpl] >> > >> (AgentManager-Handler-7:null) (logid:) There is pending job or HA >> tasks >> > >> working on the VM. vm id: 101, postpone power-change report by >> resetting >> > >> power-change counters >> > >> 2019-08-28 14:36:24,983 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-7:null) (logid:) Detected missing VM. host: 1, >> vm >> > id: >> > >> 102, power state: PowerReportMissing, last state update: >> 1566995664000 >> > >> 2019-08-28 14:36:24,983 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-7:null) (logid:) vm id: 102 - time since last >> > state >> > >> update(120978ms) has passed graceful period >> > >> 2019-08-28 14:36:24,984 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-7:null) (logid:) VM state report is updated. >> > host: 1, >> > >> vm id: 102, power state: PowerReportMissing >> > >> 2019-08-28 14:36:24,984 INFO [c.c.v.VirtualMachineManagerImpl] >> > >> (AgentManager-Handler-7:null) (logid:) There is pending job or HA >> tasks >> > >> working on the VM. vm id: 102, postpone power-change report by >> resetting >> > >> power-change counters >> > >> 2019-08-28 14:36:24,986 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >> (AgentManager-Handler-7:null) (logid:) Done with process of VM state >> > >> report. host: 1 >> > >> 2019-08-28 14:36:30,181 DEBUG [c.c.s.StatsCollector] >> > >> (StatsCollector-6:ctx-9c8e3bed) (logid:9058cad8) AutoScaling Monitor >> is >> > >> running... >> > >> 2019-08-28 14:36:34,848 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-a4ba96bd) (logid:be688b96) Begin cleanup >> > >> expired async-jobs >> > >> 2019-08-28 14:36:34,849 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >> (AsyncJobMgr-Heartbeat-1:ctx-a4ba96bd) (logid:be688b96) End cleanup >> > expired >> > >> async-jobs >> > >> 2019-08-28 14:36:37,458 DEBUG [c.c.s.StatsCollector] >> > >> (StatsCollector-4:ctx-71c1f2b0) (logid:94e16990) HostStatsCollector >> is >> > >> running... >> > >> 2019-08-28 14:36:37,515 DEBUG [c.c.a.t.Request] >> > >> (StatsCollector-4:ctx-71c1f2b0) (logid:94e16990) Seq >> > 1-5778962746846479046: >> > >> Received: { Ans: , MgmtId: 205425461278937, via: 1( >> fr-kvm1.r9host.com >> > ), >> > >> Ver: v1, Flags: 10, { GetHostStatsAnswer } } >> > >> 2019-08-28 14:36:38,661 DEBUG [c.c.s.StatsCollector] >> > >> (StatsCollector-2:ctx-3dfe46e8) (logid:a3085aca) StorageCollector is >> > >> running... >> > >> 2019-08-28 14:36:38,671 DEBUG [c.c.s.StatsCollector] >> > >> (StatsCollector-2:ctx-3dfe46e8) (logid:a3085aca) There is no >> secondary >> > >> storage VM for secondary storage host Secondary1 >> > >> 2019-08-28 14:36:38,675 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] >> > >> (StatsCollector-2:ctx-3dfe46e8) (logid:a3085aca) >> > getCommandHostDelegation: >> > >> class com.cloud.agent.api.GetStorageStatsCommand >> > >> 2019-08-28 14:36:38,675 DEBUG [c.c.h.XenServerGuru] >> > >> (StatsCollector-2:ctx-3dfe46e8) (logid:a3085aca) We are returning the >> > >> default host to execute commands because the command is not of Copy >> > type. >> > >> 2019-08-28 14:36:38,729 DEBUG [c.c.a.t.Request] >> > >> (StatsCollector-2:ctx-3dfe46e8) (logid:a3085aca) Seq >> > 1-5778962746846479047: >> > >> Received: { Ans: , MgmtId: 205425461278937, via: 1( >> fr-kvm1.r9host.com >> > ), >> > >> Ver: v1, Flags: 10, { GetStorageStatsAnswer } } >> > >> >> > >> On Wed, Aug 28, 2019 at 4:04 PM Paul Angus <[email protected] >> > >> > >> wrote: >> > >> >> > >>> The error is here Fariborz, >> > >>> >> > >>> 2019-08-28 13:23:10,989 INFO [c.c.v.VirtualMachineManagerImpl] >> > >>> (Work-Job-Executor-138:ctx-c18389dc job-76/job-220 ctx-bb1ddfae) >> > >>> (logid:e3068c13) Unable to start VM on Host[-1-Routing] due to >> Failed >> > to >> > >>> create vnet 100: device eth1.100 is already a member of a bridge; >> can't >> > >>> enslave it to bridge breth1-100.Failed to add vlan: eth1.100 to >> > >>> breth1-100 >> > >>> >> > >>> you're already using a VLAN that you've also asked CloudStack to >> use. >> > >>> >> > >>> >> > >>> >> > >>> [email protected] >> > >>> www.shapeblue.com >> > >>> Amadeus House, Floral Street, London WC2E 9DPUK >> > >>> @shapeblue >> > >>> >> > >>> >> > >>> >> > >>> >> > >>> -----Original Message----- >> > >>> From: Fariborz Navidan <[email protected]> >> > >>> Sent: 28 August 2019 12:29 >> > >>> To: [email protected] >> > >>> Subject: Unable to start System VMs >> > >>> >> > >>> Hello, >> > >>> >> > >>> New ACS management is unable to start System VMs. Below are logs. >> ACS >> > is >> > >>> still poor in error handling and reporting. It should be able to >> retyrn >> > >>> clear error messages inside UI. >> > >>> >> > >>> 2019-08-28 13:21:54,843 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >>> (AsyncJobMgr-Heartbeat-1:ctx-0663ec9c) (logid:46769467) Begin >> cleanup >> > >>> expired async-jobs >> > >>> 2019-08-28 13:21:54,844 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >>> (AsyncJobMgr-Heartbeat-1:ctx-0663ec9c) (logid:46769467) End cleanup >> > >>> expired >> > >>> async-jobs >> > >>> 2019-08-28 13:22:04,852 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >>> (AsyncJobMgr-Heartbeat-1:ctx-da64de3b) (logid:13fbf230) Begin >> cleanup >> > >>> expired async-jobs >> > >>> 2019-08-28 13:22:04,860 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >>> (AsyncJobMgr-Heartbeat-1:ctx-da64de3b) (logid:13fbf230) End cleanup >> > >>> expired >> > >>> async-jobs >> > >>> 2019-08-28 13:22:09,812 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-267:ctx-42c40f78) (logid:26b61170) ===START=== >> > >>> 137.74.35.102 -- GET >> > >>> command=listZones&page=1&pagesize=20&response=json&_=1566988128964 >> > >>> 2019-08-28 13:22:09,820 DEBUG [c.c.a.ApiServer] >> > >>> (qtp2114650936-267:ctx-42c40f78 ctx-f3a5c61e) (logid:26b61170) CIDRs >> > from >> > >>> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > >>> allowed >> > >>> to perform API calls: 0.0.0.0/0,::/0 >> > >>> 2019-08-28 13:22:09,839 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-267:ctx-42c40f78 ctx-f3a5c61e) (logid:26b61170) >> > ===END=== >> > >>> 137.74.35.102 -- GET >> > >>> command=listZones&page=1&pagesize=20&response=json&_=1566988128964 >> > >>> 2019-08-28 13:22:12,086 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-14:ctx-11b41222) (logid:34e5eff5) ===START=== >> > >>> 137.74.35.102 >> > >>> -- GET >> > >>> >> > >>> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566988128965 >> > >>> 2019-08-28 13:22:12,088 DEBUG [c.c.a.ApiServer] >> > >>> (qtp2114650936-14:ctx-11b41222 ctx-3aec20c6) (logid:34e5eff5) CIDRs >> > from >> > >>> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > >>> allowed >> > >>> to perform API calls: 0.0.0.0/0,::/0 >> > >>> 2019-08-28 13:22:12,092 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-14:ctx-11b41222 ctx-3aec20c6) (logid:34e5eff5) >> ===END=== >> > >>> 137.74.35.102 -- GET >> > >>> >> > >>> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566988128965 >> > >>> 2019-08-28 13:22:12,222 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-267:ctx-dcd82c6d) (logid:181e3933) ===START=== >> > >>> 137.74.35.102 -- GET >> > >>> >> > >>> >> > >> command=listDedicatedZones&response=json&zoneid=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566988128966 >> > >>> 2019-08-28 13:22:12,223 DEBUG [c.c.a.ApiServer] >> > >>> (qtp2114650936-267:ctx-dcd82c6d ctx-053bddc4) (logid:181e3933) CIDRs >> > from >> > >>> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > >>> allowed >> > >>> to perform API calls: 0.0.0.0/0,::/0 >> > >>> 2019-08-28 13:22:12,225 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-267:ctx-dcd82c6d ctx-053bddc4) (logid:181e3933) >> > ===END=== >> > >>> 137.74.35.102 -- GET >> > >>> >> > >>> >> > >> command=listDedicatedZones&response=json&zoneid=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566988128966 >> > >>> 2019-08-28 13:22:12,351 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-14:ctx-a671b130) (logid:6972e719) ===START=== >> > >>> 137.74.35.102 >> > >>> -- GET >> > command=listApis&response=json&name=listVmwareDcs&_=1566988128967 >> > >>> 2019-08-28 13:22:12,352 DEBUG [c.c.a.ApiServer] >> > >>> (qtp2114650936-14:ctx-a671b130 ctx-32f83603) (logid:6972e719) CIDRs >> > from >> > >>> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > >>> allowed >> > >>> to perform API calls: 0.0.0.0/0,::/0 >> > >>> 2019-08-28 13:22:12,353 INFO [c.c.a.ApiServer] >> > >>> (qtp2114650936-14:ctx-a671b130 ctx-32f83603) (logid:6972e719) Api >> > >>> Discovery >> > >>> plugin was unable to find an api by that name or process any apis >> > >>> 2019-08-28 13:22:12,354 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-14:ctx-a671b130 ctx-32f83603) (logid:6972e719) >> ===END=== >> > >>> 137.74.35.102 -- GET >> > >>> command=listApis&response=json&name=listVmwareDcs&_=1566988128967 >> > >>> 2019-08-28 13:22:14,852 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >>> (AsyncJobMgr-Heartbeat-1:ctx-cd7ab4f4) (logid:83e44417) Begin >> cleanup >> > >>> expired async-jobs >> > >>> 2019-08-28 13:22:14,852 DEBUG >> > >>> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >>> (RouterStatusMonitor-1:ctx-99c22813) (logid:97ed8f60) Found 0 >> routers >> > to >> > >>> update status. >> > >>> 2019-08-28 13:22:14,854 DEBUG >> > >>> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >>> (RouterStatusMonitor-1:ctx-99c22813) (logid:97ed8f60) Found 0 VPC >> > >>> networks >> > >>> to update Redundant State. >> > >>> 2019-08-28 13:22:14,856 DEBUG >> > >>> [c.c.n.r.VirtualNetworkApplianceManagerImpl] >> > >>> (RouterStatusMonitor-1:ctx-99c22813) (logid:97ed8f60) Found 0 >> networks >> > to >> > >>> update RvR status. >> > >>> 2019-08-28 13:22:14,860 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >>> (AsyncJobMgr-Heartbeat-1:ctx-cd7ab4f4) (logid:83e44417) End cleanup >> > >>> expired >> > >>> async-jobs >> > >>> 2019-08-28 13:22:15,564 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-267:ctx-95484c01) (logid:1697b0f8) ===START=== >> > >>> 137.74.35.102 -- GET >> > >>> >> > >>> >> > >> command=updateZone&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&allocationstate=Enabled&response=json&_=1566988128968 >> > >>> 2019-08-28 13:22:15,572 DEBUG [c.c.a.ApiServer] >> > >>> (qtp2114650936-267:ctx-95484c01 ctx-3b6e52cd) (logid:1697b0f8) CIDRs >> > from >> > >>> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > >>> allowed >> > >>> to perform API calls: 0.0.0.0/0,::/0 >> > >>> 2019-08-28 13:22:15,592 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-267:ctx-95484c01 ctx-3b6e52cd) (logid:1697b0f8) >> > ===END=== >> > >>> 137.74.35.102 -- GET >> > >>> >> > >>> >> > >> command=updateZone&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&allocationstate=Enabled&response=json&_=1566988128968 >> > >>> 2019-08-28 13:22:18,768 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-14:ctx-24de6e9c) (logid:dd464d41) ===START=== >> > >>> 137.74.35.102 >> > >>> -- GET >> > >>> >> > >>> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566988128969 >> > >>> 2019-08-28 13:22:18,776 DEBUG [c.c.a.ApiServer] >> > >>> (qtp2114650936-14:ctx-24de6e9c ctx-b0d52d8f) (logid:dd464d41) CIDRs >> > from >> > >>> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > >>> allowed >> > >>> to perform API calls: 0.0.0.0/0,::/0 >> > >>> 2019-08-28 13:22:18,794 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-14:ctx-24de6e9c ctx-b0d52d8f) (logid:dd464d41) >> ===END=== >> > >>> 137.74.35.102 -- GET >> > >>> >> > >>> >> > >> command=listZones&response=json&id=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566988128969 >> > >>> 2019-08-28 13:22:18,969 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-267:ctx-02de057f) (logid:7df7fd05) ===START=== >> > >>> 137.74.35.102 -- GET >> > >>> >> > >>> >> > >> command=listDedicatedZones&response=json&zoneid=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566988128970 >> > >>> 2019-08-28 13:22:18,976 DEBUG [c.c.a.ApiServer] >> > >>> (qtp2114650936-267:ctx-02de057f ctx-a72acff2) (logid:7df7fd05) CIDRs >> > from >> > >>> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > >>> allowed >> > >>> to perform API calls: 0.0.0.0/0,::/0 >> > >>> 2019-08-28 13:22:18,987 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-267:ctx-02de057f ctx-a72acff2) (logid:7df7fd05) >> > ===END=== >> > >>> 137.74.35.102 -- GET >> > >>> >> > >>> >> > >> command=listDedicatedZones&response=json&zoneid=57a0f2fa-e111-486d-b8c7-e93d640d45d3&_=1566988128970 >> > >>> 2019-08-28 13:22:19,115 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-14:ctx-d124351a) (logid:ea051db5) ===START=== >> > >>> 137.74.35.102 >> > >>> -- GET >> > command=listApis&response=json&name=listVmwareDcs&_=1566988128971 >> > >>> 2019-08-28 13:22:19,121 DEBUG [c.c.a.ApiServer] >> > >>> (qtp2114650936-14:ctx-d124351a ctx-a706dba7) (logid:ea051db5) CIDRs >> > from >> > >>> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > >>> allowed >> > >>> to perform API calls: 0.0.0.0/0,::/0 >> > >>> 2019-08-28 13:22:19,129 INFO [c.c.a.ApiServer] >> > >>> (qtp2114650936-14:ctx-d124351a ctx-a706dba7) (logid:ea051db5) Api >> > >>> Discovery >> > >>> plugin was unable to find an api by that name or process any apis >> > >>> 2019-08-28 13:22:19,129 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-14:ctx-d124351a ctx-a706dba7) (logid:ea051db5) >> ===END=== >> > >>> 137.74.35.102 -- GET >> > >>> command=listApis&response=json&name=listVmwareDcs&_=1566988128971 >> > >>> 2019-08-28 13:22:19,910 DEBUG [c.c.h.d.HostDaoImpl] >> > >>> (ClusteredAgentManager >> > >>> Timer:ctx-5027d656) (logid:48df0324) Resetting hosts suitable for >> > >>> reconnect >> > >>> 2019-08-28 13:22:19,912 DEBUG [c.c.h.d.HostDaoImpl] >> > >>> (ClusteredAgentManager >> > >>> Timer:ctx-5027d656) (logid:48df0324) Completed resetting hosts >> suitable >> > >>> for >> > >>> reconnect >> > >>> 2019-08-28 13:22:19,912 DEBUG [c.c.h.d.HostDaoImpl] >> > >>> (ClusteredAgentManager >> > >>> Timer:ctx-5027d656) (logid:48df0324) Acquiring hosts for clusters >> > already >> > >>> owned by this management server >> > >>> 2019-08-28 13:22:19,913 DEBUG [c.c.h.d.HostDaoImpl] >> > >>> (ClusteredAgentManager >> > >>> Timer:ctx-5027d656) (logid:48df0324) Completed acquiring hosts for >> > >>> clusters >> > >>> already owned by this management server >> > >>> 2019-08-28 13:22:19,913 DEBUG [c.c.h.d.HostDaoImpl] >> > >>> (ClusteredAgentManager >> > >>> Timer:ctx-5027d656) (logid:48df0324) Acquiring hosts for clusters >> not >> > >>> owned >> > >>> by any management server >> > >>> 2019-08-28 13:22:19,914 DEBUG [c.c.h.d.HostDaoImpl] >> > >>> (ClusteredAgentManager >> > >>> Timer:ctx-5027d656) (logid:48df0324) Completed acquiring hosts for >> > >>> clusters >> > >>> not owned by any management server >> > >>> 2019-08-28 13:22:22,777 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-267:ctx-8153bc20) (logid:32dfe4ef) ===START=== >> > >>> 137.74.35.102 -- GET >> > >>> command=listInfrastructure&response=json&_=1566988128972 >> > >>> 2019-08-28 13:22:22,785 DEBUG [c.c.a.ApiServer] >> > >>> (qtp2114650936-267:ctx-8153bc20 ctx-16497adb) (logid:32dfe4ef) CIDRs >> > from >> > >>> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > >>> allowed >> > >>> to perform API calls: 0.0.0.0/0,::/0 >> > >>> 2019-08-28 13:22:22,804 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-267:ctx-8153bc20 ctx-16497adb) (logid:32dfe4ef) >> > ===END=== >> > >>> 137.74.35.102 -- GET >> > >>> command=listInfrastructure&response=json&_=1566988128972 >> > >>> 2019-08-28 13:22:24,852 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >>> (AsyncJobMgr-Heartbeat-1:ctx-9a1a58c9) (logid:9795c691) Begin >> cleanup >> > >>> expired async-jobs >> > >>> 2019-08-28 13:22:24,860 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >>> (AsyncJobMgr-Heartbeat-1:ctx-9a1a58c9) (logid:9795c691) End cleanup >> > >>> expired >> > >>> async-jobs >> > >>> 2019-08-28 13:22:24,957 DEBUG [c.c.a.m.AgentManagerImpl] >> > >>> (AgentManager-Handler-3:null) (logid:) Ping from 1( >> fr-kvm1.r9host.com) >> > >>> 2019-08-28 13:22:24,957 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >>> (AgentManager-Handler-3:null) (logid:) Process host VM state report >> > from >> > >>> ping process. host: 1 >> > >>> 2019-08-28 13:22:24,957 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >>> (AgentManager-Handler-3:null) (logid:) Process VM state report. >> host: >> > 1, >> > >>> number of records in report: 0 >> > >>> 2019-08-28 13:22:24,957 DEBUG >> [c.c.v.VirtualMachinePowerStateSyncImpl] >> > >>> (AgentManager-Handler-3:null) (logid:) Done with process of VM state >> > >>> report. host: 1 >> > >>> 2019-08-28 13:22:29,995 DEBUG [c.c.s.StatsCollector] >> > >>> (StatsCollector-4:ctx-b6613c33) (logid:8dc05d71) AutoScaling >> Monitor is >> > >>> running... >> > >>> 2019-08-28 13:22:30,614 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-14:ctx-ee9f429f) (logid:2467c8a0) ===START=== >> > >>> 137.74.35.102 >> > >>> -- GET command=listInfrastructure&response=json&_=1566988128973 >> > >>> 2019-08-28 13:22:30,622 DEBUG [c.c.a.ApiServer] >> > >>> (qtp2114650936-14:ctx-ee9f429f ctx-474af31a) (logid:2467c8a0) CIDRs >> > from >> > >>> which account 'Acct[193f9b2f-c974-11e9-b808-d05099d38681-admin]' is >> > >>> allowed >> > >>> to perform API calls: 0.0.0.0/0,::/0 >> > >>> 2019-08-28 13:22:30,641 DEBUG [c.c.a.ApiServlet] >> > >>> (qtp2114650936-14:ctx-ee9f429f ctx-474af31a) (logid:2467c8a0) >> ===END=== >> > >>> 137.74.35.102 -- GET >> > >>> command=listInfrastructure&response=json&_=1566988128973 >> > >>> 2019-08-28 13:22:33,168 DEBUG [c.c.s.StatsCollector] >> > >>> (StatsCollector-5:ctx-8ca5de0e) (logid:1e266084) HostStatsCollector >> is >> > >>> running... >> > >>> 2019-08-28 13:22:33,225 DEBUG [c.c.a.t.Request] >> > >>> (StatsCollector-5:ctx-8ca5de0e) (logid:1e266084) Seq >> > >>> 1-5778962746846478713: >> > >>> Received: { Ans: , MgmtId: 205425461278937, via: 1( >> fr-kvm1.r9host.com >> > ), >> > >>> Ver: v1, Flags: 10, { GetHostStatsAnswer } } >> > >>> 2019-08-28 13:22:33,665 DEBUG [c.c.s.StatsCollector] >> > >>> (StatsCollector-3:ctx-07390103) (logid:8f414a20) StorageCollector is >> > >>> running... >> > >>> 2019-08-28 13:22:33,676 DEBUG [c.c.s.StatsCollector] >> > >>> (StatsCollector-3:ctx-07390103) (logid:8f414a20) There is no >> secondary >> > >>> storage VM for secondary storage host Secondary1 >> > >>> 2019-08-28 13:22:33,680 DEBUG [c.c.h.o.r.Ovm3HypervisorGuru] >> > >>> (StatsCollector-3:ctx-07390103) (logid:8f414a20) >> > >>> getCommandHostDelegation: >> > >>> class com.cloud.agent.api.GetStorageStatsCommand >> > >>> 2019-08-28 13:22:33,680 DEBUG [c.c.h.XenServerGuru] >> > >>> (StatsCollector-3:ctx-07390103) (logid:8f414a20) We are returning >> the >> > >>> default host to execute commands because the command is not of Copy >> > type. >> > >>> 2019-08-28 13:22:33,734 DEBUG [c.c.a.t.Request] >> > >>> (StatsCollector-3:ctx-07390103) (logid:8f414a20) Seq >> > >>> 1-5778962746846478714: >> > >>> Received: { Ans: , MgmtId: 205425461278937, via: 1( >> fr-kvm1.r9host.com >> > ), >> > >>> Ver: v1, Flags: 10, { GetStorageStatsAnswer } } >> > >>> 2019-08-28 13:22:34,852 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >>> (AsyncJobMgr-Heartbeat-1:ctx-dd9dc584) (logid:435aef2a) Begin >> cleanup >> > >>> expired async-jobs >> > >>> 2019-08-28 13:22:34,860 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] >> > >>> (AsyncJobMgr-Heartbeat-1:ctx-dd9dc584) (logid:435aef2a) End cleanup >> > >>> expired >> > >>> async-jobs >> > >>> 2019-08-28 13:22:40,559 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] >> > >>> (secstorage-1:ctx-3a6545e7) (logid:5fd568bf) Zone 1 is ready to >> launch >> > >>> secondary storage VM >> > >>> 2019-08-28 13:22:40,562 INFO >> > >>> [o.a.c.s.PremiumSecondaryStorageManagerImpl] >> > >>> (secstorage-1:ctx-3a6545e7) (logid:5fd568bf) No running secondary >> > storage >> > >>> vms found in datacenter id=1, starting one >> > >>> 2019-08-28 13:22:40,567 INFO [o.a.c.s.SecondaryStorageManagerImpl] >> > >>> (secstorage-1:ctx-3a6545e7) (logid:5fd568bf) No stopped secondary >> > storage >> > >>> vm is available, need to allocate a new secondary storage vm >> > >>> 2019-08-28 13:22:40,569 DEBUG [o.a.c.s.SecondaryStorageManagerImpl] >> > >>> (secstorage-1:ctx-3a6545e7) (logid:5fd568bf) Assign secondary >> storage >> > vm >> > >>> from a newly started instance for request from data center : 1 >> > >>> 2019-08-28 13:22:40,584 DEBUG [o.a.c.e.o.NetworkOrchestrator] >> > >>> (secstorage-1:ctx-3a6545e7) (logid:5fd568bf) Found existing network >> > >>> configuration for offering [Network Offering >> > >>> [6-Guest-DefaultSharedNetworkOfferingWithSGService]: >> Ntwk[203|Guest|6] >> > >>> 2019-08-28 13:22:40,584 DEBUG [o.a.c.e.o.NetworkOrchestrator] >> > >>> (secstorage-1:ctx-3a6545e7) (logid:5fd568bf) Releasing lock for >> > >>> Acct[193f925a-c974-11e9-b808-d05099d38681-system] >> > >>> 2019-08-28 13:22:40,591 DEBUG [o.a.c.e.o.NetworkOrchestrator] >> > >>> (secstorage-1:ctx-3a6545e7) (logid:5fd568bf) Found existing network >> > >>> configuration for offering [Network Offering >> > >>> [3-Control-System-Control-Network]: Ntwk[201|Control|3] >> > >>> 2019-08-28 13:22:40,591 DEBUG [o.a.c.e.o.NetworkOrchestrator] >> > >>> (secstorage-1:ctx-3a6545e7) (logid:5fd568bf) Releasing lock for >> > >>> Acct[193f925a-c974-11e9-b808-d05099d38681-system] >> > >>> 2019-08-28 13:22:40,599 DEBUG [o.a.c.e.o.NetworkOrchestrator] >> > >>> (secstorage-1:ctx-3a6545e7) (logid:5fd568bf) Found existing network >> > >>> configuration for offering [Network Offering >> > >>> [2-Management-System-Management-Network]: Ntwk[200|Management|2] >> > >>> 2019-08-28 13:22:40,599 DEBUG [o.a.c.e.o.NetworkOrchestrator] >> > >>> (secstorage-1:ctx-3a6545e7) (logid:5fd568bf) Releasing lock for >> > >>> Acct[193f925a-c974-11e9-b808-d05099d38681-system] >> > >>> 2019-08-28 13:22:40,614 DEBUG [c.c.c.ConsoleProxyManagerImpl] >> > >>> (consoleproxy-1:ctx-71d4f124) (logid:84bfc356) Zone 1 is ready to >> > launch >> > >> >
