cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Fariborz Navidan <mdvlinqu...@gmail.com>
Subject Re: Unable to start System VMs
Date Wed, 28 Aug 2019 17:01:18 GMT
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 <andrija.panic@gmail.com>
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 <mdvlinquest@gmail.com>
> wrote:
>
> > Hi,
> >
> > Also this is agent log
> >
> > On Wed, Aug 28, 2019 at 6:41 PM Fariborz Navidan <mdvlinquest@gmail.com>
> > wrote:
> >
> > > Any idea?
> > >
> > > On Wed, Aug 28, 2019 at 5:09 PM Fariborz Navidan <
> mdvlinquest@gmail.com>
> > > 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 <paul.angus@shapeblue.com>
> > >> 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.
> > >>>
> > >>>
> > >>>
> > >>> paul.angus@shapeblue.com
> > >>> www.shapeblue.com
> > >>> Amadeus House, Floral Street, London  WC2E 9DPUK
> > >>> @shapeblue
> > >>>
> > >>>
> > >>>
> > >>>
> > >>> -----Original Message-----
> > >>> From: Fariborz Navidan <mdvlinquest@gmail.com>
> > >>> Sent: 28 August 2019 12:29
> > >>> To: users@cloudstack.apache.org
> > >>> 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
> >
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message