This is fragment of vmops.log file of MS. 2015-11-12 0:49 GMT+06:00 Daan Hoogland <daan.hoogl...@gmail.com>:
> Ilya, Can you share the log of your management server? There must be some > more info in there. And maybe you can check SRLog on the host To see if > anything happened there at all. > > On Wed, Nov 11, 2015 at 6:43 PM, Илья Толстихин <inosi...@gmail.com> > wrote: > > > Yes, this is Xen. > > > > 2015-11-11 22:00 GMT+06:00 Daan Hoogland <daan.hoogl...@gmail.com>: > > > > > this is a xen host, right? > > > > > > On Wed, Nov 11, 2015 at 3:43 PM, Илья Толстихин <inosi...@gmail.com> > > > wrote: > > > > > > > On host ssh is up with 22 port only. > > > > > > > > 2015-11-11 20:03 GMT+06:00 Илья Толстихин <inosi...@gmail.com>: > > > > > > > > > Cloudstack 4.6.0 > > > > > Yes, I can ssh to host > > > > > > > > > > 2015-11-11 19:41 GMT+06:00 Daan Hoogland <daan.hoogl...@gmail.com > >: > > > > > > > > > >> what version of ACS? > > > > >> It sounds like a network issue between ms and host? can you ssh > from > > > ms > > > > to > > > > >> host on the right port? (i think it was 3922, might be 3022) > > > > >> > > > > >> On Wed, Nov 11, 2015 at 1:42 PM, Илья Толстихин < > inosi...@gmail.com > > > > > > > >> wrote: > > > > >> > > > > >> > Hi all, > > > > >> > Could you please help with the DevCloud deployment. > > > > >> > > > > > >> > I imported devcloud into virtualbox, in settings *enabled PAE* > and > > > > >> > created *host-only > > > > >> > network 192.168.56.1/24 <http://192.168.56.1/24>* > > > > >> > Devcloud is pinged now. > > > > >> > > > > > >> > I built and run cloudstack on my local machine with commands > > > > >> > *mvn -Pdeveloper,systemvm clean install* > > > > >> > *mvn -Pdeveloper -pl developer,tools/devcloud -Ddeploydb* > > > > >> > *mvn -pl :cloud-client-ui jetty:run* > > > > >> > > > > > >> > > > > > >> > Then I installed marvin and tried to deploy datacenter with > > command > > > > >> > *mvn -P developer -pl tools/devcloud -Ddeploysvr* > > > > >> > and got exception > > > > >> > > > > > >> > *==== Deploy DC Started ====* > > > > >> > *Exception Occurred :['Traceback (most recent call last):\n', ' > > > File > > > > >> > "../marvin/marvin/deployDataCenter.py", line 136, in addHosts\n > > > > ret = > > > > >> > self.__apiClient.addHost(hostcmd)\n', ' File > > > > >> > > > > > >> > > > > > >> > > > > > > > > > > "/usr/local/lib/python2.7/dist-packages/Marvin-4.6.0_SNAPSHOT-py2.7.egg/marvin/cloudstackAPI/cloudstackAPIClient.py", > > > > >> > line 1572, in addHost\n response = > > > > >> > self.connection.marvinRequest(command, response_type=response, > > > > >> > method=method)\n', ' File > > > > >> > > > > > >> > > > > > >> > > > > > > > > > > "/usr/local/lib/python2.7/dist-packages/Marvin-4.6.0_SNAPSHOT-py2.7.egg/marvin/cloudstackConnection.py", > > > > >> > line 379, in marvinRequest\n raise e\n', > > 'CloudstackAPIException: > > > > >> > Execute cmd: addhost failed, due to: errorCode: 530, > > > errorText:Cannot > > > > >> > transit agent status with event AgentDisconnected for host 1, > > > > mangement > > > > >> > server id is 18413734744879,Unable to transition to a new state > > from > > > > >> > Creating via AgentDisconnected\n']* > > > > >> > > > > > >> > *===deploy dc failed, so cleaning the created entries===* > > > > >> > > > > > >> > *====DeployDC: CleanUp Started====* > > > > >> > > > > > >> > *====Clean Up Entries=== {'Network': > > > > >> > [u'5720be8d-f8eb-4dee-af4f-9551409c8722'], 'Zone': > > > > >> > [u'd05cb102-2766-4d59-a94b-0998842b3717'], 'PhysicalNetwork': > > > > >> > [u'd641f7e3-0996-4064-a6ce-54620c0524e2'], 'Cluster': > > > > >> > [u'eb213a95-4b5b-4a7d-9b4d-be1754a3b932'], 'Pod': > > > > >> > [u'659bc864-4d10-48c9-83ef-30ee40f1ce8d'], 'order': ['Cluster', > > > 'Pod', > > > > >> > 'Network', 'PhysicalNetwork', 'Zone']}* > > > > >> > > > > > >> > *===Removing DataCenter Failed===* > > > > >> > > > > > >> > As a result in cloudstack were created zone, cluster, pod, and a > > > host > > > > >> with > > > > >> > state "Alert". > > > > >> > > > > > >> > Also I run > > > > >> > *python tools/marvin/marvin/deployDataCenter.py -i > > > > >> > tools/devcloud/devcloud.cfg* > > > > >> > that gave same result. > > > > >> > > > > > >> > What am I doing wrong? > > > > >> > > > > > >> > > > > >> > > > > >> > > > > >> -- > > > > >> Daan > > > > >> > > > > > > > > > > > > > > > > > > > > > > > > > > -- > > > Daan > > > > > > > > > -- > Daan >
2015-11-12 13:52:29,269 INFO [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Trying to add a new host at http://192.168.56.10/ in data center 1 2015-11-12 13:52:30,168 DEBUG [c.c.h.x.d.XcpServerDiscoverer] (ApiServer-2:ctx-52789484 ctx-73a790db) host 192.168.56.10 doesn't have 996dd2e7-ad95-49cc-a0be-2c9adc4dfb0b Hotfix 2015-11-12 13:52:30,182 DEBUG [c.c.h.x.d.XcpServerDiscoverer] (ApiServer-2:ctx-52789484 ctx-73a790db) host 192.168.56.10 doesn't have 0850b186-4d47-11e3-a720-001b2151a503 Hotfix 2015-11-12 13:52:30,261 INFO [c.c.h.x.d.XcpServerDiscoverer] (ApiServer-2:ctx-52789484 ctx-73a790db) Found host devcloud ip=192.168.56.10 product version=1.6.0 2015-11-12 13:52:30,267 DEBUG [c.c.n.NetworkModelImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) 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 2015-11-12 13:52:30,562 DEBUG [c.c.h.x.r.XenServerConnectionPool] (ApiServer-2:ctx-52789484 ctx-73a790db) Add master connection through 192.168.56.10 for pool(null) 2015-11-12 13:52:30,615 DEBUG [c.c.h.x.r.CitrixResourceBase] (ApiServer-2:ctx-52789484 ctx-73a790db) Management network is on pif=3a8ed229-4c86-6386-1a29-52ec85fd252f 2015-11-12 13:52:30,641 DEBUG [c.c.h.x.r.XsLocalNetwork] (ApiServer-2:ctx-52789484 ctx-73a790db) Found a network called Pool-wide network associated with eth0 on host=192.168.56.10; Network=f1b661c0-d3a0-7e94-0302-9a306f798787; pif=3a8ed229-4c86-6386-1a29-52ec85fd252f 2015-11-12 13:52:30,641 INFO [c.c.h.x.r.CitrixResourceBase] (ApiServer-2:ctx-52789484 ctx-73a790db) XenServer Version is 1.6.0 for host 192.168.56.10 2015-11-12 13:52:30,641 INFO [c.c.h.x.r.CitrixResourceBase] (ApiServer-2:ctx-52789484 ctx-73a790db) Private Network is Pool-wide network associated with eth0 for host 192.168.56.10 2015-11-12 13:52:30,641 INFO [c.c.h.x.r.CitrixResourceBase] (ApiServer-2:ctx-52789484 ctx-73a790db) Guest Network is Pool-wide network associated with eth0 for host 192.168.56.10 2015-11-12 13:52:30,642 INFO [c.c.h.x.r.CitrixResourceBase] (ApiServer-2:ctx-52789484 ctx-73a790db) Public Network is Pool-wide network associated with eth0 for host 192.168.56.10 2015-11-12 13:52:30,680 DEBUG [c.c.h.x.r.CitrixResourceBase] (ApiServer-2:ctx-52789484 ctx-73a790db) Total Ram: 1465257024 dom0 Ram: 524288000 2015-11-12 13:52:31,387 DEBUG [c.c.a.t.Request] (ApiServer-2:ctx-52789484 ctx-73a790db) Seq -1--1: Startup request from directly connected host: { Cmd , MgmtId: -1, via: -1, Ver: v1, Flags: 11, [{"cpus":1,"speed":2494,"memory":1465257024,"dom0MinMemory":524288000,"poolSync":false,"caps":"xen-3.0-x86_32p","pool":"0750a75e-0ca4-b4bf-97c8-a3e91fde4566","hypervisorType":"XenServer","hostDetails":{"product_version":"1.6.0","private.network.device":"Pool-wide network associated with eth0","com.cloud.network.Networks.RouterPrivateIpStrategy":"DcGlobal","product_brand":"XCP_Kronos"},"hostTags":[],"groupDetails":{},"type":"Routing","dataCenter":"1","pod":"1","cluster":"1","guid":"9d4c9db8-32f7-25c3-0435-eab4bf3adcea","name":"devcloud","version":"4.6.0-SNAPSHOT","privateIpAddress":"192.168.56.10","privateMacAddress":"08:00:27:9b:32:00","privateNetmask":"255.255.255.0","wait":0},{"totalSize":0,"poolInfo":{"uuid":"9f3f9262-3f77-09cc-2df7-0d8475676260","host":"192.168.56.10","localPath":"ext","hostPath":"ext","poolType":"EXT","capacityBytes":31004332032,"availableBytes":28890173440},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"1","guid":"9d4c9db8-32f7-25c3-0435-eab4bf3adcea","wait":0}] } 2015-11-12 13:52:31,392 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to BaremetalDhcpManagerImpl 2015-11-12 13:52:31,393 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to NetworkUsageManagerImpl 2015-11-12 13:52:31,393 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to BaremetalPxeManagerImpl 2015-11-12 13:52:31,393 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to Ovs 2015-11-12 13:52:31,393 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to PaloAltoExternalFirewallElement 2015-11-12 13:52:31,394 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to GloboDnsElement 2015-11-12 13:52:31,395 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to BigSwitchBcfElement 2015-11-12 13:52:31,395 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to KvmServerDiscoverer 2015-11-12 13:52:31,395 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to PremiumSecondaryStorageManagerImpl 2015-11-12 13:52:31,395 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to OpendaylightElement 2015-11-12 13:52:31,395 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to NetscalerElement 2015-11-12 13:52:31,396 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to ConsoleProxyManagerImpl 2015-11-12 13:52:31,396 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to LxcServerDiscoverer 2015-11-12 13:52:31,396 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to BareMetalDiscoverer 2015-11-12 13:52:31,396 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to NiciraNvp 2015-11-12 13:52:31,396 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to HypervServerDiscoverer 2015-11-12 13:52:31,396 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to BrocadeVcsElement 2015-11-12 13:52:31,396 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to Ovm3Discoverer 2015-11-12 13:52:31,396 DEBUG [c.c.h.o.r.Ovm3Discoverer] (ApiServer-2:ctx-52789484 ctx-73a790db) createHostVOForDirectConnectAgent: Host[-0-null] 2015-11-12 13:52:31,396 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Dispatching resource state event CREATE_HOST_VO_FOR_DIRECT_CONNECT to XcpServerDiscoverer 2015-11-12 13:52:31,397 INFO [c.c.h.x.d.XcpServerDiscoverer] (ApiServer-2:ctx-52789484 ctx-73a790db) Host: devcloud connected with hypervisor type: XenServer. Checking CIDR... 2015-11-12 13:52:31,501 DEBUG [c.c.r.ResourceState] (ApiServer-2:ctx-52789484 ctx-73a790db) Resource state update: [id = 1; name = devcloud; old state = Creating; event = InternalCreated; new state = Enabled] 2015-11-12 13:52:31,501 DEBUG [c.c.h.Status] (ApiServer-2:ctx-52789484 ctx-73a790db) Transition:[Resource state = Enabled, Agent event = AgentConnected, Host id = 1, name = devcloud] 2015-11-12 13:52:31,534 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) create ClusteredDirectAgentAttache for 1 2015-11-12 13:52:31,536 INFO [c.c.a.m.DirectAgentAttache] (ApiServer-2:ctx-52789484 ctx-73a790db) StartupAnswer received 1 Interval = 60 2015-11-12 13:52:31,543 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Connect to listener: XcpServerDiscoverer 2015-11-12 13:52:31,548 DEBUG [c.c.h.x.d.XcpServerDiscoverer] (ApiServer-2:ctx-52789484 ctx-73a790db) Setting up host 1 2015-11-12 13:52:31,560 DEBUG [c.c.a.t.Request] (ApiServer-2:ctx-52789484 ctx-73a790db) Seq 1-1945555039024054273: Sending { Cmd , MgmtId: 18413734744879, via: 1(devcloud), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.SetupCommand":{"env":{},"multipath":false,"needSetup":true,"wait":0}}] } 2015-11-12 13:52:31,561 DEBUG [c.c.a.t.Request] (ApiServer-2:ctx-52789484 ctx-73a790db) Seq 1-1945555039024054273: Executing: { Cmd , MgmtId: 18413734744879, via: 1(devcloud), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.SetupCommand":{"env":{},"multipath":false,"needSetup":true,"wait":0}}] } 2015-11-12 13:52:31,564 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-1:ctx-24ba7583) Seq 1-1945555039024054273: Executing request 2015-11-12 13:52:31,674 DEBUG [o.r.Reflections] (DirectAgent-1:ctx-24ba7583) going to scan these urls: jar:file:/home/tyrael/.m2/repository/org/apache/cloudstack/cloud-plugin-hypervisor-xenserver/4.6.0-SNAPSHOT/cloud-plugin-hypervisor-xenserver-4.6.0-SNAPSHOT.jar!/ 2015-11-12 13:52:31,923 INFO [o.r.Reflections] (DirectAgent-1:ctx-24ba7583) Reflections took 248 ms to scan 1 urls, producing 4 keys and 122 values 2015-11-12 13:52:31,993 DEBUG [o.r.Reflections] (DirectAgent-1:ctx-24ba7583) going to scan these urls: jar:file:/home/tyrael/.m2/repository/org/apache/cloudstack/cloud-plugin-hypervisor-xenserver/4.6.0-SNAPSHOT/cloud-plugin-hypervisor-xenserver-4.6.0-SNAPSHOT.jar!/ 2015-11-12 13:52:32,017 INFO [o.r.Reflections] (DirectAgent-1:ctx-24ba7583) Reflections took 23 ms to scan 1 urls, producing 2 keys and 8 values 2015-11-12 13:52:32,021 DEBUG [o.r.Reflections] (DirectAgent-1:ctx-24ba7583) going to scan these urls: jar:file:/home/tyrael/.m2/repository/org/apache/cloudstack/cloud-plugin-hypervisor-xenserver/4.6.0-SNAPSHOT/cloud-plugin-hypervisor-xenserver-4.6.0-SNAPSHOT.jar!/ 2015-11-12 13:52:32,023 INFO [o.r.Reflections] (DirectAgent-1:ctx-24ba7583) Reflections took 2 ms to scan 1 urls, producing 2 keys and 2 values 2015-11-12 13:52:32,024 DEBUG [o.r.Reflections] (DirectAgent-1:ctx-24ba7583) going to scan these urls: jar:file:/home/tyrael/.m2/repository/org/apache/cloudstack/cloud-plugin-hypervisor-xenserver/4.6.0-SNAPSHOT/cloud-plugin-hypervisor-xenserver-4.6.0-SNAPSHOT.jar!/ 2015-11-12 13:52:32,027 INFO [o.r.Reflections] (DirectAgent-1:ctx-24ba7583) Reflections took 2 ms to scan 1 urls, producing 2 keys and 10 values 2015-11-12 13:52:32,033 DEBUG [o.r.Reflections] (DirectAgent-1:ctx-24ba7583) going to scan these urls: jar:file:/home/tyrael/.m2/repository/org/apache/cloudstack/cloud-plugin-hypervisor-xenserver/4.6.0-SNAPSHOT/cloud-plugin-hypervisor-xenserver-4.6.0-SNAPSHOT.jar!/ 2015-11-12 13:52:32,034 INFO [o.r.Reflections] (DirectAgent-1:ctx-24ba7583) Reflections took 1 ms to scan 1 urls, producing 2 keys and 2 values 2015-11-12 13:52:32,036 DEBUG [o.r.Reflections] (DirectAgent-1:ctx-24ba7583) going to scan these urls: jar:file:/home/tyrael/.m2/repository/org/apache/cloudstack/cloud-plugin-hypervisor-xenserver/4.6.0-SNAPSHOT/cloud-plugin-hypervisor-xenserver-4.6.0-SNAPSHOT.jar!/ 2015-11-12 13:52:32,037 INFO [o.r.Reflections] (DirectAgent-1:ctx-24ba7583) Reflections took 1 ms to scan 1 urls, producing 2 keys and 2 values 2015-11-12 13:52:32,108 INFO [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24ba7583) Host 192.168.56.10 OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c: Host 192.168.56.10 is already setup. 2015-11-12 13:52:32,123 INFO [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24ba7583) Host 192.168.56.10 OpaqueRef:0d19f3fa-7f04-543a-d906-aaf478fc574c: Host 192.168.56.10 is already setup. 2015-11-12 13:52:32,285 WARN [c.c.h.x.r.CitrixResourceBase] (DirectAgent-1:ctx-24ba7583) callHostPlugin failed for cmd: setIptables with args due to There was a failure communicating with the plugin. 2015-11-12 13:52:32,287 WARN [c.c.h.x.r.w.x.CitrixSetupCommandWrapper] (DirectAgent-1:ctx-24ba7583) Unable to setup com.cloud.utils.exception.CloudRuntimeException: callHostPlugin failed for cmd: setIptables with args due to There was a failure communicating with the plugin. at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.callHostPlugin(CitrixResourceBase.java:328) at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.setIptables(CitrixResourceBase.java:4431) at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixSetupCommandWrapper.execute(CitrixSetupCommandWrapper.java:63) at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixSetupCommandWrapper.execute(CitrixSetupCommandWrapper.java:45) at com.cloud.hypervisor.xenserver.resource.wrapper.xenbase.CitrixRequestWrapper.execute(CitrixRequestWrapper.java:122) at com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:1676) at com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:302) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49) 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:46) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask.run(FutureTask.java:262) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292) 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:745) 2015-11-12 13:52:32,290 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-1:ctx-24ba7583) Seq 1-1945555039024054273: Response Received: 2015-11-12 13:52:32,292 DEBUG [c.c.a.t.Request] (DirectAgent-1:ctx-24ba7583) Seq 1-1945555039024054273: Processing: { Ans: , MgmtId: 18413734744879, via: 1(devcloud), Ver: v1, Flags: 110, [{"com.cloud.agent.api.SetupAnswer":{"_reconnect":true,"result":false,"details":"callHostPlugin failed for cmd: setIptables with args due to There was a failure communicating with the plugin.","wait":0}}] } 2015-11-12 13:52:32,293 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-1:ctx-24ba7583) Seq 1-1945555039024054273: No more commands found 2015-11-12 13:52:32,293 DEBUG [c.c.a.t.Request] (ApiServer-2:ctx-52789484 ctx-73a790db) Seq 1-1945555039024054273: Received: { Ans: , MgmtId: 18413734744879, via: 1(devcloud), Ver: v1, Flags: 110, { SetupAnswer } } 2015-11-12 13:52:32,293 WARN [c.c.h.x.d.XcpServerDiscoverer] (ApiServer-2:ctx-52789484 ctx-73a790db) Unable to setup agent 1 due to callHostPlugin failed for cmd: setIptables with args due to There was a failure communicating with the plugin. 2015-11-12 13:52:32,294 INFO [c.c.u.e.CSExceptionErrorCode] (ApiServer-2:ctx-52789484 ctx-73a790db) Could not find exception: com.cloud.exception.ConnectionException in error code list for exceptions 2015-11-12 13:52:32,294 WARN [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Monitor XcpServerDiscoverer says there is an error in the connect process for 1 due to Reinitialize agent after setup. 2015-11-12 13:52:32,294 INFO [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Host 1 is disconnecting with event AgentDisconnected 2015-11-12 13:52:32,295 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) The next status of agent 1is Alert, current status is Connecting 2015-11-12 13:52:32,295 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Deregistering link for 1 with state Alert 2015-11-12 13:52:32,295 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Remove Agent : 1 2015-11-12 13:52:32,296 DEBUG [c.c.a.m.DirectAgentAttache] (ApiServer-2:ctx-52789484 ctx-73a790db) Processing disconnect 1(devcloud) 2015-11-12 13:52:32,296 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.hypervisor.xenserver.discoverer.XcpServerDiscoverer 2015-11-12 13:52:32,296 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.hypervisor.hyperv.discoverer.HypervServerDiscoverer 2015-11-12 13:52:32,296 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.vm.ClusteredVirtualMachineManagerImpl 2015-11-12 13:52:32,296 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.storage.listener.StoragePoolMonitor 2015-11-12 13:52:32,296 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.deploy.DeploymentPlanningManagerImpl 2015-11-12 13:52:32,296 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.storage.secondary.SecondaryStorageListener 2015-11-12 13:52:32,296 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.network.security.SecurityGroupListener 2015-11-12 13:52:32,296 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: org.apache.cloudstack.engine.orchestration.NetworkOrchestrator 2015-11-12 13:52:32,296 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.network.NetworkUsageManagerImpl$DirectNetworkStatsListener 2015-11-12 13:52:32,296 DEBUG [c.c.n.NetworkUsageManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Disconnected called on 1 with status Alert 2015-11-12 13:52:32,296 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.storage.upload.UploadListener 2015-11-12 13:52:32,297 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.agent.manager.AgentManagerImpl$BehindOnPingListener 2015-11-12 13:52:32,297 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.storage.download.DownloadListener 2015-11-12 13:52:32,297 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor 2015-11-12 13:52:32,297 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.network.router.VirtualNetworkApplianceManagerImpl 2015-11-12 13:52:32,297 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.consoleproxy.ConsoleProxyListener 2015-11-12 13:52:32,298 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.storage.LocalStoragePoolListener 2015-11-12 13:52:32,298 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor 2015-11-12 13:52:32,299 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.network.router.VpcVirtualNetworkApplianceManagerImpl 2015-11-12 13:52:32,299 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.capacity.StorageCapacityListener 2015-11-12 13:52:32,299 DEBUG [c.c.a.m.AgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Sending Disconnect to listener: com.cloud.capacity.ComputeCapacityListener 2015-11-12 13:52:32,299 DEBUG [c.c.h.Status] (ApiServer-2:ctx-52789484 ctx-73a790db) Transition:[Resource state = Enabled, Agent event = AgentDisconnected, Host id = 1, name = devcloud] 2015-11-12 13:52:32,345 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Notifying other nodes of to disconnect 2015-11-12 13:52:32,351 WARN [c.c.r.ResourceManagerImpl] (ApiServer-2:ctx-52789484 ctx-73a790db) Unable to connect due to com.cloud.exception.ConnectionException: Reinitialize agent after setup. at com.cloud.hypervisor.xenserver.discoverer.XcpServerDiscoverer.processConnect(XcpServerDiscoverer.java:621) at com.cloud.agent.manager.AgentManagerImpl.notifyMonitorsOfConnection(AgentManagerImpl.java:550) at com.cloud.agent.manager.AgentManagerImpl.handleDirectConnectAgent(AgentManagerImpl.java:1472) at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1801) at com.cloud.resource.ResourceManagerImpl.discoverHostsFull(ResourceManagerImpl.java:786) at com.cloud.resource.ResourceManagerImpl.discoverHosts(ResourceManagerImpl.java:599) 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.$Proxy167.discoverHosts(Unknown Source) at org.apache.cloudstack.api.command.admin.host.AddHostCmd.execute(AddHostCmd.java:142) at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:150) at com.cloud.api.ApiServer.queueCommand(ApiServer.java:703) at com.cloud.api.ApiServer.handleRequest(ApiServer.java:528) at com.cloud.api.ApiServer.handle(ApiServer.java:434) at org.apache.http.protocol.HttpService.doService(HttpService.java:423) at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:341) at com.cloud.api.ApiServer$WorkerTask.runInContext(ApiServer.java:1241) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49) 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:46) 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:745) 2015-11-12 13:52:32,353 DEBUG [c.c.h.Status] (ApiServer-2:ctx-52789484 ctx-73a790db) Transition:[Resource state = Enabled, Agent event = AgentDisconnected, Host id = 1, name = devcloud] 2015-11-12 13:52:32,353 DEBUG [c.c.h.Status] (ApiServer-2:ctx-52789484 ctx-73a790db) Cannot transit agent status with event AgentDisconnected for host 1, name=devcloud, mangement server id is 18413734744879 2015-11-12 13:52:32,353 ERROR [c.c.a.ApiServer] (ApiServer-2:ctx-52789484 ctx-73a790db) unhandled exception executing api command: [Ljava.lang.String;@40e51362 com.cloud.utils.exception.CloudRuntimeException: Cannot transit agent status with event AgentDisconnected for host 1, mangement server id is 18413734744879,Unable to transition to a new state from Creating via AgentDisconnected at com.cloud.agent.manager.AgentManagerImpl.agentStatusTransitTo(AgentManagerImpl.java:1388) at com.cloud.resource.ResourceManagerImpl.markHostAsDisconnected(ResourceManagerImpl.java:1756) at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1817) at com.cloud.resource.ResourceManagerImpl.discoverHostsFull(ResourceManagerImpl.java:786) at com.cloud.resource.ResourceManagerImpl.discoverHosts(ResourceManagerImpl.java:599) 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.$Proxy167.discoverHosts(Unknown Source) at org.apache.cloudstack.api.command.admin.host.AddHostCmd.execute(AddHostCmd.java:142) at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:150) at com.cloud.api.ApiServer.queueCommand(ApiServer.java:703) at com.cloud.api.ApiServer.handleRequest(ApiServer.java:528) at com.cloud.api.ApiServer.handle(ApiServer.java:434) at org.apache.http.protocol.HttpService.doService(HttpService.java:423) at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:341) at com.cloud.api.ApiServer$WorkerTask.runInContext(ApiServer.java:1241) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49) 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:46) 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:745) 2015-11-12 13:52:32,410 DEBUG [c.c.r.ResourceManagerImpl] (ApiServer-3:ctx-263637d4 ctx-72b1789b) Cluster: 1 still has hosts, can't remove 2015-11-12 13:52:32,411 DEBUG [c.c.u.d.T.Transaction] (ApiServer-3:ctx-263637d4 ctx-72b1789b) Rolling back the transaction: Time = 3 Name = ApiServer-3; called by -TransactionLegacy.rollback:879-TransactionLegacy.removeUpTo:822-TransactionLegacy.close:646-Transaction.execute:49-Transaction.execute:54-ResourceManagerImpl.deleteCluster:946-NativeMethodAccessorImpl.invoke0:-2-NativeMethodAccessorImpl.invoke:57-DelegatingMethodAccessorImpl.invoke:43-Method.invoke:606-AopUtils.invokeJoinpointUsingReflection:317-ReflectiveMethodInvocation.invokeJoinpoint:183 2015-11-12 13:52:32,411 ERROR [c.c.a.ApiServer] (ApiServer-3:ctx-263637d4 ctx-72b1789b) unhandled exception executing api command: [Ljava.lang.String;@79781829 com.cloud.utils.exception.CloudRuntimeException: Cluster: 1 cannot be removed. Cluster still has hosts at com.cloud.resource.ResourceManagerImpl$2.doInTransactionWithoutResult(ResourceManagerImpl.java:964) at com.cloud.utils.db.TransactionCallbackNoReturn.doInTransaction(TransactionCallbackNoReturn.java:25) at com.cloud.utils.db.Transaction$2.doInTransaction(Transaction.java:57) at com.cloud.utils.db.Transaction.execute(Transaction.java:45) at com.cloud.utils.db.Transaction.execute(Transaction.java:54) at com.cloud.resource.ResourceManagerImpl.deleteCluster(ResourceManagerImpl.java:946) 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.$Proxy167.deleteCluster(Unknown Source) at org.apache.cloudstack.api.command.admin.cluster.DeleteClusterCmd.execute(DeleteClusterCmd.java:70) at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:150) at com.cloud.api.ApiServer.queueCommand(ApiServer.java:703) at com.cloud.api.ApiServer.handleRequest(ApiServer.java:528) at com.cloud.api.ApiServer.handle(ApiServer.java:434) at org.apache.http.protocol.HttpService.doService(HttpService.java:423) at org.apache.http.protocol.HttpService.handleRequest(HttpService.java:341) at com.cloud.api.ApiServer$WorkerTask.runInContext(ApiServer.java:1241) at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49) 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:46) 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:745) 2015-11-12 13:52:33,360 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-f07209ee) Begin cleanup expired async-jobs 2015-11-12 13:52:33,381 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-f07209ee) End cleanup expired async-jobs 2015-11-12 13:52:38,132 DEBUG [c.c.c.ConsoleProxyManagerImpl] (consoleproxy-1:ctx-1ae2e1c7) Skip capacity scan as there is no Primary Storage in 'Up' state 2015-11-12 13:52:43,359 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-b8bc9fba) Begin cleanup expired async-jobs 2015-11-12 13:52:43,372 INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-b8bc9fba) End cleanup expired async-jobs
