cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Justyn Shull <just...@codero.com>
Subject Re: CS failing to restart a network and virtual router on 4.4
Date Fri, 22 Aug 2014 23:34:18 GMT
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 (andrei@arhont.com<mailto:andrei@arhont.com>) 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" <justyns@codero.com>
To: users@cloudstack.apache.org
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 (andrei@arhont.com<mailto:andrei@arhont.com>) 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" <justyns@codero.com>
To: users@cloudstack.apache.org
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
Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message