cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Bret Mette <bret.me...@dbihosting.com>
Subject Re: 4.3 test deployment - systemVM's not coming up
Date Fri, 13 Jun 2014 19:45:37 GMT
Looks like your network setup may not be correct:

XenServer due to:Unable to find the default physical network with traffic=Storage in the specified zone id

I believe CS would need that fixed before it could deploy any VM, including system VMs.


- Bret

> On Jun 13, 2014, at 12:32 PM, John Muckley <j.muckley@databax.com> wrote:
> 
> Hi all,
> 
> I’ve just run through a 4.3 deployment with iscsi primary storage and nfs secondary storage.
> Followed the installation guide to the letter as I’ve not done a 4.3 install before.
> 
> Everything looked good and it all installed and set up fine etc, however I have no systemVMs online.
> No console proxy, no SSVM and no virtual router.
> 
> I’ve seeded the template and, as I’m using a separate NFS server for secondary storage, I unmounted /mnt/secondary.
> I’ve also set up the global settings to make sure that secstorage.allowed.internal.sites was set.
> 
> I can’t see any actual errors in management-server.log to indicate what the problem is.
> 
> Has anyone got any thoughts?
> 
> Management-server.log….
> 
> 
> 
> 2014-06-13 19:24:54,980 DEBUG [c.c.a.ClusterAlertAdapter] (Cluster-Notification-1:ctx-5d3a6e3e) Management server node 192.168.16.221 is up, send alert
> 2014-06-13 19:24:54,983 WARN  [o.a.c.alerts] (Cluster-Notification-1:ctx-5d3a6e3e)  alertType:: 14 // dataCenterId:: 0 // podId:: 0 // clusterId:: null // message:: Management server node 192.168.16.221 is up
> 2014-06-13 19:24:55,132 WARN  [c.c.c.ClusterManagerImpl] (Cluster-Notification-1:ctx-5d3a6e3e) Notifying management server join event took 154 ms
> 2014-06-13 19:24:55,652 ERROR [c.c.a.AlertManagerImpl] (Email-Alerts-Sender-1:null)  Failed to send email alert javax.mail.MessagingException: Exception reading response (javax.net.ssl.SSLException: Unrecognized SSL message, plaintext connection?)
> 2014-06-13 19:24:57,379 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-28603a4d) Resetting hosts suitable for reconnect
> 2014-06-13 19:24:57,389 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-28603a4d) Completed resetting hosts suitable for reconnect
> 2014-06-13 19:24:57,389 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-28603a4d) Acquiring hosts for clusters already owned by this management server
> 2014-06-13 19:24:57,390 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-28603a4d) Completed acquiring hosts for clusters already owned by this management server
> 2014-06-13 19:24:57,390 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-28603a4d) Acquiring hosts for clusters not owned by any management server
> 2014-06-13 19:24:57,412 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-28603a4d) Completed acquiring hosts for clusters not owned by any management server
> 2014-06-13 19:24:57,442 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (ClusteredAgentManager Timer:ctx-28603a4d) Found 2 unmanaged direct hosts, processing connect for them...
> 2014-06-13 19:24:57,450 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (ClusteredAgentManager Timer:ctx-28603a4d) Loading directly connected host 1(CP-HOST-02)
> 2014-06-13 19:24:57,651 DEBUG [c.c.n.NetworkModelImpl] (ClusteredAgentManager Timer:ctx-28603a4d) Failed to retrive the default label for storage traffic:zone: 1 hypervisor: XenServer due to:Unable to find the default physical network with traffic=Storage in the specified zone id
> 2014-06-13 19:24:57,669 DEBUG [c.c.h.x.r.CitrixResourceBase] (ClusteredAgentManager Timer:ctx-28603a4d) XAPI time out after 600 seconds
> 2014-06-13 19:24:58,487 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (ClusteredAgentManager Timer:ctx-28603a4d) Loading directly connected host 2(CP-HOST-01)
> 2014-06-13 19:24:58,517 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Simulating start for resource 2cdc3124-6002-4ee5-8460-37d521fe0a7c id 1
> 2014-06-13 19:24:58,524 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Creating agent for host 1
> 2014-06-13 19:24:58,568 DEBUG [c.c.n.NetworkModelImpl] (ClusteredAgentManager Timer:ctx-28603a4d) Failed to retrive the default label for storage traffic:zone: 1 hypervisor: XenServer due to:Unable to find the default physical network with traffic=Storage in the specified zone id
> 2014-06-13 19:24:58,583 DEBUG [c.c.a.ApiServlet] (catalina-exec-24:ctx-be4d0f55) ===START===  192.168.16.45 -- POST
> 2014-06-13 19:24:58,605 DEBUG [c.c.u.AccountManagerImpl] (catalina-exec-24:ctx-be4d0f55) Attempting to log in user: dbxc in domain 1
> 2014-06-13 19:24:58,605 DEBUG [c.c.s.a.SHA256SaltedUserAuthenticator] (catalina-exec-24:ctx-be4d0f55) Retrieving user: dbxc
> 2014-06-13 19:24:58,626 DEBUG [c.c.h.x.r.CitrixResourceBase] (ClusteredAgentManager Timer:ctx-28603a4d) XAPI time out after 600 seconds
> 2014-06-13 19:24:58,671 DEBUG [c.c.u.AccountManagerImpl] (catalina-exec-24:ctx-be4d0f55) User: dbxc in domain 1 has successfully logged in
> 2014-06-13 19:24:58,703 INFO  [c.c.a.ApiServer] (catalina-exec-24:ctx-be4d0f55) Current user logged in under Etc/GMT timezone
> 2014-06-13 19:24:58,703 INFO  [c.c.a.ApiServer] (catalina-exec-24:ctx-be4d0f55) Timezone offset from UTC is: 0.0
> 2014-06-13 19:24:58,797 DEBUG [c.c.h.x.r.XenServerConnectionPool] (AgentTaskPool-1:ctx-0b484d87) Add master connection through 192.168.16.216 for pool(null)
> 2014-06-13 19:24:58,806 DEBUG [c.c.a.ApiServlet] (catalina-exec-24:ctx-be4d0f55) ===END===  192.168.16.45 -- POST
> 2014-06-13 19:24:58,836 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-9fa9ca8f) ===START===  192.168.16.45 -- GET  command=listCapabilities&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687290625
> 2014-06-13 19:24:58,844 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Simulating start for resource 012ffb72-a098-41c8-8df4-e5682e074c38 id 2
> 2014-06-13 19:24:58,844 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Creating agent for host 2
> 2014-06-13 19:24:59,007 DEBUG [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-1:ctx-0b484d87) Management network is on pif=5ca2b358-73ce-29e4-f01a-be92f8144083
> 2014-06-13 19:24:59,070 DEBUG [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-2:ctx-7fb2f798) Management network is on pif=fd46a646-5c9f-c1e3-2ce9-998db7f63acd
> 2014-06-13 19:24:59,097 DEBUG [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-1:ctx-0b484d87) Found a network called Management on host=192.168.16.215;  Network=fcfd0c0d-70f5-511a-a246-b849b600e7bf; pif=5ca2b358-73ce-29e4-f01a-be92f8144083
> 2014-06-13 19:24:59,097 INFO  [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-1:ctx-0b484d87) Private Network is Management for host 192.168.16.215
> 2014-06-13 19:24:59,097 INFO  [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-1:ctx-0b484d87) Guest Network is Management for host 192.168.16.215
> 2014-06-13 19:24:59,098 INFO  [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-1:ctx-0b484d87) Public Network is Management for host 192.168.16.215
> 2014-06-13 19:24:59,112 DEBUG [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-2:ctx-7fb2f798) Found a network called Management on host=192.168.16.216;  Network=fcfd0c0d-70f5-511a-a246-b849b600e7bf; pif=fd46a646-5c9f-c1e3-2ce9-998db7f63acd
> 2014-06-13 19:24:59,115 INFO  [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-2:ctx-7fb2f798) Private Network is Management for host 192.168.16.216
> 2014-06-13 19:24:59,115 INFO  [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-2:ctx-7fb2f798) Guest Network is Management for host 192.168.16.216
> 2014-06-13 19:24:59,115 INFO  [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-2:ctx-7fb2f798) Public Network is Management for host 192.168.16.216
> 2014-06-13 19:24:59,121 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-9fa9ca8f ctx-ade6375d) ===END===  192.168.16.45 -- GET  command=listCapabilities&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687290625
> 2014-06-13 19:24:59,150 DEBUG [c.c.a.ApiServlet] (catalina-exec-25:ctx-092d2924) ===START===  192.168.16.45 -- GET  command=listZones&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687290938
> 2014-06-13 19:24:59,198 DEBUG [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-1:ctx-0b484d87) can't get patches information
> The uuid you supplied was invalid.
>        at com.xensource.xenapi.Types.checkResponse(Types.java:927)
>        at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
>        at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:433)
>        at com.xensource.xenapi.PoolPatch.getByUuid(PoolPatch.java:200)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.hostHasFixFox(CitrixResourceBase.java:5990)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.fillHostInfo(CitrixResourceBase.java:6021)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.initialize(CitrixResourceBase.java:5071)
>        at com.cloud.hypervisor.xen.resource.XenServer56Resource.initialize(XenServer56Resource.java:277)
>        at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1702)
>        at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1862)
>        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
>        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>        at java.lang.reflect.Method.invoke(Method.java:606)
>        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
>        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
>        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
>        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
>        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
>        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
>        at com.sun.proxy.$Proxy145.createHostAndAgent(Unknown Source)
>        at com.cloud.agent.manager.AgentManagerImpl$SimulateStartTask.runInContext(AgentManagerImpl.java:1047)
>        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:50)
>        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
>        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
>        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
>        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:47)
>        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>        at java.lang.Thread.run(Thread.java:744)
> 2014-06-13 19:24:59,212 DEBUG [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-2:ctx-7fb2f798) can't get patches information
> The uuid you supplied was invalid.
>        at com.xensource.xenapi.Types.checkResponse(Types.java:927)
>        at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
>        at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:433)
>        at com.xensource.xenapi.PoolPatch.getByUuid(PoolPatch.java:200)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.hostHasFixFox(CitrixResourceBase.java:5990)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.fillHostInfo(CitrixResourceBase.java:6021)
>        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.initialize(CitrixResourceBase.java:5071)
>        at com.cloud.hypervisor.xen.resource.XenServer56Resource.initialize(XenServer56Resource.java:277)
>        at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1702)
>        at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1862)
>        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
>        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>        at java.lang.reflect.Method.invoke(Method.java:606)
>        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
>        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
>        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
>        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
>        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
>        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
>        at com.sun.proxy.$Proxy145.createHostAndAgent(Unknown Source)
>        at com.cloud.agent.manager.AgentManagerImpl$SimulateStartTask.runInContext(AgentManagerImpl.java:1047)
>        at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:50)
>        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
>        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
>        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
>        at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:47)
>        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>        at java.lang.Thread.run(Thread.java:744)
> 2014-06-13 19:24:59,222 DEBUG [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-1:ctx-0b484d87) Total Ram: 97078222080 dom0 Ram: 4278190080
> 2014-06-13 19:24:59,250 DEBUG [c.c.h.x.r.CitrixResourceBase] (AgentTaskPool-2:ctx-7fb2f798) Total Ram: 97086737664 dom0 Ram: 4269539328
> 2014-06-13 19:24:59,297 DEBUG [c.c.a.ApiServlet] (catalina-exec-25:ctx-092d2924 ctx-43058f97) ===END===  192.168.16.45 -- GET  command=listZones&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687290938
> 2014-06-13 19:24:59,512 DEBUG [c.c.a.ApiServlet] (catalina-exec-4:ctx-734301b4) ===START===  192.168.16.45 -- GET  command=listZones&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687291134
> 2014-06-13 19:24:59,517 DEBUG [c.c.a.ApiServlet] (catalina-exec-5:ctx-872af475) ===START===  192.168.16.45 -- GET  command=listProjectInvitations&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&state=Pending&_=1402687291137
> 2014-06-13 19:24:59,528 DEBUG [c.c.a.ApiServlet] (catalina-exec-6:ctx-064af16b) ===START===  192.168.16.45 -- GET  command=listProjects&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&accountId=9c8cf63c-dd37-4633-bc17-5f4232060be5&listAll=true&_=1402687291145
> 2014-06-13 19:24:59,581 DEBUG [c.c.a.ApiServlet] (catalina-exec-1:ctx-fc704b4f) ===START===  192.168.16.45 -- GET  command=listRegions&listAll=true&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687291140
> 2014-06-13 19:24:59,951 DEBUG [c.c.a.ApiServlet] (catalina-exec-1:ctx-fc704b4f ctx-2fad2da4) ===END===  192.168.16.45 -- GET  command=listRegions&listAll=true&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687291140
> 2014-06-13 19:24:59,954 DEBUG [c.c.a.ApiServlet] (catalina-exec-4:ctx-734301b4 ctx-f64158e1) ===END===  192.168.16.45 -- GET  command=listZones&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687291134
> 2014-06-13 19:24:59,957 DEBUG [c.c.a.ApiServlet] (catalina-exec-5:ctx-872af475 ctx-f01a3779) ===END===  192.168.16.45 -- GET  command=listProjectInvitations&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&state=Pending&_=1402687291137
> 2014-06-13 19:24:59,970 DEBUG [c.c.a.ApiServlet] (catalina-exec-3:ctx-0e356636) ===START===  192.168.16.45 -- GET  command=listAlerts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&page=1&pageSize=4&_=1402687291763
> 2014-06-13 19:25:00,027 DEBUG [c.c.a.ApiServlet] (catalina-exec-6:ctx-064af16b ctx-e894e8b0) ===END===  192.168.16.45 -- GET  command=listProjects&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&accountId=9c8cf63c-dd37-4633-bc17-5f4232060be5&listAll=true&_=1402687291145
> 2014-06-13 19:25:00,083 DEBUG [c.c.a.ApiServlet] (catalina-exec-3:ctx-0e356636 ctx-a11446cc) ===END===  192.168.16.45 -- GET  command=listAlerts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&page=1&pageSize=4&_=1402687291763
> 2014-06-13 19:25:00,120 DEBUG [c.c.a.ApiServlet] (catalina-exec-7:ctx-19912c11) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&state=Alert&page=1&pageSize=4&_=1402687291902
> 2014-06-13 19:25:00,180 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-7:ctx-19912c11 ctx-9cda5027) >>>Searching for hosts>>>
> 2014-06-13 19:25:00,194 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-7:ctx-19912c11 ctx-9cda5027) >>>Generating Response>>>
> 2014-06-13 19:25:00,210 DEBUG [c.c.a.ApiServlet] (catalina-exec-7:ctx-19912c11 ctx-9cda5027) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&state=Alert&page=1&pageSize=4&_=1402687291902
> 2014-06-13 19:25:00,229 DEBUG [c.c.a.ApiServlet] (catalina-exec-10:ctx-dce5edc5) ===START===  192.168.16.45 -- GET  command=listCapacity&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&fetchLatest=false&sortBy=usage&page=0&pagesize=8&_=1402687292020
> 2014-06-13 19:25:00,557 DEBUG [c.c.a.ApiServlet] (catalina-exec-10:ctx-dce5edc5 ctx-b8216fc2) ===END===  192.168.16.45 -- GET  command=listCapacity&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&fetchLatest=false&sortBy=usage&page=0&pagesize=8&_=1402687292020
> 2014-06-13 19:25:00,987 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq -1--1: Startup request from directly connected host:  { Cmd , MgmtId: -1, via: -1, Ver: v1, Flags: 11, [{"cpuSockets":2,"cpus":24,"speed":2500,"memory":97078222080,"dom0MinMemory":4278190080,"poolSync":false,"_hostVmStateReport":{},"caps":"xen-3.0-x86_64 , xen-3.0-x86_32p , hvm-3.0-x86_32 , hvm-3.0-x86_32p , hvm-3.0-x86_64","pool":"2d56decf-8b47-eb93-9e56-fa01cc68e24e","hypervisorType":"XenServer","hostDetails":{"xs_has_fixfox":"false","product_version":"6.2.0","private.network.device":"Management","com.cloud.network.Networks.RouterPrivateIpStrategy":"DcGlobal","product_brand":"XenServer","product_version_text_short":"6.2"},"hypervisorVersion":"6.2.0","type":"Routing","dataCenter":"1","pod":"1","cluster":"1","guid":"2cdc3124-6002-4ee5-8460-37d521fe0a7c","name":"CP-HOST-02","version":"4.3.0.0","iqn":"iqn.2014-06.com.example:c5f2e6dc","publicIpAddress":"192.168.16.215","publicNetmask":"255.255.255.0","publicMacAddress":"00:15:17:7a:6a:ac","privateIpAddress":"192.168.16.215","privateMacAddress":"00:15:17:7a:6a:ac","privateNetmask":"255.255.255.0","storageIpAddress":"192.168.16.215","storageNetmask":"255.255.255.0","storageMacAddress":"00:15:17:7a:6a:ac","wait":0},{"totalSize":0,"poolInfo":{"uuid":"05c34ed2-ed51-f6b0-aeda-e49884a46c53","host":"192.168.16.215","localPath":"ext","hostPath":"ext","poolType":"EXT","capacityBytes":483206168576,"availableBytes":482998427648},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"1","guid":"2cdc3124-6002-4ee5-8460-37d521fe0a7c","wait":0}] }
> 2014-06-13 19:25:01,005 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to BaremetalDhcpManagerImpl
> 2014-06-13 19:25:01,006 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to BaremetalPxeManagerImpl
> 2014-06-13 19:25:01,007 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to NetworkUsageManagerImpl
> 2014-06-13 19:25:01,009 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to PaloAltoExternalFirewallElement
> 2014-06-13 19:25:01,010 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to KvmServerDiscoverer
> 2014-06-13 19:25:01,011 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to F5ExternalLoadBalancerElement
> 2014-06-13 19:25:01,011 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to PremiumSecondaryStorageManagerImpl
> 2014-06-13 19:25:01,012 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to JuniperSRXExternalFirewallElement
> 2014-06-13 19:25:01,012 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to NetscalerElement
> 2014-06-13 19:25:01,013 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to ConsoleProxyManagerImpl
> 2014-06-13 19:25:01,013 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to VmwareServerDiscoverer
> 2014-06-13 19:25:01,013 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to LxcServerDiscoverer
> 2014-06-13 19:25:01,013 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to BareMetalDiscoverer
> 2014-06-13 19:25:01,013 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to NiciraNvp
> 2014-06-13 19:25:01,021 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to HypervServerDiscoverer
> 2014-06-13 19:25:01,021 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to CiscoVnmcElement
> 2014-06-13 19:25:01,021 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to BigSwitchVnsElement
> 2014-06-13 19:25:01,022 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to XcpServerDiscoverer
> 2014-06-13 19:25:01,023 INFO  [c.c.h.x.d.XcpServerDiscoverer] (AgentTaskPool-1:ctx-0b484d87) Host: CP-HOST-02 connected with hypervisor type: XenServer. Checking CIDR...
> 2014-06-13 19:25:01,117 DEBUG [c.c.r.ResourceState] (AgentTaskPool-1:ctx-0b484d87) Resource state update: [id = 1; name = CP-HOST-02; old state = Enabled; event = InternalCreated; new state = Enabled]
> 2014-06-13 19:25:01,117 DEBUG [c.c.h.Status] (AgentTaskPool-1:ctx-0b484d87) Transition:[Resource state = Enabled, Agent event = AgentConnected, Host id = 1, name = CP-HOST-02]
> 2014-06-13 19:25:01,164 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) create ClusteredDirectAgentAttache for 1
> 2014-06-13 19:25:01,180 INFO  [c.c.a.m.DirectAgentAttache] (AgentTaskPool-1:ctx-0b484d87) StartupAnswer received 1 Interval = 60
> 2014-06-13 19:25:01,193 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: XcpServerDiscoverer
> 2014-06-13 19:25:01,204 DEBUG [c.c.h.x.d.XcpServerDiscoverer] (AgentTaskPool-1:ctx-0b484d87) Setting up host 1
> 2014-06-13 19:25:01,219 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328769: Sending  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.SetupCommand":{"env":{},"multipath":true,"needSetup":false,"wait":0}}] }
> 2014-06-13 19:25:01,220 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328769: Executing:  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.SetupCommand":{"env":{},"multipath":true,"needSetup":false,"wait":0}}] }
> 2014-06-13 19:25:01,242 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-1:ctx-134f26f9) Seq 1-1847328769: Executing request
> 2014-06-13 19:25:01,344 INFO  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-134f26f9) Host 192.168.16.215 OpaqueRef:f2aada3d-f0df-fb29-a00c-c55086ef016b: Host 192.168.16.215 is already setup.
> 2014-06-13 19:25:01,517 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq -1--1: Startup request from directly connected host:  { Cmd , MgmtId: -1, via: -1, Ver: v1, Flags: 11, [{"cpuSockets":2,"cpus":24,"speed":2200,"memory":97086737664,"dom0MinMemory":4269539328,"poolSync":false,"_hostVmStateReport":{},"_clusterVMStates":{},"caps":"xen-3.0-x86_64 , xen-3.0-x86_32p , hvm-3.0-x86_32 , hvm-3.0-x86_32p , hvm-3.0-x86_64","pool":"2d56decf-8b47-eb93-9e56-fa01cc68e24e","hypervisorType":"XenServer","hostDetails":{"xs_has_fixfox":"false","product_version":"6.2.0","private.network.device":"Management","com.cloud.network.Networks.RouterPrivateIpStrategy":"DcGlobal","product_brand":"XenServer","product_version_text_short":"6.2"},"hypervisorVersion":"6.2.0","type":"Routing","dataCenter":"1","pod":"1","cluster":"1","guid":"012ffb72-a098-41c8-8df4-e5682e074c38","name":"CP-HOST-01","version":"4.3.0.0","iqn":"iqn.2014-03.com.example:eb31d4d7","publicIpAddress":"192.168.16.216","publicNetmask":"255.255.255.0","publicMacAddress":"00:15:17:6b:2b:6c","privateIpAddress":"192.168.16.216","privateMacAddress":"00:15:17:6b:2b:6c","privateNetmask":"255.255.255.0","storageIpAddress":"192.168.16.216","storageNetmask":"255.255.255.0","storageMacAddress":"00:15:17:6b:2b:6c","wait":0},{"totalSize":0,"poolInfo":{"uuid":"4cdde5c6-a69e-3355-d5b3-0d2c35496c8e","host":"192.168.16.216","localPath":"lvm","hostPath":"lvm","poolType":"LVM","capacityBytes":490909728768,"availableBytes":490905534464},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"1","guid":"012ffb72-a098-41c8-8df4-e5682e074c38","wait":0}] }
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to BaremetalDhcpManagerImpl
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to BaremetalPxeManagerImpl
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to NetworkUsageManagerImpl
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to PaloAltoExternalFirewallElement
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to KvmServerDiscoverer
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to F5ExternalLoadBalancerElement
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to PremiumSecondaryStorageManagerImpl
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to JuniperSRXExternalFirewallElement
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to NetscalerElement
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to ConsoleProxyManagerImpl
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to VmwareServerDiscoverer
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to LxcServerDiscoverer
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to BareMetalDiscoverer
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to NiciraNvp
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to HypervServerDiscoverer
> 2014-06-13 19:25:01,538 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to CiscoVnmcElement
> 2014-06-13 19:25:01,539 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to BigSwitchVnsElement
> 2014-06-13 19:25:01,539 DEBUG [c.c.r.ResourceManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to XcpServerDiscoverer
> 2014-06-13 19:25:01,539 INFO  [c.c.h.x.d.XcpServerDiscoverer] (AgentTaskPool-2:ctx-7fb2f798) Host: CP-HOST-01 connected with hypervisor type: XenServer. Checking CIDR...
> 2014-06-13 19:25:01,623 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-1:ctx-134f26f9) Seq 1-1847328769: Response Received:
> 2014-06-13 19:25:01,624 DEBUG [c.c.a.t.Request] (DirectAgent-1:ctx-134f26f9) Seq 1-1847328769: Processing:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.SetupAnswer":{"_reconnect":false,"result":true,"wait":0}}] }
> 2014-06-13 19:25:01,628 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328769: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 110, { SetupAnswer } }
> 2014-06-13 19:25:01,632 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-1:ctx-134f26f9) Seq 1-1847328769: No more commands found
> 2014-06-13 19:25:01,663 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: HypervServerDiscoverer
> 2014-06-13 19:25:01,663 DEBUG [c.c.h.h.d.HypervServerDiscoverer] (AgentTaskPool-1:ctx-0b484d87) Not Hyper-V hypervisor, so moving on.
> 2014-06-13 19:25:01,663 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: DeploymentPlanningManagerImpl
> 2014-06-13 19:25:01,667 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: SecurityGroupListener
> 2014-06-13 19:25:01,667 INFO  [c.c.n.s.SecurityGroupListener] (AgentTaskPool-1:ctx-0b484d87) Received a host startup notification
> 2014-06-13 19:25:01,667 DEBUG [c.c.r.ResourceState] (AgentTaskPool-2:ctx-7fb2f798) Resource state update: [id = 2; name = CP-HOST-01; old state = Enabled; event = InternalCreated; new state = Enabled]
> 2014-06-13 19:25:01,668 DEBUG [c.c.h.Status] (AgentTaskPool-2:ctx-7fb2f798) Transition:[Resource state = Enabled, Agent event = AgentConnected, Host id = 2, name = CP-HOST-01]
> 2014-06-13 19:25:01,674 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328770: Sending  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CleanupNetworkRulesCmd":{"interval":1947,"wait":0}}] }
> 2014-06-13 19:25:01,674 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328770: Executing:  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CleanupNetworkRulesCmd":{"interval":1947,"wait":0}}] }
> 2014-06-13 19:25:01,683 INFO  [c.c.n.s.SecurityGroupListener] (AgentTaskPool-1:ctx-0b484d87) Scheduled network rules cleanup, interval=1947
> 2014-06-13 19:25:01,683 INFO  [c.c.n.s.SecurityGroupListener] (AgentTaskPool-1:ctx-0b484d87) Received a host startup notification
> 2014-06-13 19:25:01,683 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: SecondaryStorageListener
> 2014-06-13 19:25:01,684 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: StoragePoolMonitor
> 2014-06-13 19:25:01,692 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) create ClusteredDirectAgentAttache for 2
> 2014-06-13 19:25:01,693 INFO  [c.c.a.m.DirectAgentAttache] (AgentTaskPool-2:ctx-7fb2f798) StartupAnswer received 2 Interval = 60
> 2014-06-13 19:25:01,713 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: XcpServerDiscoverer
> 2014-06-13 19:25:01,714 DEBUG [c.c.s.l.StoragePoolMonitor] (AgentTaskPool-1:ctx-0b484d87) Host 1 connected, sending down storage pool information ...
> 2014-06-13 19:25:01,746 DEBUG [c.c.h.x.d.XcpServerDiscoverer] (AgentTaskPool-2:ctx-7fb2f798) Setting up host 2
> 2014-06-13 19:25:01,761 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773889: Sending  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.SetupCommand":{"env":{},"multipath":true,"needSetup":false,"wait":0}}] }
> 2014-06-13 19:25:01,762 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773889: Executing:  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.SetupCommand":{"env":{},"multipath":true,"needSetup":false,"wait":0}}] }
> 2014-06-13 19:25:01,782 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-2:ctx-2e40ab3a) Seq 2-1956773889: Executing request
> 2014-06-13 19:25:01,783 DEBUG [c.c.s.StorageManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Adding pool null to  host 1
> 2014-06-13 19:25:01,818 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328771: Sending  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifyStoragePoolCommand":{"add":true,"pool":{"id":3,"uuid":"5a36de98-58bb-3082-b94d-a5ce0ed45779","host":"192.168.16.168","path":"/iqn.2001-05.com.equallogic:4-52aed6-9bcd6cfa0-8590030f343539b3-cloudplatformprimarystorage/0","port":3260,"type":"IscsiLUN"},"localPath":"/mnt//5a36de98-58bb-3082-b94d-a5ce0ed45779","wait":0}}] }
> 2014-06-13 19:25:01,818 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328771: Executing:  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifyStoragePoolCommand":{"add":true,"pool":{"id":3,"uuid":"5a36de98-58bb-3082-b94d-a5ce0ed45779","host":"192.168.16.168","path":"/iqn.2001-05.com.equallogic:4-52aed6-9bcd6cfa0-8590030f343539b3-cloudplatformprimarystorage/0","port":3260,"type":"IscsiLUN"},"localPath":"/mnt//5a36de98-58bb-3082-b94d-a5ce0ed45779","wait":0}}] }
> 2014-06-13 19:25:01,833 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-3:ctx-55805cc5) Seq 1-1847328771: Executing request
> 2014-06-13 19:25:01,840 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-3:ctx-55805cc5) SR retrieved for 5a36de98-58bb-3082-b94d-a5ce0ed45779
> 2014-06-13 19:25:01,849 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-3:ctx-55805cc5) Checking 5a36de98-58bb-3082-b94d-a5ce0ed45779 or SR 1bea5e6a-5e57-88b6-2a05-09f388ff3c38 on XS[2cdc3124-6002-4ee5-8460-37d521fe0a7c-192.168.16.215]
> 2014-06-13 19:25:01,866 INFO  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-2:ctx-2e40ab3a) Host 192.168.16.216 OpaqueRef:f3c40646-e02c-3e40-1852-ef995e443001: Host 192.168.16.216 is already setup.
> 2014-06-13 19:25:01,957 DEBUG [c.c.a.ApiServlet] (catalina-exec-11:ctx-6cc07c6d) ===START===  192.168.16.45 -- GET  command=listZones&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687293737
> 2014-06-13 19:25:01,995 DEBUG [c.c.a.ApiServlet] (catalina-exec-11:ctx-6cc07c6d ctx-55617bde) ===END===  192.168.16.45 -- GET  command=listZones&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687293737
> 2014-06-13 19:25:02,024 DEBUG [c.c.a.ApiServlet] (catalina-exec-14:ctx-d9a18c1f) ===START===  192.168.16.45 -- GET  command=listPods&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687293810
> 2014-06-13 19:25:02,120 DEBUG [c.c.a.ApiServlet] (catalina-exec-14:ctx-d9a18c1f ctx-fa308892) ===END===  192.168.16.45 -- GET  command=listPods&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687293810
> 2014-06-13 19:25:02,128 DEBUG [c.c.a.ApiServlet] (catalina-exec-9:ctx-19d137d3) ===START===  192.168.16.45 -- GET  command=listClusters&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687293929
> 2014-06-13 19:25:02,170 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-2:ctx-2e40ab3a) Seq 2-1956773889: Response Received:
> 2014-06-13 19:25:02,171 DEBUG [c.c.a.t.Request] (DirectAgent-2:ctx-2e40ab3a) Seq 2-1956773889: Processing:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 110, [{"com.cloud.agent.api.SetupAnswer":{"_reconnect":false,"result":true,"wait":0}}] }
> 2014-06-13 19:25:02,171 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773889: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 110, { SetupAnswer } }
> 2014-06-13 19:25:02,190 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: HypervServerDiscoverer
> 2014-06-13 19:25:02,190 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-2:ctx-2e40ab3a) Seq 2-1956773889: No more commands found
> 2014-06-13 19:25:02,190 DEBUG [c.c.h.h.d.HypervServerDiscoverer] (AgentTaskPool-2:ctx-7fb2f798) Not Hyper-V hypervisor, so moving on.
> 2014-06-13 19:25:02,192 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: DeploymentPlanningManagerImpl
> 2014-06-13 19:25:02,194 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-3:ctx-55805cc5) Seq 1-1847328771: Response Received:
> 2014-06-13 19:25:02,196 DEBUG [c.c.a.t.Request] (DirectAgent-3:ctx-55805cc5) Seq 1-1847328771: Processing:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ModifyStoragePoolAnswer":{"poolInfo":{"host":"192.168.16.168","localPath":"/mnt//5a36de98-58bb-3082-b94d-a5ce0ed45779","hostPath":"/iqn.2001-05.com.equallogic:4-52aed6-9bcd6cfa0-8590030f343539b3-cloudplatformprimarystorage/0","poolType":"IscsiLUN","capacityBytes":2675965952,"availableBytes":2663383040},"templateInfo":{},"result":true,"wait":0}}] }
> 2014-06-13 19:25:02,196 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: SecurityGroupListener
> 2014-06-13 19:25:02,196 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328771: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, { ModifyStoragePoolAnswer } }
> 2014-06-13 19:25:02,196 INFO  [c.c.n.s.SecurityGroupListener] (AgentTaskPool-2:ctx-7fb2f798) Received a host startup notification
> 2014-06-13 19:25:02,224 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773890: Sending  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CleanupNetworkRulesCmd":{"interval":1916,"wait":0}}] }
> 2014-06-13 19:25:02,224 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773890: Executing:  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.CleanupNetworkRulesCmd":{"interval":1916,"wait":0}}] }
> 2014-06-13 19:25:02,229 INFO  [c.c.n.s.SecurityGroupListener] (AgentTaskPool-2:ctx-7fb2f798) Scheduled network rules cleanup, interval=1916
> 2014-06-13 19:25:02,245 INFO  [c.c.n.s.SecurityGroupListener] (AgentTaskPool-2:ctx-7fb2f798) Received a host startup notification
> 2014-06-13 19:25:02,245 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: SecondaryStorageListener
> 2014-06-13 19:25:02,245 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: StoragePoolMonitor
> 2014-06-13 19:25:02,264 DEBUG [c.c.s.l.StoragePoolMonitor] (AgentTaskPool-2:ctx-7fb2f798) Host 2 connected, sending down storage pool information ...
> 2014-06-13 19:25:02,271 DEBUG [c.c.n.l.LBHealthCheckManagerImpl] (LBHealthCheck-1:ctx-e6cf1e21) LB HealthCheck Manager is running and getting the updates from LB providers and updating service status
> 2014-06-13 19:25:02,284 DEBUG [c.c.s.StorageManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Adding pool null to  host 2
> 2014-06-13 19:25:02,299 DEBUG [c.c.a.ApiServlet] (catalina-exec-9:ctx-19d137d3 ctx-e7506a85) ===END===  192.168.16.45 -- GET  command=listClusters&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687293929
> 2014-06-13 19:25:02,318 DEBUG [c.c.a.ApiServlet] (catalina-exec-12:ctx-f45a49f1) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&listAll=true&page=1&pagesize=1&_=1402687294114
> 2014-06-13 19:25:02,332 INFO  [o.a.c.s.d.p.DefaultHostListener] (AgentTaskPool-1:ctx-0b484d87) Connection established between org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@7131fae4 host + 1
> 2014-06-13 19:25:02,340 DEBUG [c.c.s.StorageManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Successfully set Capacity - 2675965952 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 3, PodId 1
> 2014-06-13 19:25:02,340 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: ClusteredVirtualMachineManagerImpl
> 2014-06-13 19:25:02,340 DEBUG [c.c.v.VirtualMachineManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Received startup command from hypervisor host. host id: 1
> 2014-06-13 19:25:02,341 INFO  [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentTaskPool-1:ctx-0b484d87) Reset VM power state sync for host: 1
> 2014-06-13 19:25:02,344 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773891: Sending  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifyStoragePoolCommand":{"add":true,"pool":{"id":3,"uuid":"5a36de98-58bb-3082-b94d-a5ce0ed45779","host":"192.168.16.168","path":"/iqn.2001-05.com.equallogic:4-52aed6-9bcd6cfa0-8590030f343539b3-cloudplatformprimarystorage/0","port":3260,"type":"IscsiLUN"},"localPath":"/mnt//5a36de98-58bb-3082-b94d-a5ce0ed45779","wait":0}}] }
> 2014-06-13 19:25:02,345 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773891: Executing:  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifyStoragePoolCommand":{"add":true,"pool":{"id":3,"uuid":"5a36de98-58bb-3082-b94d-a5ce0ed45779","host":"192.168.16.168","path":"/iqn.2001-05.com.equallogic:4-52aed6-9bcd6cfa0-8590030f343539b3-cloudplatformprimarystorage/0","port":3260,"type":"IscsiLUN"},"localPath":"/mnt//5a36de98-58bb-3082-b94d-a5ce0ed45779","wait":0}}] }
> 2014-06-13 19:25:02,349 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-1:ctx-434ad74f) Seq 2-1956773891: Executing request
> 2014-06-13 19:25:02,356 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-434ad74f) SR retrieved for 5a36de98-58bb-3082-b94d-a5ce0ed45779
> 2014-06-13 19:25:02,363 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-12:ctx-f45a49f1 ctx-6b48446b) >>>Searching for hosts>>>
> 2014-06-13 19:25:02,372 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-434ad74f) Checking 5a36de98-58bb-3082-b94d-a5ce0ed45779 or SR 1bea5e6a-5e57-88b6-2a05-09f388ff3c38 on XS[012ffb72-a098-41c8-8df4-e5682e074c38-192.168.16.216]
> 2014-06-13 19:25:02,389 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-12:ctx-f45a49f1 ctx-6b48446b) >>>Generating Response>>>
> 2014-06-13 19:25:02,393 DEBUG [c.c.n.l.LBHealthCheckManagerImpl] (LBHealthCheck-1:ctx-e6cf1e21) LB HealthCheck Manager is running and getting the updates from LB providers and updating service status
> 2014-06-13 19:25:02,396 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328772: Sending  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ClusterVMMetaDataSyncCommand":{"_interval":180,"_clusterId":1,"wait":0}}] }
> 2014-06-13 19:25:02,397 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328772: Executing:  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ClusterVMMetaDataSyncCommand":{"_interval":180,"_clusterId":1,"wait":0}}] }
> 2014-06-13 19:25:02,405 DEBUG [c.c.v.VirtualMachineManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Cluster VM metadata sync started with jobid 1847328772
> 2014-06-13 19:25:02,405 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: NetworkOrchestrator
> 2014-06-13 19:25:02,409 DEBUG [o.a.c.e.o.NetworkOrchestrator] (AgentTaskPool-1:ctx-0b484d87) Host's hypervisorType is: XenServer
> 2014-06-13 19:25:02,428 DEBUG [c.c.a.ApiServlet] (catalina-exec-12:ctx-f45a49f1 ctx-6b48446b) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&listAll=true&page=1&pagesize=1&_=1402687294114
> 2014-06-13 19:25:02,439 DEBUG [c.c.a.ApiServlet] (catalina-exec-12:ctx-0f77c8bc) ===START===  192.168.16.45 -- GET  command=listStoragePools&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687294237
> 2014-06-13 19:25:02,444 DEBUG [o.a.c.e.o.NetworkOrchestrator] (AgentTaskPool-1:ctx-0b484d87) Sending CheckNetworkCommand to check the Network is setup correctly on Agent
> 2014-06-13 19:25:02,466 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328773: Sending  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.CheckNetworkCommand":{"networkInfoList":[{"physicalNetworkId":200,"publicNetworkName":"Guest","guestNetworkName":"InternalTraffic"},{"physicalNetworkId":201,"privateNetworkName":"Management"}],"wait":0}}] }
> 2014-06-13 19:25:02,467 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328773: Executing:  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.CheckNetworkCommand":{"networkInfoList":[{"physicalNetworkId":200,"publicNetworkName":"Guest","guestNetworkName":"InternalTraffic"},{"physicalNetworkId":201,"privateNetworkName":"Management"}],"wait":0}}] }
> 2014-06-13 19:25:02,467 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-4:ctx-da7e307d) Seq 1-1847328773: Executing request
> 2014-06-13 19:25:02,474 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-4:ctx-da7e307d) Checking if network name setup is done on the resource
> 2014-06-13 19:25:02,474 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-4:ctx-da7e307d) Looking for network setup by name InternalTraffic
> 2014-06-13 19:25:02,483 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-4:ctx-da7e307d) Looking for network setup by name Guest
> 2014-06-13 19:25:02,490 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-4:ctx-da7e307d) Found more than one network with the name Guest
> 2014-06-13 19:25:02,512 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-4:ctx-da7e307d) Found a network called Guest on host=192.168.16.215;  Network=ead503c9-6d23-88c0-b65c-bbde688f4789; pif=bea80b5f-425b-e95b-acf2-05439d4a7875
> 2014-06-13 19:25:02,512 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-4:ctx-da7e307d) Looking for network setup by name Management
> 2014-06-13 19:25:02,528 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-4:ctx-da7e307d) Seq 1-1847328773: Response Received:
> 2014-06-13 19:25:02,528 DEBUG [c.c.a.t.Request] (DirectAgent-4:ctx-da7e307d) Seq 1-1847328773: Processing:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.CheckNetworkAnswer":{"_reconnect":false,"result":true,"details":"Network Setup check by names is done","wait":0}}] }
> 2014-06-13 19:25:02,528 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-4:ctx-da7e307d) Seq 1-1847328773: No more commands found
> 2014-06-13 19:25:02,530 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328773: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 110, { CheckNetworkAnswer } }
> 2014-06-13 19:25:02,531 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Details from executing class com.cloud.agent.api.CheckNetworkCommand: Network Setup check by names is done
> 2014-06-13 19:25:02,531 DEBUG [o.a.c.e.o.NetworkOrchestrator] (AgentTaskPool-1:ctx-0b484d87) Network setup is correct on Agent
> 2014-06-13 19:25:02,531 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: VmwareManagerImpl
> 2014-06-13 19:25:02,531 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: SshKeysDistriMonitor
> 2014-06-13 19:25:02,536 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-1:ctx-434ad74f) Seq 2-1956773891: Response Received:
> 2014-06-13 19:25:02,538 DEBUG [c.c.a.t.Request] (DirectAgent-1:ctx-434ad74f) Seq 2-1956773891: Processing:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ModifyStoragePoolAnswer":{"poolInfo":{"host":"192.168.16.168","localPath":"/mnt//5a36de98-58bb-3082-b94d-a5ce0ed45779","hostPath":"/iqn.2001-05.com.equallogic:4-52aed6-9bcd6cfa0-8590030f343539b3-cloudplatformprimarystorage/0","poolType":"IscsiLUN","capacityBytes":2675965952,"availableBytes":2663383040},"templateInfo":{},"result":true,"wait":0}}] }
> 2014-06-13 19:25:02,538 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773891: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { ModifyStoragePoolAnswer } }
> 2014-06-13 19:25:02,548 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328774: Sending  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] }
> 2014-06-13 19:25:02,553 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328774: Executing:  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] }
> 2014-06-13 19:25:02,553 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-2:ctx-bf287a7d) Seq 1-1847328774: Executing request
> 2014-06-13 19:25:02,553 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-2:ctx-bf287a7d) Seq 1-1847328774: Response Received:
> 2014-06-13 19:25:02,554 DEBUG [c.c.a.t.Request] (DirectAgent-2:ctx-bf287a7d) Seq 1-1847328774: Processing:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
> 2014-06-13 19:25:02,561 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: VpcVirtualNetworkApplianceManagerImpl
> 2014-06-13 19:25:02,564 INFO  [o.a.c.s.d.p.DefaultHostListener] (AgentTaskPool-2:ctx-7fb2f798) Connection established between org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@36c53d99 host + 2
> 2014-06-13 19:25:02,586 DEBUG [c.c.s.StorageManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Successfully set Capacity - 2675965952 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 3, PodId 1
> 2014-06-13 19:25:02,586 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: ClusteredVirtualMachineManagerImpl
> 2014-06-13 19:25:02,592 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: UploadListener
> 2014-06-13 19:25:02,592 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: StorageCapacityListener
> 2014-06-13 19:25:02,593 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: ComputeCapacityListener
> 2014-06-13 19:25:02,586 DEBUG [c.c.v.VirtualMachineManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Received startup command from hypervisor host. host id: 2
> 2014-06-13 19:25:02,598 INFO  [c.c.v.VirtualMachinePowerStateSyncImpl] (AgentTaskPool-2:ctx-7fb2f798) Reset VM power state sync for host: 2
> 2014-06-13 19:25:02,609 DEBUG [c.c.a.ApiServlet] (catalina-exec-12:ctx-0f77c8bc ctx-080180bb) ===END===  192.168.16.45 -- GET  command=listStoragePools&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687294237
> 2014-06-13 19:25:02,614 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773892: Sending  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ClusterVMMetaDataSyncCommand":{"_interval":180,"_clusterId":1,"wait":0}}] }
> 2014-06-13 19:25:02,616 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773892: Executing:  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ClusterVMMetaDataSyncCommand":{"_interval":180,"_clusterId":1,"wait":0}}] }
> 2014-06-13 19:25:02,615 DEBUG [c.c.c.CapacityManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Found 0 VMs on host 1
> 2014-06-13 19:25:02,621 DEBUG [c.c.a.ApiServlet] (catalina-exec-16:ctx-ecfa6b28) ===START===  192.168.16.45 -- GET  command=listImageStores&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=SecondaryStorage&listAll=true&page=1&pagesize=1&_=1402687294418
> 2014-06-13 19:25:02,630 DEBUG [c.c.v.VirtualMachineManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Cluster VM metadata sync started with jobid 1956773892
> 2014-06-13 19:25:02,630 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: NetworkOrchestrator
> 2014-06-13 19:25:02,633 DEBUG [o.a.c.e.o.NetworkOrchestrator] (AgentTaskPool-2:ctx-7fb2f798) Host's hypervisorType is: XenServer
> 2014-06-13 19:25:02,647 DEBUG [c.c.c.CapacityManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Found 0 VM, not running on host 1
> 2014-06-13 19:25:02,660 DEBUG [c.c.c.CapacityManagerImpl] (AgentTaskPool-1:ctx-0b484d87) No need to calibrate cpu capacity, host:1 usedCpu: 0 reservedCpu: 0
> 2014-06-13 19:25:02,660 DEBUG [c.c.c.CapacityManagerImpl] (AgentTaskPool-1:ctx-0b484d87) No need to calibrate memory capacity, host:1 usedMem: 0 reservedMem: 0
> 2014-06-13 19:25:02,661 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: SshKeysDistriMonitor
> 2014-06-13 19:25:02,687 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328775: Sending  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] }
> 2014-06-13 19:25:02,687 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328775: Executing:  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] }
> 2014-06-13 19:25:02,697 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-7:ctx-ce526100) Seq 1-1847328775: Executing request
> 2014-06-13 19:25:02,697 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: VirtualNetworkApplianceManagerImpl
> 2014-06-13 19:25:02,697 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-7:ctx-ce526100) Seq 1-1847328775: Response Received:
> 2014-06-13 19:25:02,700 DEBUG [c.c.a.t.Request] (DirectAgent-7:ctx-ce526100) Seq 1-1847328775: Processing:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
> 2014-06-13 19:25:02,701 DEBUG [c.c.a.ApiServlet] (catalina-exec-16:ctx-ecfa6b28 ctx-b3459e1c) ===END===  192.168.16.45 -- GET  command=listImageStores&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=SecondaryStorage&listAll=true&page=1&pagesize=1&_=1402687294418
> 2014-06-13 19:25:02,710 DEBUG [c.c.a.ApiServlet] (catalina-exec-13:ctx-8031aa47) ===START===  192.168.16.45 -- GET  command=listSystemVms&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687294511
> 2014-06-13 19:25:02,712 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: LocalStoragePoolListener
> 2014-06-13 19:25:02,713 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: ConsoleProxyListener
> 2014-06-13 19:25:02,714 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: DirectNetworkStatsListener
> 2014-06-13 19:25:02,714 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: BehindOnPingListener
> 2014-06-13 19:25:02,716 DEBUG [o.a.c.e.o.NetworkOrchestrator] (AgentTaskPool-2:ctx-7fb2f798) Sending CheckNetworkCommand to check the Network is setup correctly on Agent
> 2014-06-13 19:25:02,741 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Sending Connect to listener: DownloadListener
> 2014-06-13 19:25:02,742 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773893: Sending  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.CheckNetworkCommand":{"networkInfoList":[{"physicalNetworkId":200,"publicNetworkName":"Guest","guestNetworkName":"InternalTraffic"},{"physicalNetworkId":201,"privateNetworkName":"Management"}],"wait":0}}] }
> 2014-06-13 19:25:02,743 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773893: Executing:  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.CheckNetworkCommand":{"networkInfoList":[{"physicalNetworkId":200,"publicNetworkName":"Guest","guestNetworkName":"InternalTraffic"},{"physicalNetworkId":201,"privateNetworkName":"Management"}],"wait":0}}] }
> 2014-06-13 19:25:02,744 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-8:ctx-6a2a4558) Seq 2-1956773893: Executing request
> 2014-06-13 19:25:02,744 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-8:ctx-6a2a4558) Checking if network name setup is done on the resource
> 2014-06-13 19:25:02,744 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-8:ctx-6a2a4558) Looking for network setup by name InternalTraffic
> 2014-06-13 19:25:02,754 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-8:ctx-6a2a4558) Looking for network setup by name Guest
> 2014-06-13 19:25:02,768 DEBUG [c.c.a.ApiServlet] (catalina-exec-13:ctx-8031aa47 ctx-f00c796d) ===END===  192.168.16.45 -- GET  command=listSystemVms&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687294511
> 2014-06-13 19:25:02,773 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-8:ctx-6a2a4558) Found more than one network with the name Guest
> 2014-06-13 19:25:02,780 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328776: Sending  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.ReadyCommand":{"dcId":1,"hostId":1,"wait":0}}] }
> 2014-06-13 19:25:02,780 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328776: Executing:  { Cmd , MgmtId: 240491168032724, via: 1(CP-HOST-02), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.ReadyCommand":{"dcId":1,"hostId":1,"wait":0}}] }
> 2014-06-13 19:25:02,785 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-6:ctx-ed43cab0) Seq 1-1847328776: Executing request
> 2014-06-13 19:25:02,787 DEBUG [c.c.a.ApiServlet] (catalina-exec-15:ctx-fb657ad5) ===START===  192.168.16.45 -- GET  command=listRouters&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687294586
> 2014-06-13 19:25:02,797 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-8:ctx-6a2a4558) Found a network called Guest on host=192.168.16.216;  Network=ead503c9-6d23-88c0-b65c-bbde688f4789; pif=885e1858-c1af-a6ef-3170-702dfe99e2b3
> 2014-06-13 19:25:02,797 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-8:ctx-6a2a4558) Looking for network setup by name Management
> 2014-06-13 19:25:02,820 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-8:ctx-6a2a4558) Seq 2-1956773893: Response Received:
> 2014-06-13 19:25:02,821 DEBUG [c.c.a.t.Request] (DirectAgent-8:ctx-6a2a4558) Seq 2-1956773893: Processing:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 110, [{"com.cloud.agent.api.CheckNetworkAnswer":{"_reconnect":false,"result":true,"details":"Network Setup check by names is done","wait":0}}] }
> 2014-06-13 19:25:02,821 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773893: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 110, { CheckNetworkAnswer } }
> 2014-06-13 19:25:02,821 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Details from executing class com.cloud.agent.api.CheckNetworkCommand: Network Setup check by names is done
> 2014-06-13 19:25:02,821 DEBUG [o.a.c.e.o.NetworkOrchestrator] (AgentTaskPool-2:ctx-7fb2f798) Network setup is correct on Agent
> 2014-06-13 19:25:02,821 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: VmwareManagerImpl
> 2014-06-13 19:25:02,821 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: SshKeysDistriMonitor
> 2014-06-13 19:25:02,822 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-8:ctx-6a2a4558) Seq 2-1956773893: No more commands found
> 2014-06-13 19:25:02,838 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773894: Sending  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] }
> 2014-06-13 19:25:02,838 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773894: Executing:  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] }
> 2014-06-13 19:25:02,839 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-4:ctx-9258b6e5) Seq 2-1956773894: Executing request
> 2014-06-13 19:25:02,839 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-4:ctx-9258b6e5) Seq 2-1956773894: Response Received:
> 2014-06-13 19:25:02,839 DEBUG [c.c.a.t.Request] (DirectAgent-4:ctx-9258b6e5) Seq 2-1956773894: Processing:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
> 2014-06-13 19:25:02,854 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: VpcVirtualNetworkApplianceManagerImpl
> 2014-06-13 19:25:02,859 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: UploadListener
> 2014-06-13 19:25:02,860 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: StorageCapacityListener
> 2014-06-13 19:25:02,860 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: ComputeCapacityListener
> 2014-06-13 19:25:02,867 DEBUG [c.c.a.ApiServlet] (catalina-exec-15:ctx-fb657ad5 ctx-5446c381) ===END===  192.168.16.45 -- GET  command=listRouters&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687294586
> 2014-06-13 19:25:02,877 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-7f561746) ===START===  192.168.16.45 -- GET  command=listRouters&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&projectid=-1&page=1&pagesize=1&_=1402687294676
> 2014-06-13 19:25:02,888 DEBUG [c.c.c.CapacityManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Found 0 VMs on host 2
> 2014-06-13 19:25:02,916 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-7f561746 ctx-559427b8) ===END===  192.168.16.45 -- GET  command=listRouters&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&projectid=-1&page=1&pagesize=1&_=1402687294676
> 2014-06-13 19:25:02,926 DEBUG [c.c.a.ApiServlet] (catalina-exec-17:ctx-4cbd679f) ===START===  192.168.16.45 -- GET  command=listCapacity&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687294725
> 2014-06-13 19:25:02,932 DEBUG [c.c.c.CapacityManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Found 0 VM, not running on host 2
> 2014-06-13 19:25:02,948 DEBUG [c.c.c.CapacityManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) No need to calibrate cpu capacity, host:2 usedCpu: 0 reservedCpu: 0
> 2014-06-13 19:25:02,948 DEBUG [c.c.c.CapacityManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) No need to calibrate memory capacity, host:2 usedMem: 0 reservedMem: 0
> 2014-06-13 19:25:02,949 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: SshKeysDistriMonitor
> 2014-06-13 19:25:02,971 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-6:ctx-ed43cab0) already have a vif on dom0 for link local network
> 2014-06-13 19:25:02,982 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773895: Sending  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] }
> 2014-06-13 19:25:02,983 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773895: Executing:  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100011, [{"com.cloud.agent.api.ModifySshKeysCommand":{"wait":0}}] }
> 2014-06-13 19:25:02,991 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-3:ctx-d52bb49b) Seq 2-1956773895: Executing request
> 2014-06-13 19:25:02,991 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-3:ctx-d52bb49b) Seq 2-1956773895: Response Received:
> 2014-06-13 19:25:02,991 DEBUG [c.c.a.t.Request] (DirectAgent-3:ctx-d52bb49b) Seq 2-1956773895: Processing:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"wait":0}}] }
> 2014-06-13 19:25:02,999 DEBUG [c.c.a.ApiServlet] (catalina-exec-17:ctx-4cbd679f ctx-57d0f4c9) ===END===  192.168.16.45 -- GET  command=listCapacity&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687294725
> 2014-06-13 19:25:03,006 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: VirtualNetworkApplianceManagerImpl
> 2014-06-13 19:25:03,007 DEBUG [c.c.a.ApiServlet] (catalina-exec-19:ctx-c2eb49e2) ===START===  192.168.16.45 -- GET  command=listHypervisors&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687294808
> 2014-06-13 19:25:03,011 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: LocalStoragePoolListener
> 2014-06-13 19:25:03,012 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: ConsoleProxyListener
> 2014-06-13 19:25:03,012 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: DirectNetworkStatsListener
> 2014-06-13 19:25:03,012 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: BehindOnPingListener
> 2014-06-13 19:25:03,012 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Sending Connect to listener: DownloadListener
> 2014-06-13 19:25:03,029 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773896: Sending  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.ReadyCommand":{"dcId":1,"hostId":2,"wait":0}}] }
> 2014-06-13 19:25:03,029 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773896: Executing:  { Cmd , MgmtId: 240491168032724, via: 2(CP-HOST-01), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.ReadyCommand":{"dcId":1,"hostId":2,"wait":0}}] }
> 2014-06-13 19:25:03,030 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-11:ctx-e94bf3ef) Seq 2-1956773896: Executing request
> 2014-06-13 19:25:03,072 DEBUG [c.c.a.ApiServlet] (catalina-exec-19:ctx-c2eb49e2 ctx-0ccdd546) ===END===  192.168.16.45 -- GET  command=listHypervisors&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687294808
> 2014-06-13 19:25:03,080 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-fd304711) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=Hyperv&page=1&pagesize=20&_=1402687294881
> 2014-06-13 19:25:03,099 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-20:ctx-fd304711 ctx-45f22286) >>>Searching for hosts>>>
> 2014-06-13 19:25:03,150 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-20:ctx-fd304711 ctx-45f22286) >>>Generating Response>>>
> 2014-06-13 19:25:03,151 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-fd304711 ctx-45f22286) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=Hyperv&page=1&pagesize=20&_=1402687294881
> 2014-06-13 19:25:03,163 DEBUG [c.c.a.ApiServlet] (catalina-exec-22:ctx-3ea0bc5f) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=KVM&page=1&pagesize=20&_=1402687294962
> 2014-06-13 19:25:03,182 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-22:ctx-3ea0bc5f ctx-4dc898c0) >>>Searching for hosts>>>
> 2014-06-13 19:25:03,190 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-22:ctx-3ea0bc5f ctx-4dc898c0) >>>Generating Response>>>
> 2014-06-13 19:25:03,191 DEBUG [c.c.a.ApiServlet] (catalina-exec-22:ctx-3ea0bc5f ctx-4dc898c0) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=KVM&page=1&pagesize=20&_=1402687294962
> 2014-06-13 19:25:03,199 DEBUG [c.c.a.ApiServlet] (catalina-exec-21:ctx-df6758b1) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=XenServer&page=1&pagesize=20&_=1402687295000
> 2014-06-13 19:25:03,223 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-11:ctx-e94bf3ef) already have a vif on dom0 for link local network
> 2014-06-13 19:25:03,235 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-21:ctx-df6758b1 ctx-b28bf34c) >>>Searching for hosts>>>
> 2014-06-13 19:25:03,260 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-21:ctx-df6758b1 ctx-b28bf34c) >>>Generating Response>>>
> 2014-06-13 19:25:03,311 DEBUG [c.c.a.ApiServlet] (catalina-exec-21:ctx-df6758b1 ctx-b28bf34c) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=XenServer&page=1&pagesize=20&_=1402687295000
> 2014-06-13 19:25:03,399 DEBUG [c.c.a.ApiServlet] (catalina-exec-23:ctx-92af79ce) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=VMware&page=1&pagesize=20&_=1402687295121
> 2014-06-13 19:25:03,415 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-23:ctx-92af79ce ctx-13d392b4) >>>Searching for hosts>>>
> 2014-06-13 19:25:03,425 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-23:ctx-92af79ce ctx-13d392b4) >>>Generating Response>>>
> 2014-06-13 19:25:03,426 DEBUG [c.c.a.ApiServlet] (catalina-exec-23:ctx-92af79ce ctx-13d392b4) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=VMware&page=1&pagesize=20&_=1402687295121
> 2014-06-13 19:25:03,447 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-6:ctx-ed43cab0) Seq 1-1847328776: Response Received:
> 2014-06-13 19:25:03,448 DEBUG [c.c.a.t.Request] (DirectAgent-6:ctx-ed43cab0) Seq 1-1847328776: Processing:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 110, [{"com.cloud.agent.api.ReadyAnswer":{"result":true,"wait":0}}] }
> 2014-06-13 19:25:03,448 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-0b484d87) Seq 1-1847328776: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 110, { ReadyAnswer } }
> 2014-06-13 19:25:03,448 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-6:ctx-ed43cab0) Seq 1-1847328776: No more commands found
> 2014-06-13 19:25:03,448 DEBUG [c.c.h.Status] (AgentTaskPool-1:ctx-0b484d87) Transition:[Resource state = Enabled, Agent event = Ready, Host id = 1, name = CP-HOST-02]
> 2014-06-13 19:25:03,496 DEBUG [c.c.a.ApiServlet] (catalina-exec-24:ctx-2e82b11a) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=BareMetal&page=1&pagesize=20&_=1402687295235
> 2014-06-13 19:25:03,499 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-0b484d87) Completed creating agent for host 1
> 2014-06-13 19:25:03,519 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-24:ctx-2e82b11a ctx-867eddca) >>>Searching for hosts>>>
> 2014-06-13 19:25:03,544 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-24:ctx-2e82b11a ctx-867eddca) >>>Generating Response>>>
> 2014-06-13 19:25:03,544 DEBUG [c.c.a.ApiServlet] (catalina-exec-24:ctx-2e82b11a ctx-867eddca) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=BareMetal&page=1&pagesize=20&_=1402687295235
> 2014-06-13 19:25:03,614 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-11:ctx-e94bf3ef) Seq 2-1956773896: Response Received:
> 2014-06-13 19:25:03,615 DEBUG [c.c.a.t.Request] (DirectAgent-11:ctx-e94bf3ef) Seq 2-1956773896: Processing:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 110, [{"com.cloud.agent.api.ReadyAnswer":{"result":true,"wait":0}}] }
> 2014-06-13 19:25:03,615 DEBUG [c.c.a.t.Request] (AgentTaskPool-2:ctx-7fb2f798) Seq 2-1956773896: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 110, { ReadyAnswer } }
> 2014-06-13 19:25:03,615 DEBUG [c.c.h.Status] (AgentTaskPool-2:ctx-7fb2f798) Transition:[Resource state = Enabled, Agent event = Ready, Host id = 2, name = CP-HOST-01]
> 2014-06-13 19:25:03,616 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-11:ctx-e94bf3ef) Seq 2-1956773896: No more commands found
> 2014-06-13 19:25:03,621 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-0150be6f) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=Ovm&page=1&pagesize=20&_=1402687295353
> 2014-06-13 19:25:03,637 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-2:ctx-0150be6f ctx-d8e73987) >>>Searching for hosts>>>
> 2014-06-13 19:25:03,647 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-2:ctx-0150be6f ctx-d8e73987) >>>Generating Response>>>
> 2014-06-13 19:25:03,648 DEBUG [c.c.a.ApiServlet] (catalina-exec-2:ctx-0150be6f ctx-d8e73987) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=Ovm&page=1&pagesize=20&_=1402687295353
> 2014-06-13 19:25:03,649 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-2:ctx-7fb2f798) Completed creating agent for host 2
> 2014-06-13 19:25:03,717 DEBUG [c.c.a.ApiServlet] (catalina-exec-25:ctx-d363e9b6) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=LXC&page=1&pagesize=20&_=1402687295460
> 2014-06-13 19:25:03,739 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-25:ctx-d363e9b6 ctx-471ad2f2) >>>Searching for hosts>>>
> 2014-06-13 19:25:03,744 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-25:ctx-d363e9b6 ctx-471ad2f2) >>>Generating Response>>>
> 2014-06-13 19:25:03,745 DEBUG [c.c.a.ApiServlet] (catalina-exec-25:ctx-d363e9b6 ctx-471ad2f2) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=LXC&page=1&pagesize=20&_=1402687295460
> 2014-06-13 19:25:07,271 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-10eb52be) HostStatsCollector is running...
> 2014-06-13 19:25:07,272 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-0d967237) VmStatsCollector is running...
> 2014-06-13 19:25:07,288 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-b2c342e1) StorageCollector is running...
> 2014-06-13 19:25:07,312 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-b2c342e1) There is no secondary storage VM for secondary storage host CPSS
> 2014-06-13 19:25:07,322 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-5:ctx-3ed66343) Seq 1-1847328777: Executing request
> 2014-06-13 19:25:07,330 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-19:ctx-f0059bbe) Seq 2-1956773897: Executing request
> 2014-06-13 19:25:07,356 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-5:ctx-3ed66343) Seq 1-1847328777: Response Received:
> 2014-06-13 19:25:07,357 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-10eb52be) Seq 1-1847328777: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:25:07,377 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-14:ctx-1017d222) Seq 2-1956773898: Executing request
> 2014-06-13 19:25:07,416 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-14:ctx-1017d222) Seq 2-1956773898: Response Received:
> 2014-06-13 19:25:07,417 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-10eb52be) Seq 2-1956773898: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:25:07,520 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.OfferingDaoImpl_EnhancerByCloudStack_8611176e
> 2014-06-13 19:25:07,534 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.CloudStackAccountDaoImpl_EnhancerByCloudStack_f106a814
> 2014-06-13 19:25:07,534 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.SMetaDaoImpl_EnhancerByCloudStack_a2b80766
> 2014-06-13 19:25:07,534 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.UserCredentialsDaoImpl_EnhancerByCloudStack_43b9d285
> 2014-06-13 19:25:07,535 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.MultipartMetaDaoImpl_EnhancerByCloudStack_8a208a25
> 2014-06-13 19:25:07,536 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.CloudStackConfigurationDaoImpl_EnhancerByCloudStack_b1ec1a43
> 2014-06-13 19:25:07,537 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.BucketPolicyDaoImpl_EnhancerByCloudStack_9868408
> 2014-06-13 19:25:07,538 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.SObjectItemDaoImpl_EnhancerByCloudStack_ed993bd1
> 2014-06-13 19:25:07,538 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.MHostMountDaoImpl_EnhancerByCloudStack_429c6fe0
> 2014-06-13 19:25:07,539 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.MHostDaoImpl_EnhancerByCloudStack_b4849221
> 2014-06-13 19:25:07,540 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.MultiPartUploadsDaoImpl_EnhancerByCloudStack_6ff9374e
> 2014-06-13 19:25:07,541 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.SBucketDaoImpl_EnhancerByCloudStack_41357419
> 2014-06-13 19:25:07,542 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.SAclDaoImpl_EnhancerByCloudStack_b4244c95
> 2014-06-13 19:25:07,542 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.MultiPartPartsDaoImpl_EnhancerByCloudStack_3bf361d0
> 2014-06-13 19:25:07,543 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.CloudStackSvcOfferingDaoImpl_EnhancerByCloudStack_3b494e33
> 2014-06-13 19:25:07,544 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.SHostDaoImpl_EnhancerByCloudStack_dd17086b
> 2014-06-13 19:25:07,545 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.SObjectDaoImpl_EnhancerByCloudStack_c3f1785c
> 2014-06-13 19:25:07,545 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.persist.dao.CloudStackUserDaoImpl_EnhancerByCloudStack_bf3ffdb6
> 2014-06-13 19:25:07,552 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.service.core.ec2.EC2Engine_EnhancerByCloudStack_167e5d0c
> 2014-06-13 19:25:07,642 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-19:ctx-f0059bbe) Seq 2-1956773897: Response Received:
> 2014-06-13 19:25:07,643 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-b2c342e1) Seq 2-1956773897: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2014-06-13 19:25:07,697 INFO  [c.c.u.c.ComponentContext] (main:null) Configuring com.cloud.bridge.service.controller.s3.ServiceProvider_EnhancerByCloudStack_41aef781
> 2014-06-13 19:25:07,896 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.OfferingDaoImpl_EnhancerByCloudStack_8611176e
> 2014-06-13 19:25:07,897 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.CloudStackAccountDaoImpl_EnhancerByCloudStack_f106a814
> 2014-06-13 19:25:07,897 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.SMetaDaoImpl_EnhancerByCloudStack_a2b80766
> 2014-06-13 19:25:07,897 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.UserCredentialsDaoImpl_EnhancerByCloudStack_43b9d285
> 2014-06-13 19:25:07,897 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.MultipartMetaDaoImpl_EnhancerByCloudStack_8a208a25
> 2014-06-13 19:25:07,897 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.CloudStackConfigurationDaoImpl_EnhancerByCloudStack_b1ec1a43
> 2014-06-13 19:25:07,897 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.BucketPolicyDaoImpl_EnhancerByCloudStack_9868408
> 2014-06-13 19:25:07,898 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.SObjectItemDaoImpl_EnhancerByCloudStack_ed993bd1
> 2014-06-13 19:25:07,898 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.MHostMountDaoImpl_EnhancerByCloudStack_429c6fe0
> 2014-06-13 19:25:07,898 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.MHostDaoImpl_EnhancerByCloudStack_b4849221
> 2014-06-13 19:25:07,898 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.MultiPartUploadsDaoImpl_EnhancerByCloudStack_6ff9374e
> 2014-06-13 19:25:07,898 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.SBucketDaoImpl_EnhancerByCloudStack_41357419
> 2014-06-13 19:25:07,898 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.SAclDaoImpl_EnhancerByCloudStack_b4244c95
> 2014-06-13 19:25:07,898 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.MultiPartPartsDaoImpl_EnhancerByCloudStack_3bf361d0
> 2014-06-13 19:25:07,898 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.CloudStackSvcOfferingDaoImpl_EnhancerByCloudStack_3b494e33
> 2014-06-13 19:25:07,898 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.SHostDaoImpl_EnhancerByCloudStack_dd17086b
> 2014-06-13 19:25:07,898 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.SObjectDaoImpl_EnhancerByCloudStack_c3f1785c
> 2014-06-13 19:25:07,899 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.persist.dao.CloudStackUserDaoImpl_EnhancerByCloudStack_bf3ffdb6
> 2014-06-13 19:25:07,899 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.service.core.ec2.EC2Engine_EnhancerByCloudStack_167e5d0c
> 2014-06-13 19:25:07,899 INFO  [c.c.u.c.ComponentContext] (main:null) Starting com.cloud.bridge.service.controller.s3.ServiceProvider_EnhancerByCloudStack_41aef781
> 2014-06-13 19:25:22,135 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-9a97a229) Found 0 routers to update status.
> 2014-06-13 19:25:22,139 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-9a97a229) Found 0 networks to update RvR status.
> 2014-06-13 19:25:22,285 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (HostReservationReleaseChecker:ctx-ad2ac015) Checking if any host reservation can be released ...
> 2014-06-13 19:25:22,288 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (HostReservationReleaseChecker:ctx-ad2ac015) Done running HostReservationReleaseChecker ...
> 2014-06-13 19:25:22,353 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-a4c07666) Running Capacity Checker ...
> 2014-06-13 19:25:22,354 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-a4c07666) recalculating system capacity
> 2014-06-13 19:25:22,354 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-a4c07666) Executing cpu/ram capacity update
> 2014-06-13 19:25:22,374 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-a4c07666) Found 0 VMs on host 1
> 2014-06-13 19:25:22,378 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-a4c07666) Found 0 VM, not running on host 1
> 2014-06-13 19:25:22,381 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-a4c07666) No need to calibrate cpu capacity, host:1 usedCpu: 0 reservedCpu: 0
> 2014-06-13 19:25:22,382 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-a4c07666) No need to calibrate memory capacity, host:1 usedMem: 0 reservedMem: 0
> 2014-06-13 19:25:22,410 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-a4c07666) Found 0 VMs on host 2
> 2014-06-13 19:25:22,418 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-a4c07666) Found 0 VM, not running on host 2
> 2014-06-13 19:25:22,425 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-a4c07666) No need to calibrate cpu capacity, host:2 usedCpu: 0 reservedCpu: 0
> 2014-06-13 19:25:22,425 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-a4c07666) No need to calibrate memory capacity, host:2 usedMem: 0 reservedMem: 0
> 2014-06-13 19:25:22,426 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-a4c07666) Done executing cpu/ram capacity update
> 2014-06-13 19:25:22,426 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-a4c07666) Executing storage capacity update
> 2014-06-13 19:25:22,451 DEBUG [c.c.s.StorageManagerImpl] (CapacityChecker:ctx-a4c07666) Successfully set Capacity - 2675965952 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 3, PodId 1
> 2014-06-13 19:25:22,451 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-a4c07666) Done executing storage capacity update
> 2014-06-13 19:25:22,451 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-a4c07666) Executing capacity updates for public ip and Vlans
> 2014-06-13 19:25:22,506 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-a4c07666) Done capacity updates for public ip and Vlans
> 2014-06-13 19:25:22,506 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-a4c07666) Executing capacity updates for private ip
> 2014-06-13 19:25:22,523 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-a4c07666) Done executing capacity updates for private ip
> 2014-06-13 19:25:22,523 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-a4c07666) Done recalculating system capacity
> 2014-06-13 19:25:22,562 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-a4c07666) Done running Capacity Checker ...
> 2014-06-13 19:25:52,134 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-b0604ca3) Found 0 routers to update status.
> 2014-06-13 19:25:52,137 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-b0604ca3) Found 0 networks to update RvR status.
> 2014-06-13 19:26:01,409 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-10:ctx-a317748e) Ping from 1(CP-HOST-02)
> 2014-06-13 19:26:01,409 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-10:ctx-a317748e) Process host VM state report from ping process. host: 1
> 2014-06-13 19:26:01,409 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-10:ctx-a317748e) Process VM state report. host: 1, number of records in report: 0
> 2014-06-13 19:26:01,413 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-10:ctx-a317748e) Done with process of VM state report. host: 1
> 2014-06-13 19:26:01,908 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-1:ctx-24b7bc89) Ping from 2(CP-HOST-01)
> 2014-06-13 19:26:01,908 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-1:ctx-24b7bc89) Process host VM state report from ping process. host: 2
> 2014-06-13 19:26:01,908 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-1:ctx-24b7bc89) Process VM state report. host: 2, number of records in report: 0
> 2014-06-13 19:26:01,912 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-1:ctx-24b7bc89) Done with process of VM state report. host: 2
> 2014-06-13 19:26:07,303 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-2810c471) VmStatsCollector is running...
> 2014-06-13 19:26:07,417 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-75f959d9) HostStatsCollector is running...
> 2014-06-13 19:26:07,437 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-16:ctx-ef498128) Seq 1-1847328778: Executing request
> 2014-06-13 19:26:07,478 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-16:ctx-ef498128) Seq 1-1847328778: Response Received:
> 2014-06-13 19:26:07,478 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-75f959d9) Seq 1-1847328778: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:26:07,493 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-3:ctx-c8b53d98) Seq 2-1956773899: Executing request
> 2014-06-13 19:26:07,526 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-3:ctx-c8b53d98) Seq 2-1956773899: Response Received:
> 2014-06-13 19:26:07,526 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-75f959d9) Seq 2-1956773899: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:26:07,644 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-6afd77aa) StorageCollector is running...
> 2014-06-13 19:26:07,653 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-6afd77aa) There is no secondary storage VM for secondary storage host CPSS
> 2014-06-13 19:26:07,659 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-18:ctx-06dfe1cf) Seq 2-1956773900: Executing request
> 2014-06-13 19:26:07,947 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-18:ctx-06dfe1cf) Seq 2-1956773900: Response Received:
> 2014-06-13 19:26:07,948 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-6afd77aa) Seq 2-1956773900: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2014-06-13 19:26:22,135 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-29129121) Found 0 routers to update status.
> 2014-06-13 19:26:22,138 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-29129121) Found 0 networks to update RvR status.
> 2014-06-13 19:26:27,377 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-54bb630d) Resetting hosts suitable for reconnect
> 2014-06-13 19:26:27,380 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-54bb630d) Completed resetting hosts suitable for reconnect
> 2014-06-13 19:26:27,380 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-54bb630d) Acquiring hosts for clusters already owned by this management server
> 2014-06-13 19:26:27,382 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-54bb630d) Completed acquiring hosts for clusters already owned by this management server
> 2014-06-13 19:26:27,382 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-54bb630d) Acquiring hosts for clusters not owned by any management server
> 2014-06-13 19:26:27,383 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-54bb630d) Completed acquiring hosts for clusters not owned by any management server
> 2014-06-13 19:26:52,135 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-cd5124d0) Found 0 routers to update status.
> 2014-06-13 19:26:52,138 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-cd5124d0) Found 0 networks to update RvR status.
> 2014-06-13 19:27:01,395 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-6:ctx-a0436124) Ping from 1(CP-HOST-02)
> 2014-06-13 19:27:01,395 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-6:ctx-a0436124) Process host VM state report from ping process. host: 1
> 2014-06-13 19:27:01,395 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-6:ctx-a0436124) Process VM state report. host: 1, number of records in report: 0
> 2014-06-13 19:27:01,398 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-6:ctx-a0436124) Done with process of VM state report. host: 1
> 2014-06-13 19:27:01,896 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-11:ctx-b5625016) Ping from 2(CP-HOST-01)
> 2014-06-13 19:27:01,897 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-11:ctx-b5625016) Process host VM state report from ping process. host: 2
> 2014-06-13 19:27:01,897 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-11:ctx-b5625016) Process VM state report. host: 2, number of records in report: 0
> 2014-06-13 19:27:01,900 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-11:ctx-b5625016) Done with process of VM state report. host: 2
> 2014-06-13 19:27:07,313 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-d9ecd69a) VmStatsCollector is running...
> 2014-06-13 19:27:07,527 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-3a1e4f5e) HostStatsCollector is running...
> 2014-06-13 19:27:07,545 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-20:ctx-402b5bf8) Seq 1-1847328779: Executing request
> 2014-06-13 19:27:07,580 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-20:ctx-402b5bf8) Seq 1-1847328779: Response Received:
> 2014-06-13 19:27:07,581 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-3a1e4f5e) Seq 1-1847328779: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:27:07,595 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-21:ctx-ab66fcd4) Seq 2-1956773901: Executing request
> 2014-06-13 19:27:07,633 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-21:ctx-ab66fcd4) Seq 2-1956773901: Response Received:
> 2014-06-13 19:27:07,633 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-3a1e4f5e) Seq 2-1956773901: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:27:07,949 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-eba5ed7f) StorageCollector is running...
> 2014-06-13 19:27:07,957 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-eba5ed7f) There is no secondary storage VM for secondary storage host CPSS
> 2014-06-13 19:27:07,963 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-19:ctx-34263265) Seq 2-1956773902: Executing request
> 2014-06-13 19:27:08,244 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-19:ctx-34263265) Seq 2-1956773902: Response Received:
> 2014-06-13 19:27:08,245 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-eba5ed7f) Seq 2-1956773902: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2014-06-13 19:27:22,135 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-ec16046e) Found 0 routers to update status.
> 2014-06-13 19:27:22,137 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-ec16046e) Found 0 networks to update RvR status.
> 2014-06-13 19:27:52,134 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-3c41f8dc) Found 0 routers to update status.
> 2014-06-13 19:27:52,137 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-3c41f8dc) Found 0 networks to update RvR status.
> 2014-06-13 19:27:57,376 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-e713bb96) Resetting hosts suitable for reconnect
> 2014-06-13 19:27:57,379 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-e713bb96) Completed resetting hosts suitable for reconnect
> 2014-06-13 19:27:57,379 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-e713bb96) Acquiring hosts for clusters already owned by this management server
> 2014-06-13 19:27:57,381 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-e713bb96) Completed acquiring hosts for clusters already owned by this management server
> 2014-06-13 19:27:57,381 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-e713bb96) Acquiring hosts for clusters not owned by any management server
> 2014-06-13 19:27:57,400 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-e713bb96) Completed acquiring hosts for clusters not owned by any management server
> 2014-06-13 19:28:01,400 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-5:ctx-06a8b6f0) Ping from 1(CP-HOST-02)
> 2014-06-13 19:28:01,400 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-5:ctx-06a8b6f0) Process host VM state report from ping process. host: 1
> 2014-06-13 19:28:01,400 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-5:ctx-06a8b6f0) Process VM state report. host: 1, number of records in report: 0
> 2014-06-13 19:28:01,404 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-5:ctx-06a8b6f0) Done with process of VM state report. host: 1
> 2014-06-13 19:28:01,903 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-15:ctx-fa4d85df) Ping from 2(CP-HOST-01)
> 2014-06-13 19:28:01,904 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-15:ctx-fa4d85df) Process host VM state report from ping process. host: 2
> 2014-06-13 19:28:01,904 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-15:ctx-fa4d85df) Process VM state report. host: 2, number of records in report: 0
> 2014-06-13 19:28:01,907 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-15:ctx-fa4d85df) Done with process of VM state report. host: 2
> 2014-06-13 19:28:02,398 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-12:ctx-1b763a34) Seq 1-1847328772: Executing request
> 2014-06-13 19:28:02,414 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-12:ctx-1b763a34) Seq 1-1847328772: Response Received:
> 2014-06-13 19:28:02,415 DEBUG [c.c.a.t.Request] (DirectAgent-12:ctx-1b763a34) Seq 1-1847328772: Processing:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ClusterVMMetaDataSyncAnswer":{"_clusterId":1,"_isExecuted":false,"result":true,"wait":0}}] }
> 2014-06-13 19:28:02,622 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-13:ctx-f570d2ac) Seq 2-1956773892: Executing request
> 2014-06-13 19:28:02,780 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-13:ctx-f570d2ac) Seq 2-1956773892: Response Received:
> 2014-06-13 19:28:02,780 DEBUG [c.c.a.t.Request] (DirectAgent-13:ctx-f570d2ac) Seq 2-1956773892: Processing:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ClusterVMMetaDataSyncAnswer":{"_clusterId":1,"_vmMetaDatum":{},"_isExecuted":false,"result":true,"wait":0}}] }
> 2014-06-13 19:28:07,323 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-51e5ea3f) VmStatsCollector is running...
> 2014-06-13 19:28:07,634 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-cc3fa375) HostStatsCollector is running...
> 2014-06-13 19:28:07,652 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-7:ctx-f5428859) Seq 1-1847328780: Executing request
> 2014-06-13 19:28:07,676 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-7:ctx-f5428859) Seq 1-1847328780: Response Received:
> 2014-06-13 19:28:07,677 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-cc3fa375) Seq 1-1847328780: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:28:07,702 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-22:ctx-f89a875b) Seq 2-1956773903: Executing request
> 2014-06-13 19:28:07,721 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-22:ctx-f89a875b) Seq 2-1956773903: Response Received:
> 2014-06-13 19:28:07,722 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-cc3fa375) Seq 2-1956773903: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:28:08,246 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-4590cc84) StorageCollector is running...
> 2014-06-13 19:28:08,254 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-4590cc84) There is no secondary storage VM for secondary storage host CPSS
> 2014-06-13 19:28:08,260 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-23:ctx-5e896e56) Seq 1-1847328781: Executing request
> 2014-06-13 19:28:08,539 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-23:ctx-5e896e56) Seq 1-1847328781: Response Received:
> 2014-06-13 19:28:08,539 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-4590cc84) Seq 1-1847328781: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2014-06-13 19:28:22,135 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-99da0f4d) Found 0 routers to update status.
> 2014-06-13 19:28:22,138 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-99da0f4d) Found 0 networks to update RvR status.
> 2014-06-13 19:28:52,135 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-5da54d04) Found 0 routers to update status.
> 2014-06-13 19:28:52,138 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-5da54d04) Found 0 networks to update RvR status.
> 2014-06-13 19:29:01,400 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-10:ctx-503d6369) Ping from 1(CP-HOST-02)
> 2014-06-13 19:29:01,400 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-10:ctx-503d6369) Process host VM state report from ping process. host: 1
> 2014-06-13 19:29:01,400 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-10:ctx-503d6369) Process VM state report. host: 1, number of records in report: 0
> 2014-06-13 19:29:01,403 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-10:ctx-503d6369) Done with process of VM state report. host: 1
> 2014-06-13 19:29:01,907 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-24:ctx-e52af5b2) Ping from 2(CP-HOST-01)
> 2014-06-13 19:29:01,907 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-24:ctx-e52af5b2) Process host VM state report from ping process. host: 2
> 2014-06-13 19:29:01,907 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-24:ctx-e52af5b2) Process VM state report. host: 2, number of records in report: 0
> 2014-06-13 19:29:01,910 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-24:ctx-e52af5b2) Done with process of VM state report. host: 2
> 2014-06-13 19:29:07,332 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-0e5d962b) VmStatsCollector is running...
> 2014-06-13 19:29:07,723 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-cccc50ab) HostStatsCollector is running...
> 2014-06-13 19:29:07,741 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-25:ctx-9d241fea) Seq 1-1847328782: Executing request
> 2014-06-13 19:29:07,775 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-25:ctx-9d241fea) Seq 1-1847328782: Response Received:
> 2014-06-13 19:29:07,776 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-cccc50ab) Seq 1-1847328782: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:29:07,790 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-26:ctx-6de67a6d) Seq 2-1956773904: Executing request
> 2014-06-13 19:29:07,823 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-26:ctx-6de67a6d) Seq 2-1956773904: Response Received:
> 2014-06-13 19:29:07,824 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-cccc50ab) Seq 2-1956773904: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:29:08,541 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-9a8f6511) StorageCollector is running...
> 2014-06-13 19:29:08,559 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-9a8f6511) There is no secondary storage VM for secondary storage host CPSS
> 2014-06-13 19:29:08,565 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-8:ctx-8d1d40b9) Seq 2-1956773905: Executing request
> 2014-06-13 19:29:08,846 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-8:ctx-8d1d40b9) Seq 2-1956773905: Response Received:
> 2014-06-13 19:29:08,847 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-9a8f6511) Seq 2-1956773905: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2014-06-13 19:29:22,135 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-c7f8ea48) Found 0 routers to update status.
> 2014-06-13 19:29:22,137 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-c7f8ea48) Found 0 networks to update RvR status.
> 2014-06-13 19:29:27,376 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-ae155444) Resetting hosts suitable for reconnect
> 2014-06-13 19:29:27,378 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-ae155444) Completed resetting hosts suitable for reconnect
> 2014-06-13 19:29:27,378 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-ae155444) Acquiring hosts for clusters already owned by this management server
> 2014-06-13 19:29:27,380 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-ae155444) Completed acquiring hosts for clusters already owned by this management server
> 2014-06-13 19:29:27,380 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-ae155444) Acquiring hosts for clusters not owned by any management server
> 2014-06-13 19:29:27,381 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-ae155444) Completed acquiring hosts for clusters not owned by any management server
> 2014-06-13 19:29:52,109 DEBUG [c.c.n.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:ctx-ae8822bb) External devices stats collector is running...
> 2014-06-13 19:29:52,132 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:ctx-8b413ef4) Found 0 running routers.
> 2014-06-13 19:29:52,134 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-1e0dd8b1) Found 0 routers to update status.
> 2014-06-13 19:29:52,136 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-1e0dd8b1) Found 0 networks to update RvR status.
> 2014-06-13 19:29:52,182 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (SnapshotPollTask:ctx-45a12412) Snapshot scheduler.poll is being called at 2014-06-13 19:29:52 GMT
> 2014-06-13 19:29:52,185 DEBUG [c.c.s.s.SnapshotSchedulerImpl] (SnapshotPollTask:ctx-45a12412) Got 0 snapshots to be executed at 2014-06-13 19:29:52 GMT
> 2014-06-13 19:30:01,402 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-3:ctx-e8dd9c19) Ping from 1(CP-HOST-02)
> 2014-06-13 19:30:01,402 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-3:ctx-e8dd9c19) Process host VM state report from ping process. host: 1
> 2014-06-13 19:30:01,402 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-3:ctx-e8dd9c19) Process VM state report. host: 1, number of records in report: 0
> 2014-06-13 19:30:01,405 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-3:ctx-e8dd9c19) Done with process of VM state report. host: 1
> 2014-06-13 19:30:01,902 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-17:ctx-547291ea) Ping from 2(CP-HOST-01)
> 2014-06-13 19:30:01,902 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-17:ctx-547291ea) Process host VM state report from ping process. host: 2
> 2014-06-13 19:30:01,902 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-17:ctx-547291ea) Process VM state report. host: 2, number of records in report: 0
> 2014-06-13 19:30:01,905 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-17:ctx-547291ea) Done with process of VM state report. host: 2
> 2014-06-13 19:30:07,342 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-06a2cbd6) VmStatsCollector is running...
> 2014-06-13 19:30:07,824 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-8b79c53b) HostStatsCollector is running...
> 2014-06-13 19:30:07,842 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-6:ctx-6c9cac8b) Seq 1-1847328783: Executing request
> 2014-06-13 19:30:07,879 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-6:ctx-6c9cac8b) Seq 1-1847328783: Response Received:
> 2014-06-13 19:30:07,879 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-8b79c53b) Seq 1-1847328783: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:30:07,893 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-11:ctx-dcc725b6) Seq 2-1956773906: Executing request
> 2014-06-13 19:30:07,933 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-11:ctx-dcc725b6) Seq 2-1956773906: Response Received:
> 2014-06-13 19:30:07,935 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-8b79c53b) Seq 2-1956773906: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:30:08,847 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-63679d8a) StorageCollector is running...
> 2014-06-13 19:30:08,855 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-63679d8a) There is no secondary storage VM for secondary storage host CPSS
> 2014-06-13 19:30:08,861 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-29:ctx-2d845828) Seq 2-1956773907: Executing request
> 2014-06-13 19:30:09,142 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-29:ctx-2d845828) Seq 2-1956773907: Response Received:
> 2014-06-13 19:30:09,143 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-63679d8a) Seq 2-1956773907: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2014-06-13 19:30:22,135 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-d8e2203a) Found 0 routers to update status.
> 2014-06-13 19:30:22,138 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-d8e2203a) Found 0 networks to update RvR status.
> 2014-06-13 19:30:22,284 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (HostReservationReleaseChecker:ctx-66982d6e) Checking if any host reservation can be released ...
> 2014-06-13 19:30:22,287 DEBUG [c.c.d.DeploymentPlanningManagerImpl] (HostReservationReleaseChecker:ctx-66982d6e) Done running HostReservationReleaseChecker ...
> 2014-06-13 19:30:22,353 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b29bbf80) Running Capacity Checker ...
> 2014-06-13 19:30:22,353 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b29bbf80) recalculating system capacity
> 2014-06-13 19:30:22,353 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b29bbf80) Executing cpu/ram capacity update
> 2014-06-13 19:30:22,362 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-b29bbf80) Found 0 VMs on host 1
> 2014-06-13 19:30:22,365 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-b29bbf80) Found 0 VM, not running on host 1
> 2014-06-13 19:30:22,368 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-b29bbf80) No need to calibrate cpu capacity, host:1 usedCpu: 0 reservedCpu: 0
> 2014-06-13 19:30:22,368 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-b29bbf80) No need to calibrate memory capacity, host:1 usedMem: 0 reservedMem: 0
> 2014-06-13 19:30:22,379 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-b29bbf80) Found 0 VMs on host 2
> 2014-06-13 19:30:22,388 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-b29bbf80) Found 0 VM, not running on host 2
> 2014-06-13 19:30:22,393 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-b29bbf80) No need to calibrate cpu capacity, host:2 usedCpu: 0 reservedCpu: 0
> 2014-06-13 19:30:22,393 DEBUG [c.c.c.CapacityManagerImpl] (CapacityChecker:ctx-b29bbf80) No need to calibrate memory capacity, host:2 usedMem: 0 reservedMem: 0
> 2014-06-13 19:30:22,394 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b29bbf80) Done executing cpu/ram capacity update
> 2014-06-13 19:30:22,394 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b29bbf80) Executing storage capacity update
> 2014-06-13 19:30:22,405 DEBUG [c.c.s.StorageManagerImpl] (CapacityChecker:ctx-b29bbf80) Successfully set Capacity - 2675965952 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 3, PodId 1
> 2014-06-13 19:30:22,405 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b29bbf80) Done executing storage capacity update
> 2014-06-13 19:30:22,405 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b29bbf80) Executing capacity updates for public ip and Vlans
> 2014-06-13 19:30:22,443 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b29bbf80) Done capacity updates for public ip and Vlans
> 2014-06-13 19:30:22,444 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b29bbf80) Executing capacity updates for private ip
> 2014-06-13 19:30:22,458 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b29bbf80) Done executing capacity updates for private ip
> 2014-06-13 19:30:22,458 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b29bbf80) Done recalculating system capacity
> 2014-06-13 19:30:22,493 DEBUG [c.c.a.AlertManagerImpl] (CapacityChecker:ctx-b29bbf80) Done running Capacity Checker ...
> 2014-06-13 19:30:35,030 DEBUG [c.c.a.ApiServlet] (catalina-exec-1:ctx-5facfe36) ===START===  192.168.16.45 -- GET  command=listZones&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687626845
> 2014-06-13 19:30:35,055 DEBUG [c.c.a.ApiServlet] (catalina-exec-1:ctx-5facfe36 ctx-a43bb928) ===END===  192.168.16.45 -- GET  command=listZones&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687626845
> 2014-06-13 19:30:35,064 DEBUG [c.c.a.ApiServlet] (catalina-exec-5:ctx-51011b85) ===START===  192.168.16.45 -- GET  command=listPods&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687626883
> 2014-06-13 19:30:35,089 DEBUG [c.c.a.ApiServlet] (catalina-exec-5:ctx-51011b85 ctx-36c65828) ===END===  192.168.16.45 -- GET  command=listPods&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687626883
> 2014-06-13 19:30:35,098 DEBUG [c.c.a.ApiServlet] (catalina-exec-4:ctx-e0e4cf4d) ===START===  192.168.16.45 -- GET  command=listClusters&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687626918
> 2014-06-13 19:30:35,119 DEBUG [c.c.a.ApiServlet] (catalina-exec-4:ctx-e0e4cf4d ctx-8f706851) ===END===  192.168.16.45 -- GET  command=listClusters&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687626918
> 2014-06-13 19:30:35,169 DEBUG [c.c.a.ApiServlet] (catalina-exec-6:ctx-df193432) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&listAll=true&page=1&pagesize=1&_=1402687626947
> 2014-06-13 19:30:35,179 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-6:ctx-df193432 ctx-c37c7402) >>>Searching for hosts>>>
> 2014-06-13 19:30:35,188 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-6:ctx-df193432 ctx-c37c7402) >>>Generating Response>>>
> 2014-06-13 19:30:35,198 DEBUG [c.c.a.ApiServlet] (catalina-exec-6:ctx-df193432 ctx-c37c7402) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&listAll=true&page=1&pagesize=1&_=1402687626947
> 2014-06-13 19:30:35,214 DEBUG [c.c.a.ApiServlet] (catalina-exec-3:ctx-2a382d05) ===START===  192.168.16.45 -- GET  command=listStoragePools&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687627031
> 2014-06-13 19:30:35,242 DEBUG [c.c.a.ApiServlet] (catalina-exec-3:ctx-2a382d05 ctx-ca5040fe) ===END===  192.168.16.45 -- GET  command=listStoragePools&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687627031
> 2014-06-13 19:30:35,254 DEBUG [c.c.a.ApiServlet] (catalina-exec-7:ctx-4c7277a8) ===START===  192.168.16.45 -- GET  command=listImageStores&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=SecondaryStorage&listAll=true&page=1&pagesize=1&_=1402687627071
> 2014-06-13 19:30:35,273 DEBUG [c.c.a.ApiServlet] (catalina-exec-7:ctx-4c7277a8 ctx-947e5e87) ===END===  192.168.16.45 -- GET  command=listImageStores&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=SecondaryStorage&listAll=true&page=1&pagesize=1&_=1402687627071
> 2014-06-13 19:30:35,292 DEBUG [c.c.a.ApiServlet] (catalina-exec-10:ctx-a0e7f6ef) ===START===  192.168.16.45 -- GET  command=listSystemVms&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687627101
> 2014-06-13 19:30:35,304 DEBUG [c.c.a.ApiServlet] (catalina-exec-10:ctx-a0e7f6ef ctx-0ad80e6a) ===END===  192.168.16.45 -- GET  command=listSystemVms&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687627101
> 2014-06-13 19:30:35,330 DEBUG [c.c.a.ApiServlet] (catalina-exec-11:ctx-5c47151b) ===START===  192.168.16.45 -- GET  command=listRouters&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687627132
> 2014-06-13 19:30:35,345 DEBUG [c.c.a.ApiServlet] (catalina-exec-11:ctx-5c47151b ctx-37ce924d) ===END===  192.168.16.45 -- GET  command=listRouters&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&page=1&pagesize=1&_=1402687627132
> 2014-06-13 19:30:35,372 DEBUG [c.c.a.ApiServlet] (catalina-exec-14:ctx-0ddf45da) ===START===  192.168.16.45 -- GET  command=listRouters&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&projectid=-1&page=1&pagesize=1&_=1402687627173
> 2014-06-13 19:30:35,386 DEBUG [c.c.a.ApiServlet] (catalina-exec-14:ctx-0ddf45da ctx-f663115f) ===END===  192.168.16.45 -- GET  command=listRouters&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&listAll=true&projectid=-1&page=1&pagesize=1&_=1402687627173
> 2014-06-13 19:30:35,413 DEBUG [c.c.a.ApiServlet] (catalina-exec-9:ctx-3640bcf8) ===START===  192.168.16.45 -- GET  command=listCapacity&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687627214
> 2014-06-13 19:30:35,439 DEBUG [c.c.a.ApiServlet] (catalina-exec-9:ctx-3640bcf8 ctx-08e70cc0) ===END===  192.168.16.45 -- GET  command=listCapacity&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687627214
> 2014-06-13 19:30:35,450 DEBUG [c.c.a.ApiServlet] (catalina-exec-8:ctx-f783187b) ===START===  192.168.16.45 -- GET  command=listHypervisors&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687627268
> 2014-06-13 19:30:35,462 DEBUG [c.c.a.ApiServlet] (catalina-exec-8:ctx-f783187b ctx-b42760d1) ===END===  192.168.16.45 -- GET  command=listHypervisors&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&_=1402687627268
> 2014-06-13 19:30:35,532 DEBUG [c.c.a.ApiServlet] (catalina-exec-12:ctx-ad1863ea) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=Hyperv&page=1&pagesize=20&_=1402687627290
> 2014-06-13 19:30:35,542 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-12:ctx-ad1863ea ctx-16890f03) >>>Searching for hosts>>>
> 2014-06-13 19:30:35,546 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-12:ctx-ad1863ea ctx-16890f03) >>>Generating Response>>>
> 2014-06-13 19:30:35,546 DEBUG [c.c.a.ApiServlet] (catalina-exec-12:ctx-ad1863ea ctx-16890f03) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=Hyperv&page=1&pagesize=20&_=1402687627290
> 2014-06-13 19:30:35,576 DEBUG [c.c.a.ApiServlet] (catalina-exec-16:ctx-46e357e8) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=KVM&page=1&pagesize=20&_=1402687627374
> 2014-06-13 19:30:35,586 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-16:ctx-46e357e8 ctx-aea414f6) >>>Searching for hosts>>>
> 2014-06-13 19:30:35,590 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-16:ctx-46e357e8 ctx-aea414f6) >>>Generating Response>>>
> 2014-06-13 19:30:35,591 DEBUG [c.c.a.ApiServlet] (catalina-exec-16:ctx-46e357e8 ctx-aea414f6) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=KVM&page=1&pagesize=20&_=1402687627374
> 2014-06-13 19:30:35,628 DEBUG [c.c.a.ApiServlet] (catalina-exec-13:ctx-f8586468) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=XenServer&page=1&pagesize=20&_=1402687627423
> 2014-06-13 19:30:35,638 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-13:ctx-f8586468 ctx-43ee0f01) >>>Searching for hosts>>>
> 2014-06-13 19:30:35,648 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-13:ctx-f8586468 ctx-43ee0f01) >>>Generating Response>>>
> 2014-06-13 19:30:35,666 DEBUG [c.c.a.ApiServlet] (catalina-exec-13:ctx-f8586468 ctx-43ee0f01) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=XenServer&page=1&pagesize=20&_=1402687627423
> 2014-06-13 19:30:35,744 DEBUG [c.c.a.ApiServlet] (catalina-exec-15:ctx-8f19b50a) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=VMware&page=1&pagesize=20&_=1402687627494
> 2014-06-13 19:30:35,754 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-15:ctx-8f19b50a ctx-6bfbad4a) >>>Searching for hosts>>>
> 2014-06-13 19:30:35,759 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-15:ctx-8f19b50a ctx-6bfbad4a) >>>Generating Response>>>
> 2014-06-13 19:30:35,760 DEBUG [c.c.a.ApiServlet] (catalina-exec-15:ctx-8f19b50a ctx-6bfbad4a) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=VMware&page=1&pagesize=20&_=1402687627494
> 2014-06-13 19:30:35,781 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-85f9ddd8) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=BareMetal&page=1&pagesize=20&_=1402687627589
> 2014-06-13 19:30:35,791 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-18:ctx-85f9ddd8 ctx-1742c713) >>>Searching for hosts>>>
> 2014-06-13 19:30:35,795 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-18:ctx-85f9ddd8 ctx-1742c713) >>>Generating Response>>>
> 2014-06-13 19:30:35,796 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-85f9ddd8 ctx-1742c713) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=BareMetal&page=1&pagesize=20&_=1402687627589
> 2014-06-13 19:30:35,872 DEBUG [c.c.a.ApiServlet] (catalina-exec-17:ctx-542b1b68) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=Ovm&page=1&pagesize=20&_=1402687627624
> 2014-06-13 19:30:35,882 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-17:ctx-542b1b68 ctx-5602842a) >>>Searching for hosts>>>
> 2014-06-13 19:30:35,886 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-17:ctx-542b1b68 ctx-5602842a) >>>Generating Response>>>
> 2014-06-13 19:30:35,887 DEBUG [c.c.a.ApiServlet] (catalina-exec-17:ctx-542b1b68 ctx-5602842a) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=Ovm&page=1&pagesize=20&_=1402687627624
> 2014-06-13 19:30:35,894 DEBUG [c.c.a.ApiServlet] (catalina-exec-19:ctx-5a46e6a1) ===START===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=LXC&page=1&pagesize=20&_=1402687627714
> 2014-06-13 19:30:35,903 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-19:ctx-5a46e6a1 ctx-24342408) >>>Searching for hosts>>>
> 2014-06-13 19:30:35,908 DEBUG [c.c.a.q.QueryManagerImpl] (catalina-exec-19:ctx-5a46e6a1 ctx-24342408) >>>Generating Response>>>
> 2014-06-13 19:30:35,909 DEBUG [c.c.a.ApiServlet] (catalina-exec-19:ctx-5a46e6a1 ctx-24342408) ===END===  192.168.16.45 -- GET  command=listHosts&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&type=routing&hypervisor=LXC&page=1&pagesize=20&_=1402687627714
> 2014-06-13 19:30:52,134 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-dfc2ec19) Found 0 routers to update status.
> 2014-06-13 19:30:52,137 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-dfc2ec19) Found 0 networks to update RvR status.
> 2014-06-13 19:30:53,863 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-01785a0d) ===START===  192.168.16.45 -- GET  command=listConfigurations&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&page=1&pagesize=20&_=1402687645674
> 2014-06-13 19:30:53,933 DEBUG [c.c.a.ApiServlet] (catalina-exec-20:ctx-01785a0d ctx-536225b2) ===END===  192.168.16.45 -- GET  command=listConfigurations&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&page=1&pagesize=20&_=1402687645674
> 2014-06-13 19:30:56,657 DEBUG [c.c.a.ApiServlet] (catalina-exec-22:ctx-2cab1a13) ===START===  192.168.16.45 -- GET  command=listConfigurations&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&page=1&pagesize=20&name=internal&_=1402687648447
> 2014-06-13 19:30:56,674 DEBUG [c.c.a.ApiServlet] (catalina-exec-22:ctx-2cab1a13 ctx-2b50a321) ===END===  192.168.16.45 -- GET  command=listConfigurations&response=json&sessionkey=bSfSP9u6YMDkiehXKkCvBj42yFQ%3D&page=1&pagesize=20&name=internal&_=1402687648447
> 2014-06-13 19:30:57,376 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-0450d763) Resetting hosts suitable for reconnect
> 2014-06-13 19:30:57,378 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-0450d763) Completed resetting hosts suitable for reconnect
> 2014-06-13 19:30:57,378 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-0450d763) Acquiring hosts for clusters already owned by this management server
> 2014-06-13 19:30:57,380 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-0450d763) Completed acquiring hosts for clusters already owned by this management server
> 2014-06-13 19:30:57,380 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-0450d763) Acquiring hosts for clusters not owned by any management server
> 2014-06-13 19:30:57,381 DEBUG [c.c.h.d.HostDaoImpl] (ClusteredAgentManager Timer:ctx-0450d763) Completed acquiring hosts for clusters not owned by any management server
> 2014-06-13 19:31:01,423 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-20:ctx-ef953993) Ping from 1(CP-HOST-02)
> 2014-06-13 19:31:01,423 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-20:ctx-ef953993) Process host VM state report from ping process. host: 1
> 2014-06-13 19:31:01,423 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-20:ctx-ef953993) Process VM state report. host: 1, number of records in report: 0
> 2014-06-13 19:31:01,426 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-20:ctx-ef953993) Done with process of VM state report. host: 1
> 2014-06-13 19:31:01,899 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-30:ctx-03ef17b8) Ping from 2(CP-HOST-01)
> 2014-06-13 19:31:01,899 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-30:ctx-03ef17b8) Process host VM state report from ping process. host: 2
> 2014-06-13 19:31:01,899 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-30:ctx-03ef17b8) Process VM state report. host: 2, number of records in report: 0
> 2014-06-13 19:31:01,902 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-30:ctx-03ef17b8) Done with process of VM state report. host: 2
> 2014-06-13 19:31:02,398 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-21:ctx-5a85ff4a) Seq 1-1847328772: Executing request
> 2014-06-13 19:31:02,415 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-21:ctx-5a85ff4a) Seq 1-1847328772: Response Received:
> 2014-06-13 19:31:02,415 DEBUG [c.c.a.t.Request] (DirectAgent-21:ctx-5a85ff4a) Seq 1-1847328772: Processing:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ClusterVMMetaDataSyncAnswer":{"_clusterId":1,"_isExecuted":false,"result":true,"wait":0}}] }
> 2014-06-13 19:31:02,622 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-31:ctx-390f345d) Seq 2-1956773892: Executing request
> 2014-06-13 19:31:02,779 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-31:ctx-390f345d) Seq 2-1956773892: Response Received:
> 2014-06-13 19:31:02,780 DEBUG [c.c.a.t.Request] (DirectAgent-31:ctx-390f345d) Seq 2-1956773892: Processing:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, [{"com.cloud.agent.api.ClusterVMMetaDataSyncAnswer":{"_clusterId":1,"_vmMetaDatum":{},"_isExecuted":false,"result":true,"wait":0}}] }
> 2014-06-13 19:31:07,352 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-9ad5b6fa) VmStatsCollector is running...
> 2014-06-13 19:31:07,936 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-e8029e4b) HostStatsCollector is running...
> 2014-06-13 19:31:07,966 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-9:ctx-29a5726c) Seq 1-1847328784: Executing request
> 2014-06-13 19:31:07,997 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-9:ctx-29a5726c) Seq 1-1847328784: Response Received:
> 2014-06-13 19:31:07,998 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-e8029e4b) Seq 1-1847328784: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:31:08,010 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-5:ctx-2e07dcff) Seq 2-1956773908: Executing request
> 2014-06-13 19:31:08,040 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-5:ctx-2e07dcff) Seq 2-1956773908: Response Received:
> 2014-06-13 19:31:08,040 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-e8029e4b) Seq 2-1956773908: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:31:09,143 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-08a6f6d2) StorageCollector is running...
> 2014-06-13 19:31:09,151 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-08a6f6d2) There is no secondary storage VM for secondary storage host CPSS
> 2014-06-13 19:31:09,156 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-15:ctx-b399ea66) Seq 1-1847328785: Executing request
> 2014-06-13 19:31:09,434 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-15:ctx-b399ea66) Seq 1-1847328785: Response Received:
> 2014-06-13 19:31:09,434 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-08a6f6d2) Seq 1-1847328785: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 2014-06-13 19:31:22,135 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-cb91aff9) Found 0 routers to update status.
> 2014-06-13 19:31:22,137 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-cb91aff9) Found 0 networks to update RvR status.
> 2014-06-13 19:31:52,134 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-b061b214) Found 0 routers to update status.
> 2014-06-13 19:31:52,137 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:ctx-b061b214) Found 0 networks to update RvR status.
> 2014-06-13 19:32:01,393 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-14:ctx-4bf7a05e) Ping from 1(CP-HOST-02)
> 2014-06-13 19:32:01,393 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-14:ctx-4bf7a05e) Process host VM state report from ping process. host: 1
> 2014-06-13 19:32:01,393 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-14:ctx-4bf7a05e) Process VM state report. host: 1, number of records in report: 0
> 2014-06-13 19:32:01,396 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-14:ctx-4bf7a05e) Done with process of VM state report. host: 1
> 2014-06-13 19:32:01,901 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-33:ctx-4943da7c) Ping from 2(CP-HOST-01)
> 2014-06-13 19:32:01,901 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-33:ctx-4943da7c) Process host VM state report from ping process. host: 2
> 2014-06-13 19:32:01,902 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-33:ctx-4943da7c) Process VM state report. host: 2, number of records in report: 0
> 2014-06-13 19:32:01,904 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl] (DirectAgent-33:ctx-4943da7c) Done with process of VM state report. host: 2
> 2014-06-13 19:32:07,361 DEBUG [c.c.s.StatsCollector] (StatsCollector-2:ctx-63ce06db) VmStatsCollector is running...
> 2014-06-13 19:32:08,041 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-2460c9f0) HostStatsCollector is running...
> 2014-06-13 19:32:08,057 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-34:ctx-f13a54a3) Seq 1-1847328786: Executing request
> 2014-06-13 19:32:08,093 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-34:ctx-f13a54a3) Seq 1-1847328786: Response Received:
> 2014-06-13 19:32:08,093 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-2460c9f0) Seq 1-1847328786: Received:  { Ans: , MgmtId: 240491168032724, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:32:08,107 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-35:ctx-7a2ed32f) Seq 2-1956773909: Executing request
> 2014-06-13 19:32:08,130 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-35:ctx-7a2ed32f) Seq 2-1956773909: Response Received:
> 2014-06-13 19:32:08,130 DEBUG [c.c.a.t.Request] (StatsCollector-1:ctx-2460c9f0) Seq 2-1956773909: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2014-06-13 19:32:09,435 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-e13d08cf) StorageCollector is running...
> 2014-06-13 19:32:09,442 DEBUG [c.c.s.StatsCollector] (StatsCollector-3:ctx-e13d08cf) There is no secondary storage VM for secondary storage host CPSS
> 2014-06-13 19:32:09,448 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-7:ctx-1201ed4c) Seq 2-1956773910: Executing request
> 2014-06-13 19:32:09,727 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-7:ctx-1201ed4c) Seq 2-1956773910: Response Received:
> 2014-06-13 19:32:09,728 DEBUG [c.c.a.t.Request] (StatsCollector-3:ctx-e13d08cf) Seq 2-1956773910: Received:  { Ans: , MgmtId: 240491168032724, via: 2, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
> 
> ________________________________
> 
> This is an e-mail from Databax Ltd (Company No.04085248). The contents of this e-mail are confidential. Databax Ltd does not accept responsibility for the accuracy or completeness of the contents of this e-mail as it has been transmitted over a public network.  If you receive this e-mail in error please accept our apology. If this is the case we would be obliged if you would contact the sender and then delete this e-mail. This e-mail and/or any replies to it, and any attachments may be intercepted, copied or monitored by Databax Ltd for the purpose of monitoring or keeping record of its business and for the purposes set out in the Telecommunications (Lawful Business Practices) (Interception of Communications) Regulations 2000. All statements made in this e-mail are subject to contract. The contents are not to be regarded as a contractual offer or acceptance. The sender is not authorised to bind Databax Ltd. The views expressed in this e-mail are those of the sender and not necessarily those of  Databax Ltd.
> Feel free to visit the Databax web site at www.databax.com<http://www.databax.com/>  to find out about our range of products and services, and for the latest Databax news and information.
> 
> <
> 
>> Please consider the environment before printing this email.

Mime
View raw message