I destroyed the VR, and then restarted the network and got different errors
this time at least, but the VR still didn’t get deployed correctly.
This was the log while it was trying to deploy:
2014-08-22 16:26:06,474 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-77:ctx-e3bd173c job-157499/job-157500) Add job-157500 into
job monitoring
2014-08-22 16:26:09,526 WARN [o.a.c.f.j.AsyncJobExecutionContext]
(Network-Scavenger-1:ctx-49d5b5e4) Job is executed without a context, setup
psudo job for the executing thread
2014-08-22 16:26:09,543 WARN [c.c.u.d.Merovingian2]
(Network-Scavenger-1:ctx-49d5b5e4) Was unable to find lock for the key
vm_instance5815 and thread id 1521119662
2014-08-22 16:26:10,467 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-78:ctx-77966742 job-157233/job-157501) Add job-157501 into
job monitoring
2014-08-22 16:26:12,742 INFO [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-77:ctx-e3bd173c job-157499/job-157500 ctx-b30e64b4) Unable
to start VM on Host[-17-Routing] due to Unable to start r-6455-VM due to
2014-08-22 16:26:22,880 INFO [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-77:ctx-e3bd173c job-157499/job-157500 ctx-b30e64b4) Unable
to start VM on Host[-26-Routing] due to Unable to start r-6455-VM due to
2014-08-22 16:26:25,645 INFO [c.c.h.x.r.XenServer56Resource]
(DirectAgent-240:ctx-2bf1703d) Catch com.xensource.xenapi.Types$VifInUse:
failed to destory VLAN eth0 on host a250276a-fd9d-4dfc-8a28-dcf2ec52fdcb due to
Network has active VIFs
2014-08-22 16:26:25,807 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-78:ctx-77966742 job-157233/job-157501) Remove job-157501
from job monitoring
2014-08-22 16:26:28,296 INFO [o.a.c.e.o.NetworkOrchestrator]
(Network-Scavenger-1:ctx-49d5b5e4) Let VirtualRouter handle StaticNat in
network 683
2014-08-22 16:26:31,200 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-251:ctx-640e1279) Catch Exception: class
java.lang.NullPointerException due to java.lang.NullPointerException
java.lang.NullPointerException
at
com.cloud.network.Networks$BroadcastDomainType.getSchemeValue(Networks.java:159)
at
com.cloud.network.Networks$BroadcastDomainType.getValue(Networks.java:213)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.getNetwork(CitrixResourceBase.java:1043)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.createVif(CitrixResourceBase.java:1113)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1756)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:504)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
at
com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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)
2014-08-22 16:26:31,201 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-251:ctx-640e1279) Unable to start r-6455-VM due to
java.lang.NullPointerException
at
com.cloud.network.Networks$BroadcastDomainType.getSchemeValue(Networks.java:159)
at
com.cloud.network.Networks$BroadcastDomainType.getValue(Networks.java:213)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.getNetwork(CitrixResourceBase.java:1043)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.createVif(CitrixResourceBase.java:1113)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1756)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:504)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
at
com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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)
2014-08-22 16:26:31,353 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-251:ctx-640e1279) Unable to clean up VBD due to
You gave an invalid object reference. The object may have recently been
deleted. The class parameter gives the type of reference given, and the handle
parameter echoes the bad value given.
at com.xensource.xenapi.Types.checkResponse(Types.java:693)
at com.xensource.xenapi.Connection.dispatch(Connection.java:350)
at
com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:456)
at com.xensource.xenapi.VBD.unplug(VBD.java:1059)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1491)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1839)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:504)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
at
com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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)
2014-08-22 16:26:31,387 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-251:ctx-640e1279) Unable to clean up VBD due to
You gave an invalid object reference. The object may have recently been
deleted. The class parameter gives the type of reference given, and the handle
parameter echoes the bad value given.
at com.xensource.xenapi.Types.checkResponse(Types.java:693)
at com.xensource.xenapi.Connection.dispatch(Connection.java:350)
at
com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:456)
at com.xensource.xenapi.VBD.unplug(VBD.java:1059)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1491)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1839)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:504)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
at
com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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)
2014-08-22 16:26:31,416 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-251:ctx-640e1279) Unable to cleanup VIF
You gave an invalid object reference. The object may have recently been
deleted. The class parameter gives the type of reference given, and the handle
parameter echoes the bad value given.
at com.xensource.xenapi.Types.checkResponse(Types.java:693)
at com.xensource.xenapi.Connection.dispatch(Connection.java:350)
at
com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:456)
at com.xensource.xenapi.VIF.unplug(VIF.java:878)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1499)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1839)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:504)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
at
com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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)
2014-08-22 16:26:31,698 INFO [c.c.h.x.r.XenServer56Resource]
(DirectAgent-251:ctx-640e1279) Catch com.xensource.xenapi.Types$VifInUse:
failed to destory VLAN eth0 on host 337bcab9-267e-4e8c-97f7-71f8c7d44165 due to
Network has active VIFs
2014-08-22 16:26:31,708 INFO [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-77:ctx-e3bd173c job-157499/job-157500 ctx-b30e64b4) Unable
to start VM on Host[-33-Routing] due to Unable to start r-6455-VM due to
2014-08-22 16:26:31,756 INFO [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-308:ctx-6510f2e4) VM does not exist on
XenServer337bcab9-267e-4e8c-97f7-71f8c7d44165
2014-08-22 16:26:37,237 WARN [c.c.u.d.Merovingian2]
(Network-Scavenger-1:ctx-49d5b5e4) Was unable to find lock for the key
vm_instance5828 and thread id 1521119662
2014-08-22 16:26:38,463 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-79:ctx-fe6aabfd job-157233/job-157502) Add job-157502 into
job monitoring
2014-08-22 16:26:39,452 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-439:ctx-b25ae57e) Catch Exception: class
java.lang.NullPointerException due to java.lang.NullPointerException
java.lang.NullPointerException
at
com.cloud.network.Networks$BroadcastDomainType.getSchemeValue(Networks.java:159)
at
com.cloud.network.Networks$BroadcastDomainType.getValue(Networks.java:213)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.getNetwork(CitrixResourceBase.java:1043)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.createVif(CitrixResourceBase.java:1113)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1756)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:504)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
at
com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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)
2014-08-22 16:26:39,456 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-439:ctx-b25ae57e) Unable to start r-6455-VM due to
java.lang.NullPointerException
at
com.cloud.network.Networks$BroadcastDomainType.getSchemeValue(Networks.java:159)
at
com.cloud.network.Networks$BroadcastDomainType.getValue(Networks.java:213)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.getNetwork(CitrixResourceBase.java:1043)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.createVif(CitrixResourceBase.java:1113)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1756)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:504)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
at
com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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)
2014-08-22 16:26:39,626 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-439:ctx-b25ae57e) Unable to clean up VBD due to
You gave an invalid object reference. The object may have recently been
deleted. The class parameter gives the type of reference given, and the handle
parameter echoes the bad value given.
at com.xensource.xenapi.Types.checkResponse(Types.java:693)
at com.xensource.xenapi.Connection.dispatch(Connection.java:350)
at
com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:456)
at com.xensource.xenapi.VBD.unplug(VBD.java:1059)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1491)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1839)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:504)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
at
com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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)
2014-08-22 16:26:39,655 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-439:ctx-b25ae57e) Unable to clean up VBD due to
You gave an invalid object reference. The object may have recently been
deleted. The class parameter gives the type of reference given, and the handle
parameter echoes the bad value given.
at com.xensource.xenapi.Types.checkResponse(Types.java:693)
at com.xensource.xenapi.Connection.dispatch(Connection.java:350)
at
com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:456)
at com.xensource.xenapi.VBD.unplug(VBD.java:1059)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1491)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1839)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:504)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
at
com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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)
2014-08-22 16:26:39,693 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-439:ctx-b25ae57e) Unable to cleanup VIF
You gave an invalid object reference. The object may have recently been
deleted. The class parameter gives the type of reference given, and the handle
parameter echoes the bad value given.
at com.xensource.xenapi.Types.checkResponse(Types.java:693)
at com.xensource.xenapi.Connection.dispatch(Connection.java:350)
at
com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:456)
at com.xensource.xenapi.VIF.unplug(VIF.java:878)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1499)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1839)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:504)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:61)
at
com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:102)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:216)
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)
2014-08-22 16:26:40,139 INFO [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-77:ctx-e3bd173c job-157499/job-157500 ctx-b30e64b4) Unable
to start VM on Host[-43-Routing] due to Unable to start r-6455-VM due to
2014-08-22 16:26:40,192 INFO [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-342:ctx-69548dbe) VM does not exist on
XenServer8b3cc009-8f90-4a39-b0f1-c1888a47d988
2014-08-22 16:26:51,279 INFO [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-77:ctx-e3bd173c job-157499/job-157500 ctx-b30e64b4) Unable
to start VM on Host[-3-Routing] due to Unable to start r-6455-VM due to
2014-08-22 16:26:51,751 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-77:ctx-e3bd173c job-157499/job-157500 ctx-b30e64b4)
Invocation exception, caused by:
com.cloud.utils.exception.CloudRuntimeException: Unable to start instance
'r-6455-VM' (cc0b60b5-ec23-45e9-b6de-6f291808760c), see management server log
for details
2014-08-22 16:26:51,752 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-77:ctx-e3bd173c job-157499/job-157500 ctx-b30e64b4) Rethrow
exception com.cloud.utils.exception.CloudRuntimeException: Unable to start
instance 'r-6455-VM' (cc0b60b5-ec23-45e9-b6de-6f291808760c), see management
server log for details
2014-08-22 16:26:51,753 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-77:ctx-e3bd173c job-157499/job-157500) Unable to complete
AsyncJobVO {id:157500, userId: 2, accountId: 2, instanceType: null, instanceId:
null, cmd: com.cloud.vm.VmWorkStart, cmdInfo:
rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAZN3QAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwc3IAEWphdmEudXRpbC5IYXNoTWFwBQfawcMWYNEDAAJGAApsb2FkRmFjdG9ySQAJdGhyZXNob2xkeHA_QAAAAAAADHcIAAAAEAAAAAF0AA5SZXN0YXJ0TmV0d29ya3QAP3JPMEFCWE55QUJGcVlYWmhMbXhoYm1jdVFtOXZiR1ZoYnMwZ2NvRFZuUHJ1QWdBQldnQUZkbUZzZFdWNGNBRXhw,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 33862771676063, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Fri Aug 22 16:26:04 MST 2014}, job origin:157499
com.cloud.utils.exception.CloudRuntimeException: Unable to start instance
'r-6455-VM' (cc0b60b5-ec23-45e9-b6de-6f291808760c), see management server log
for details
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1137)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5190)
at sun.reflect.GeneratedMethodAccessor417.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5335)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)
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
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
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)
2014-08-22 16:26:51,798 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-77:ctx-e3bd173c job-157499/job-157500) Remove job-157500
from job monitoring
2014-08-22 16:26:54,914 INFO [c.c.v.UserVmManagerImpl]
(UserVm-Scavenger-5:ctx-5305be0f) Found 1 vms to expunge.
2014-08-22 16:26:54,921 WARN [c.c.v.UserVmManagerImpl]
(UserVm-Scavenger-5:ctx-5305be0f) Unable to expunge VM[User|i-4-6450-VM]
com.cloud.utils.exception.CloudRuntimeException: Please destroy vm with
specified vmId before expunge
at com.cloud.vm.UserVmManagerImpl.expungeVm(UserVmManagerImpl.java:3674)
at
com.cloud.vm.UserVmManagerImpl$ExpungeTask.runInContext(UserVmManagerImpl.java:1817)
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.runAndReset(FutureTask.java:304)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
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)
2014-08-22 16:26:57,171 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-79:ctx-fe6aabfd job-157233/job-157502) Remove job-157502
from job monitoring
--
Justyn Shull
DevOps Engineer
On August 22, 2014 at 5:48:26 PM, Andrei Mikhailovsky
([email protected]<mailto:[email protected]>) wrote:
what happens when you delete this particular VR and restart the network? It
should re-create the VR from start on a host server that it chooses. Does that
work for you?
Andrei
----- Original Message -----
From: "Justyn Shull" <[email protected]>
To: [email protected]
Sent: Friday, 22 August, 2014 10:32:30 PM
Subject: Re: CS failing to restart a network and virtual router on 4.4
Thanks for taking a look, Andrei.
I checked the database and pool 235 is the local storage for a hv named hv–40–1
which has a host id 41, but host id 43 is a different server, hv–33–1.
I just verified that I can access the local storage (pool 235) on host 41
(hv–40–1) and it seems to be fine. Host id 43(hv–33–1) definitely cannot reach
the same storage pool, but that should be expected since it’s local storage on
a different server.
To me(and I could be entirely wrong), the VR is trying to deploy to one HV and
access storage in a separate HV, so the deploy fails. The deployment planner
seems to go through all the proper steps, but then tries to deploy to a storage
pool not associated to the HV its trying to deploy to.
--
Justyn Shull
DevOps Engineer
On August 22, 2014 at 4:03:35 PM, Andrei Mikhailovsky
([email protected]<mailto:[email protected]>) wrote:
Justyn,
Looking at the logs your problem is here:
2014-08-22 11:25:52,949 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Host: 43
cannot access pool: 235
Your local storage pool is not accessible, thus all hosts are listed in avoid
set. You need to check the hypervisor whyy your storage pool is not accessible.
Andrei
----- Original Message -----
From: "Justyn Shull" <[email protected]>
To: [email protected]
Sent: Friday, 22 August, 2014 7:41:51 PM
Subject: CS failing to restart a network and virtual router on 4.4
We just started running into an issue with a couple networks in Cloudstack that
we haven’t been able to resolve yet.
The VMs inside the network had no connectivity, so we have tried restarting the
network (with and without the ‘clean up’ option), and also just restarting the
virtual router through cloudstack.
This is part of the management-server.log when we restart the network with the
cleanup option:
2014-08-22 11:25:52,909 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Checking if host: 40 has enough capacity for
requested CPU: 500 and requested RAM: 134217728 , cpuOverprovisioningFactor: 2.0
2014-08-22 11:25:52,914 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Hosts's actual total CPU: 64000 and CPU after
applying overprovisioning: 128000
2014-08-22 11:25:52,914 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Free CPU: 110000 , Requested CPU: 500
2014-08-22 11:25:52,915 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Free RAM: 82959712256 , Requested RAM: 134217728
2014-08-22 11:25:52,915 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-08-22 11:25:52,916 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Found a suitable host, adding to list: 40
2014-08-22 11:25:52,916 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Host name: hv-40-1.phx, hostId: 41 is in avoid set,
skipping this and trying other available hosts
2014-08-22 11:25:52,932 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Host: 42 has cpu capability (cpu:32, speed:2000) to
support requested CPU: 1 and requested speed: 500
2014-08-22 11:25:52,933 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Checking if host: 42 has enough capacity for
requested CPU: 500 and requested RAM: 134217728 , cpuOverprovisioningFactor: 2.0
2014-08-22 11:25:52,938 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Hosts's actual total CPU: 64000 and CPU after
applying overprovisioning: 128000
2014-08-22 11:25:52,938 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Free CPU: 91000 , Requested CPU: 500
2014-08-22 11:25:52,938 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Free RAM: 27793432576 , Requested RAM: 134217728
2014-08-22 11:25:52,939 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-08-22 11:25:52,939 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Found a suitable host, adding to list: 42
2014-08-22 11:25:52,939 DEBUG [c.c.a.m.a.i.FirstFitAllocator]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a
FirstFitRoutingAllocator) Host Allocator returning 7 suitable hosts
2014-08-22 11:25:52,943 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Checking
suitable pools for volume (Id, Type): (6539,ROOT)
2014-08-22 11:25:52,943 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Volume
has pool already allocated, checking if pool can be reused, poolId: 235
2014-08-22 11:25:52,946 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Planner
need not allocate a pool for this volume since its READY
2014-08-22 11:25:52,946 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Trying
to find a potenial host and associated storage pools from the suitable
host/pool lists for this VM
2014-08-22 11:25:52,946 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Checking
if host: 43 can access any suitable storage pool for volume: ROOT
2014-08-22 11:25:52,949 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Host: 43
cannot access pool: 235
2014-08-22 11:25:52,949 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Checking
if host: 44 can access any suitable storage pool for volume: ROOT
2014-08-22 11:25:52,951 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Host: 44
cannot access pool: 235
2014-08-22 11:25:52,951 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Checking
if host: 45 can access any suitable storage pool for volume: ROOT
2014-08-22 11:25:52,954 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Host: 45
cannot access pool: 235
2014-08-22 11:25:52,954 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Checking
if host: 46 can access any suitable storage pool for volume: ROOT
2014-08-22 11:25:52,957 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Host: 46
cannot access pool: 235
2014-08-22 11:25:52,957 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Checking
if host: 39 can access any suitable storage pool for volume: ROOT
2014-08-22 11:25:52,959 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Host: 39
cannot access pool: 235
2014-08-22 11:25:52,959 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Checking
if host: 40 can access any suitable storage pool for volume: ROOT
2014-08-22 11:25:52,962 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Host: 40
cannot access pool: 235
2014-08-22 11:25:52,962 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Checking
if host: 42 can access any suitable storage pool for volume: ROOT
2014-08-22 11:25:52,964 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Host: 42
cannot access pool: 235
2014-08-22 11:25:52,964 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Could
not find a potential host that has associated storage pools from the suitable
host/pool lists for this VM
2014-08-22 11:25:52,972 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Could
not find suitable Deployment Destination for this VM under any clusters,
returning.
2014-08-22 11:25:52,972 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a)
Searching resources only under specified Cluster: 5
2014-08-22 11:25:52,974 DEBUG [c.c.d.FirstFitPlanner]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) The
specified cluster is in avoid set, returning.
2014-08-22 11:25:52,994 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) VM state
transitted from :Starting to Stopped with event: OperationFailedvm's original
host id: null new host id: null host id before state transition: 41
2014-08-22 11:25:53,008 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Hosts's
actual total CPU: 64000 and CPU after applying overprovisioning: 128000
2014-08-22 11:25:53,008 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Hosts's
actual total RAM: 98928826880 and RAM after applying overprovisioning:
98928828416
2014-08-22 11:25:53,009 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) release
cpu from host: 41, old used: 36000,reserved: 0, actual total: 64000, total with
overprovisioning: 128000; new used: 35500,reserved:0; movedfromreserved:
false,moveToReserveredfalse
2014-08-22 11:25:53,009 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) release
mem from host: 41, old used: 47513075712,reserved: 0, total: 98928828416; new
used: 47378857984,reserved:0; movedfromreserved: false,moveToReserveredfalse
2014-08-22 11:25:53,016 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a)
Invocation exception, caused by:
com.cloud.utils.exception.CloudRuntimeException: Unable to start instance
'r-6420-VM' (7ecbca93-f9c9-496a-9ad7-0c57cb63789f), see management server log
for details
2014-08-22 11:25:53,017 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Rethrow
exception com.cloud.utils.exception.CloudRuntimeException: Unable to start
instance 'r-6420-VM' (7ecbca93-f9c9-496a-9ad7-0c57cb63789f), see management
server log for details
2014-08-22 11:25:53,018 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940) Done with run of VM
work job: com.cloud.vm.VmWorkStart for VM 6420, job origin: 156937
2014-08-22 11:25:53,018 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940) Unable to complete
AsyncJobVO {id:156940, userId: 2, accountId: 2, instanceType: null, instanceId:
null, cmd: com.cloud.vm.VmWorkStart, cmdInfo:
rO0ABXNyABhjb20uY2xvdWQudm0uVm1Xb3JrU3RhcnR9cMGsvxz73gIAC0oABGRjSWRMAAZhdm9pZHN0ADBMY29tL2Nsb3VkL2RlcGxveS9EZXBsb3ltZW50UGxhbm5lciRFeGNsdWRlTGlzdDtMAAljbHVzdGVySWR0ABBMamF2YS9sYW5nL0xvbmc7TAAGaG9zdElkcQB-AAJMAAtqb3VybmFsTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO0wAEXBoeXNpY2FsTmV0d29ya0lkcQB-AAJMAAdwbGFubmVycQB-AANMAAVwb2RJZHEAfgACTAAGcG9vbElkcQB-AAJMAAlyYXdQYXJhbXN0AA9MamF2YS91dGlsL01hcDtMAA1yZXNlcnZhdGlvbklkcQB-AAN4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1lcQB-AAN4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAZFHQAGVZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGwAAAAAAAAAAHBwcHBwcHBwc3IAEWphdmEudXRpbC5IYXNoTWFwBQfawcMWYNEDAAJGAApsb2FkRmFjdG9ySQAJdGhyZXNob2xkeHA_QAAAAAAADHcIAAAAEAAAAAF0AA5SZXN0YXJ0TmV0d29ya3QAP3JPMEFCWE55QUJGcVlYWmhMbXhoYm1jdVFtOXZiR1ZoYnMwZ2NvRFZuUHJ1QWdBQldnQUZkbUZzZFdWNGNBRXhw,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 182571079363322, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Fri Aug 22 11:25:03 MST 2014}, job origin:156937
com.cloud.utils.exception.CloudRuntimeException: Unable to start instance
'r-6420-VM' (7ecbca93-f9c9-496a-9ad7-0c57cb63789f), see management server log
for details
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:1137)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:5190)
at sun.reflect.GeneratedMethodAccessor446.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:5335)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)
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
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
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)
2014-08-22 11:25:53,022 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940) Complete async
job-156940, jobStatus: FAILED, resultCode: 0, result:
rO0ABXNyABpqYXZhLmxhbmcuUnVudGltZUV4Y2VwdGlvbp5fBkcKNIPlAgAAeHIAE2phdmEubGFuZy5FeGNlcHRpb27Q_R8-GjscxAIAAHhyABNqYXZhLmxhbmcuVGhyb3dhYmxl1cY1Jzl3uMsDAARMAAVjYXVzZXQAFUxqYXZhL2xhbmcvVGhyb3dhYmxlO0wADWRldGFpbE1lc3NhZ2V0ABJMamF2YS9sYW5nL1N0cmluZztbAApzdGFja1RyYWNldAAeW0xqYXZhL2xhbmcvU3RhY2tUcmFjZUVsZW1lbnQ7TAAUc3VwcHJlc3NlZEV4Y2VwdGlvbnN0ABBMamF2YS91dGlsL0xpc3Q7eHBxAH4AB3QAjkpvYiBmYWlsZWQgZHVlIHRvIGV4Y2VwdGlvbiBVbmFibGUgdG8gc3RhcnQgaW5zdGFuY2UgJ3ItNjQyMC1WTScgKDdlY2JjYTkzLWY5YzktNDk2YS05YWQ3LTBjNTdjYjYzNzg5ZiksIHNlZSBtYW5hZ2VtZW50IHNlcnZlciBsb2cgZm9yIGRldGFpbHN1cgAeW0xqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnQ7AkYqPDz9IjkCAAB4cAAAAA1zcgAbamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50YQnFmiY23YUCAARJAApsaW5lTnVtYmVyTAAOZGVjbGFyaW5nQ2xhc3NxAH4ABEwACGZpbGVOYW1lcQB-AARMAAptZXRob2ROYW1lcQB-AAR4cAAAAHJ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ACwAAAfd0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-AAsAAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-AAsAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgALAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4AGnQAD2NhbGxXaXRoQ29udGV4dHNxAH4ACwAAADVxAH4AHXEAfgAadAAOcnVuV2l0aENvbnRleHRzcQB-AAsAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ABZxAH4AF3NxAH4ACwAAAcxxAH4AEXEAfgAScQB-ABdzcQB-AAsAAAHXdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ABtzcQB-AAsAAAEGdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgAXc3EAfgALAAAEeXQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgALAAACZ3QALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4ALHEAfgAXc3EAfgALAAAC6XQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAXc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAZ4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AOHg
2014-08-22 11:25:53,037 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940) Done executing
com.cloud.vm.VmWorkStart for job-156940
2014-08-22 11:25:53,068 WARN [o.a.c.e.o.NetworkOrchestrator]
(API-Job-Executor-95:ctx-63049a0d job-156937 ctx-54a932fe) Failed to implement
network Ntwk[00759e4d-4903-412f-bee3-0dcee9fc811c|Guest|8] elements and
resources as a part of network restart due to
java.lang.RuntimeException: Job failed due to exception Unable to start
instance 'r-6420-VM' (7ecbca93-f9c9-496a-9ad7-0c57cb63789f), see management
server log for details
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:114)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)
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
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
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)
2014-08-22 11:25:53,070 WARN [c.c.n.NetworkServiceImpl]
(API-Job-Executor-95:ctx-63049a0d job-156937 ctx-54a932fe) Network id=1365
failed to restart.
2014-08-22 11:25:53,069 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940) Sync queue (58718) is
currently empty
2014-08-22 11:25:53,071 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940) Remove job-156940
from job monitoring
2014-08-22 11:25:53,081 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-95:ctx-63049a0d job-156937) Complete async job-156937,
jobStatus: FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed
to restart network"}
2014-08-22 11:25:53,098 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-95:ctx-63049a0d job-156937) Done executing
org.apache.cloudstack.api.command.user.network.RestartNetworkCmd for job-156937
2014-08-22 11:25:53,104 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-95:ctx-63049a0d job-156937) Remove job-156937 from job
monitoring
In particular, this part:
2014-08-22 11:25:52,964 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Could
not find a potential host that has associated storage pools from the suitable
host/pool lists for this VM
2014-08-22 11:25:52,972 DEBUG [c.c.d.DeploymentPlanningManagerImpl]
(Work-Job-Executor-92:ctx-a176c26e job-156937/job-156940 ctx-2f39774a) Could
not find suitable Deployment Destination for this VM under any clusters,
returning.
All of our XenServer hypervisors use local storage, so each host has a local
storage pool, and can only access that pool. Cloudstack seems to be allocating
storage on one host for the vm, and then trying to deploy to a different host?
All hosts do have plenty of free space.
I tested deploying a normal(non virtual router/systemvm) and it is working fine
on the setup; so it might only be related to system vms.
Once the virtual router gets to this point, the VM will no longer start either
as the virtual router has to be running first.
Anyone have any advice on where to go from here? I can provide more
details/logs if needed; just not sure what is helpful at this point.
Thanks!
--
Justyn Shull
DevOps Engineer
