cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Sangeetha Hariharan (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (CLOUDSTACK-5545) Xenserver - After HA , ssvm fails to start on the new host . Also not able to deploy new Vms in this host.
Date Wed, 18 Dec 2013 19:35:07 GMT

     [ https://issues.apache.org/jira/browse/CLOUDSTACK-5545?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Sangeetha Hariharan updated CLOUDSTACK-5545:
--------------------------------------------

          Component/s: Management Server
          Description: 
Xenserver - After HA , ssvm fails to start on the new host . Also not able to deploy new Vms in this host.

Steps to reproduce the problem:

Set up - Advanced zone with 2 hots (Xenserver 6.2) , host1 and host2.

All user Vms (~11) and system Vms were running on host1.
power down host1.

All the HA enabled user Vms and system Vms were able to successfully start on host2 and are reported as "Running" except for SSVM.

As part of HA process , seems like there were 2 threads that were trying to work on the SSVM ( one trying to stop Vm and other trying to start Vm).
SSVM fails to start. I see that ssvm getting destroyed and trying to get recreated over and over again with no success.

Following exception seen in management server logs:

com.cloud.utils.exception.CloudRuntimeException: We cannot proceed with stop VM VM[SecondaryStorageVm|s-52-VM] since it is not in 'Stopping' state, current state: Stop
ped
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1358)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:1258)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1231)
        at com.cloud.ha.HighAvailabilityManagerImpl.restart(HighAvailabilityManagerImpl.java:485)
        at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.runWithContext(HighAvailabilityManagerImpl.java:842)
        at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.access$000(HighAvailabilityManagerImpl.java:797)
        at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread$1.run(HighAvailabilityManagerImpl.java:809)
        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 com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(HighAvailabilityManagerImpl.java:806)
2013-12-17 18:36:47,986 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea2
04d8dffe
           nameLabel: Async.VM.start_on
     nameDescription:
   allowedOperations: []
   currentOperations: {}
             created: Tue Dec 17 18:36:45 EST 2013
            finished: Tue Dec 17 18:36:59 EST 2013
              status: failure
          residentOn: com.xensource.xenapi.Host@a6594848
            progress: 1.0
                type: <none/>
              result:
           errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
         otherConfig: {debug_info:cancel_points_seen=27}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

2013-12-17 18:36:48,022 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) Unable to start VM(s-52-VM) on host(eb0add58-3df6-4870-8937-ac21abe5471b) due to Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
           nameLabel: Async.VM.start_on
     nameDescription:
   allowedOperations: []
   currentOperations: {}
             created: Tue Dec 17 18:36:45 EST 2013
            finished: Tue Dec 17 18:36:59 EST 2013
              status: failure
          residentOn: com.xensource.xenapi.Host@a6594848
            progress: 1.0
                type: <none/>
              result:
           errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
         otherConfig: {debug_info:cancel_points_seen=27}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
           nameLabel: Async.VM.start_on
     nameDescription:
   allowedOperations: []
   currentOperations: {}
             created: Tue Dec 17 18:36:45 EST 2013
            finished: Tue Dec 17 18:36:59 EST 2013
              status: failure
          residentOn: com.xensource.xenapi.Host@a6594848
            progress: 1.0
                type: <none/>
              result:
           errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
         otherConfig: {debug_info:cancel_points_seen=27}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3751)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3863)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1734)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:550)
        at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
        at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
        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$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:722)
2013-12-17 18:36:48,027 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) Catch Exception: class com.cloud.utils.exception.CloudRuntimeException due to com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(s-52-VM) on host(eb0add58-3df6-4870-8937-ac21abe5471b) due to Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
           nameLabel: Async.VM.start_on
     nameDescription:
   allowedOperations: []
   currentOperations: {}
             created: Tue Dec 17 18:36:45 EST 2013
            finished: Tue Dec 17 18:36:59 EST 2013
              status: failure
          residentOn: com.xensource.xenapi.Host@a6594848
            progress: 1.0
                type: <none/>
              result:
           errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
         otherConfig: {debug_info:cancel_points_seen=27}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []
com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(s-52-VM) on host(eb0add58-3df6-4870-8937-ac21abe5471b) due to Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
           nameLabel: Async.VM.start_on
     nameDescription:
   allowedOperations: []
   currentOperations: {}
             created: Tue Dec 17 18:36:45 EST 2013
            finished: Tue Dec 17 18:36:59 EST 2013
              status: failure
          residentOn: com.xensource.xenapi.Host@a6594848
            progress: 1.0
                type: <none/>
              result:
           errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
         otherConfig: {debug_info:cancel_points_seen=27}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3874)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1734)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:550)
        at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
        at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
        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$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:722)
2013-12-17 18:36:48,027 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) Unable to start s-52-VM due to
com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(s-52-VM) on host(eb0add58-3df6-4870-8937-ac21abe5471b) due to Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
           nameLabel: Async.VM.start_on
     nameDescription:
   allowedOperations: []
   currentOperations: {}
             created: Tue Dec 17 18:36:45 EST 2013
            finished: Tue Dec 17 18:36:59 EST 2013
              status: failure
          residentOn: com.xensource.xenapi.Host@a6594848
            progress: 1.0
                type: <none/>
              result:
           errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
         otherConfig: {debug_info:cancel_points_seen=27}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3874)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1734)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:550)
        at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
        at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
        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$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:722)
2013-12-17 18:36:48,033 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) VM getRecord failed 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:209)
        at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
        at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
        at com.xensource.xenapi.VM.getRecord(VM.java:572)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1427)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1813)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:550)
        at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
        at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
        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$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:722)
2013-12-17 18:36:48,033 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) The VM is in stopped state, detected problem during startup : s-52-VM
2013-12-17 18:36:48,036 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) null
2013-12-17 18:36:48,036 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-13:ctx-fdae8cdf) Seq 1-1541013657: Cancelling because one of the answers is false and it is stop on error.



I am also not able to deploy Vms in this host.Following exception seen duing copyCommand.

2013-12-17 19:22:40,110 DEBUG [c.c.a.t.Request] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Seq 1-1541013760: Received:  { Ans: , MgmtId: 112516401760401, via: 1, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2013-12-17 19:22:40,115 WARN  [o.a.c.s.d.ObjectInDataStoreManagerImpl] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@4ae577a4), no need to delete from object in store ref table
2013-12-17 19:22:40,117 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Unable to create Vol[55|vm=55|ROOT]:org.apache.xmlrpc.XmlRpcException: Failed to create input stream: Read timed out
2013-12-17 19:22:40,118 INFO  [c.c.v.VirtualMachineManagerImpl] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is unreachable: Unable to create Vol[55|vm=55|ROOT]:org.apache.xmlrpc.XmlRpcException: Failed to create input stream: Read timed out
        at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1138)
        at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1180)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:904)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:710)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:556)
        at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:228)
        at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3559)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3140)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3126)
        at sun.reflect.GeneratedMethodAccessor397.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
        at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy171.startVirtualMachine(Unknown Source)
        at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:443)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
        at com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
        at com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
        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 com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:521)
        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$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:722)
2013-12-17 19:22:40,121 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Cleaning up resources for the vm VM[User|new123] in Starting state
2013-12-17 19:22:40,124 DEBUG [c.c.a.t.Request] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Seq 1-1541013786: Sending  { Cmd , MgmtId: 11251640:

There seem to be lot of tasks stuck in "Pending" state in the host:

[root@Rack3Host20 log]# xe task-list
uuid ( RO)                : 5f8cd758-c12a-e7e7-4b59-be4aaee22e69
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : b97cb9c8-488a-d339-745b-81ad03a0dc97
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 610e7fb1-337c-04b6-253d-b5affd56b253
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : f95e7e81-2c43-6a03-ed8a-66b00d47a9cc
          name-label ( RO): VM.hard_shutdown
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 2a1b41eb-d5c3-d629-42fa-e54bbbf72662
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : af6abf9c-1f1f-ac9e-a5c6-596321ae754a
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 2f5826ed-fe0f-4723-6a8a-31732915e684
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : da57bfe2-bf7f-6440-2e48-efa253938d6a
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 544012b5-d6b6-2e8a-a242-812ccd47da9c
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 5906ffc3-50bb-114f-9583-98a0b3227ecb
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : ba489995-38dc-8544-249f-bb98f3e07918
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 21ec8dd4-107a-281b-a9f3-fe20d74a3004
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : f44eba9c-4205-b168-9806-5cad9c37dd74
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : aac69047-ef8d-64f6-adfc-e6e53dc501b5
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : caeafcce-cd4c-51c5-601c-b5e8ddede2b5
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : db237607-5e7b-91b5-05c2-6ca567f02134
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : fc299731-b9df-3542-0bf0-066a069a9f16
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 18dd9bcb-3d72-4f29-49c9-9aa15a8d9632
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 3f285683-71fc-2c09-fdca-13c494de9beb
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : f464807c-74f2-92b6-53e2-210b581d981f
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 61e8769e-bfd9-6cc3-def7-9117806de5d3
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 1c21be2b-4e45-bd52-46ba-aa1e83e6ca28
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : def10529-63eb-c283-2a99-6391ede7c723
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 9041d6d4-827a-0d4b-cff1-c19049239f10
          name-label ( RO): VDI.destroy
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 0e6634eb-cd01-e90f-3d06-b0b40460737e
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


[root@Rack3Host20 log]#






  was:
Xenserver - After HA , ssvm fails to start on the new host . Also not able to deploy new Vms in this host.

Steps to reproduce the problem:

Set up - Advanced zone with 2 hots , host1 and host2.

All user Vms (~11) and system Vms were running on host1.
power down host1.

All the HA enabled user Vms and system Vms were able to successfully start on host2 and are reported as "Running" except for SSVM.

As part of HA process , seems like there were 2 threads that were trying to work on the SSVM ( one trying to stop Vm and other trying to start Vm).
SSVM fails to start. I see that ssvm getting destroyed and trying to get recreated over and over again with no success.

Following exception seen in management server logs:

com.cloud.utils.exception.CloudRuntimeException: We cannot proceed with stop VM VM[SecondaryStorageVm|s-52-VM] since it is not in 'Stopping' state, current state: Stop
ped
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1358)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:1258)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1231)
        at com.cloud.ha.HighAvailabilityManagerImpl.restart(HighAvailabilityManagerImpl.java:485)
        at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.runWithContext(HighAvailabilityManagerImpl.java:842)
        at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.access$000(HighAvailabilityManagerImpl.java:797)
        at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread$1.run(HighAvailabilityManagerImpl.java:809)
        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 com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(HighAvailabilityManagerImpl.java:806)
2013-12-17 18:36:47,986 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea2
04d8dffe
           nameLabel: Async.VM.start_on
     nameDescription:
   allowedOperations: []
   currentOperations: {}
             created: Tue Dec 17 18:36:45 EST 2013
            finished: Tue Dec 17 18:36:59 EST 2013
              status: failure
          residentOn: com.xensource.xenapi.Host@a6594848
            progress: 1.0
                type: <none/>
              result:
           errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
         otherConfig: {debug_info:cancel_points_seen=27}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

2013-12-17 18:36:48,022 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) Unable to start VM(s-52-VM) on host(eb0add58-3df6-4870-8937-ac21abe5471b) due to Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
           nameLabel: Async.VM.start_on
     nameDescription:
   allowedOperations: []
   currentOperations: {}
             created: Tue Dec 17 18:36:45 EST 2013
            finished: Tue Dec 17 18:36:59 EST 2013
              status: failure
          residentOn: com.xensource.xenapi.Host@a6594848
            progress: 1.0
                type: <none/>
              result:
           errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
         otherConfig: {debug_info:cancel_points_seen=27}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
           nameLabel: Async.VM.start_on
     nameDescription:
   allowedOperations: []
   currentOperations: {}
             created: Tue Dec 17 18:36:45 EST 2013
            finished: Tue Dec 17 18:36:59 EST 2013
              status: failure
          residentOn: com.xensource.xenapi.Host@a6594848
            progress: 1.0
                type: <none/>
              result:
           errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
         otherConfig: {debug_info:cancel_points_seen=27}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3751)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3863)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1734)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:550)
        at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
        at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
        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$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:722)
2013-12-17 18:36:48,027 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) Catch Exception: class com.cloud.utils.exception.CloudRuntimeException due to com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(s-52-VM) on host(eb0add58-3df6-4870-8937-ac21abe5471b) due to Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
           nameLabel: Async.VM.start_on
     nameDescription:
   allowedOperations: []
   currentOperations: {}
             created: Tue Dec 17 18:36:45 EST 2013
            finished: Tue Dec 17 18:36:59 EST 2013
              status: failure
          residentOn: com.xensource.xenapi.Host@a6594848
            progress: 1.0
                type: <none/>
              result:
           errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
         otherConfig: {debug_info:cancel_points_seen=27}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []
com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(s-52-VM) on host(eb0add58-3df6-4870-8937-ac21abe5471b) due to Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
           nameLabel: Async.VM.start_on
     nameDescription:
   allowedOperations: []
   currentOperations: {}
             created: Tue Dec 17 18:36:45 EST 2013
            finished: Tue Dec 17 18:36:59 EST 2013
              status: failure
          residentOn: com.xensource.xenapi.Host@a6594848
            progress: 1.0
                type: <none/>
              result:
           errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
         otherConfig: {debug_info:cancel_points_seen=27}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3874)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1734)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:550)
        at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
        at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
        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$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:722)
2013-12-17 18:36:48,027 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) Unable to start s-52-VM due to
com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(s-52-VM) on host(eb0add58-3df6-4870-8937-ac21abe5471b) due to Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
           nameLabel: Async.VM.start_on
     nameDescription:
   allowedOperations: []
   currentOperations: {}
             created: Tue Dec 17 18:36:45 EST 2013
            finished: Tue Dec 17 18:36:59 EST 2013
              status: failure
          residentOn: com.xensource.xenapi.Host@a6594848
            progress: 1.0
                type: <none/>
              result:
           errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
         otherConfig: {debug_info:cancel_points_seen=27}
           subtaskOf: com.xensource.xenapi.Task@aaf13f6f
            subtasks: []

        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3874)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1734)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:550)
        at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
        at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
        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$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:722)
2013-12-17 18:36:48,033 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) VM getRecord failed 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:209)
        at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
        at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
        at com.xensource.xenapi.VM.getRecord(VM.java:572)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1427)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1813)
        at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:550)
        at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
        at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
        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$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        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:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:722)
2013-12-17 18:36:48,033 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) The VM is in stopped state, detected problem during startup : s-52-VM
2013-12-17 18:36:48,036 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) null
2013-12-17 18:36:48,036 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-13:ctx-fdae8cdf) Seq 1-1541013657: Cancelling because one of the answers is false and it is stop on error.



I am also not able to deploy Vms in this host.Following exception seen duing copyCommand.

2013-12-17 19:22:40,110 DEBUG [c.c.a.t.Request] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Seq 1-1541013760: Received:  { Ans: , MgmtId: 112516401760401, via: 1, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2013-12-17 19:22:40,115 WARN  [o.a.c.s.d.ObjectInDataStoreManagerImpl] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@4ae577a4), no need to delete from object in store ref table
2013-12-17 19:22:40,117 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Unable to create Vol[55|vm=55|ROOT]:org.apache.xmlrpc.XmlRpcException: Failed to create input stream: Read timed out
2013-12-17 19:22:40,118 INFO  [c.c.v.VirtualMachineManagerImpl] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is unreachable: Unable to create Vol[55|vm=55|ROOT]:org.apache.xmlrpc.XmlRpcException: Failed to create input stream: Read timed out
        at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1138)
        at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1180)
        at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:904)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:710)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:556)
        at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:228)
        at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3559)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3140)
        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3126)
        at sun.reflect.GeneratedMethodAccessor397.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:601)
        at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
        at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
        at $Proxy171.startVirtualMachine(Unknown Source)
        at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:443)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
        at com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
        at com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
        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 com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
        at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:521)
        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$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:722)
2013-12-17 19:22:40,121 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Cleaning up resources for the vm VM[User|new123] in Starting state
2013-12-17 19:22:40,124 DEBUG [c.c.a.t.Request] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Seq 1-1541013786: Sending  { Cmd , MgmtId: 11251640:

There seem to be lot of tasks stuck in "Pending" state in the host:

[root@Rack3Host20 log]# xe task-list
uuid ( RO)                : 5f8cd758-c12a-e7e7-4b59-be4aaee22e69
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : b97cb9c8-488a-d339-745b-81ad03a0dc97
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 610e7fb1-337c-04b6-253d-b5affd56b253
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : f95e7e81-2c43-6a03-ed8a-66b00d47a9cc
          name-label ( RO): VM.hard_shutdown
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 2a1b41eb-d5c3-d629-42fa-e54bbbf72662
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : af6abf9c-1f1f-ac9e-a5c6-596321ae754a
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 2f5826ed-fe0f-4723-6a8a-31732915e684
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : da57bfe2-bf7f-6440-2e48-efa253938d6a
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 544012b5-d6b6-2e8a-a242-812ccd47da9c
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 5906ffc3-50bb-114f-9583-98a0b3227ecb
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : ba489995-38dc-8544-249f-bb98f3e07918
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 21ec8dd4-107a-281b-a9f3-fe20d74a3004
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : f44eba9c-4205-b168-9806-5cad9c37dd74
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : aac69047-ef8d-64f6-adfc-e6e53dc501b5
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : caeafcce-cd4c-51c5-601c-b5e8ddede2b5
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : db237607-5e7b-91b5-05c2-6ca567f02134
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : fc299731-b9df-3542-0bf0-066a069a9f16
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 18dd9bcb-3d72-4f29-49c9-9aa15a8d9632
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 3f285683-71fc-2c09-fdca-13c494de9beb
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : f464807c-74f2-92b6-53e2-210b581d981f
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 61e8769e-bfd9-6cc3-def7-9117806de5d3
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 1c21be2b-4e45-bd52-46ba-aa1e83e6ca28
          name-label ( RO): SR.scan
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : def10529-63eb-c283-2a99-6391ede7c723
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 9041d6d4-827a-0d4b-cff1-c19049239f10
          name-label ( RO): VDI.destroy
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


uuid ( RO)                : 0e6634eb-cd01-e90f-3d06-b0b40460737e
          name-label ( RO): VDI.clone
    name-description ( RO):
              status ( RO): pending
            progress ( RO): 0.000


[root@Rack3Host20 log]#






          Environment: Build from 4.3
    Affects Version/s: 4.3.0
        Fix Version/s: 4.3.0

> Xenserver - After HA , ssvm fails to start on the new host . Also not able to deploy new Vms in this host.
> ----------------------------------------------------------------------------------------------------------
>
>                 Key: CLOUDSTACK-5545
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5545
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>          Components: Management Server
>    Affects Versions: 4.3.0
>         Environment: Build from 4.3
>            Reporter: Sangeetha Hariharan
>            Priority: Critical
>             Fix For: 4.3.0
>
>
> Xenserver - After HA , ssvm fails to start on the new host . Also not able to deploy new Vms in this host.
> Steps to reproduce the problem:
> Set up - Advanced zone with 2 hots (Xenserver 6.2) , host1 and host2.
> All user Vms (~11) and system Vms were running on host1.
> power down host1.
> All the HA enabled user Vms and system Vms were able to successfully start on host2 and are reported as "Running" except for SSVM.
> As part of HA process , seems like there were 2 threads that were trying to work on the SSVM ( one trying to stop Vm and other trying to start Vm).
> SSVM fails to start. I see that ssvm getting destroyed and trying to get recreated over and over again with no success.
> Following exception seen in management server logs:
> com.cloud.utils.exception.CloudRuntimeException: We cannot proceed with stop VM VM[SecondaryStorageVm|s-52-VM] since it is not in 'Stopping' state, current state: Stop
> ped
>         at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1358)
>         at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStop(VirtualMachineManagerImpl.java:1258)
>         at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMachineManagerImpl.java:1231)
>         at com.cloud.ha.HighAvailabilityManagerImpl.restart(HighAvailabilityManagerImpl.java:485)
>         at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.runWithContext(HighAvailabilityManagerImpl.java:842)
>         at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.access$000(HighAvailabilityManagerImpl.java:797)
>         at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread$1.run(HighAvailabilityManagerImpl.java:809)
>         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 com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(HighAvailabilityManagerImpl.java:806)
> 2013-12-17 18:36:47,986 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea2
> 04d8dffe
>            nameLabel: Async.VM.start_on
>      nameDescription:
>    allowedOperations: []
>    currentOperations: {}
>              created: Tue Dec 17 18:36:45 EST 2013
>             finished: Tue Dec 17 18:36:59 EST 2013
>               status: failure
>           residentOn: com.xensource.xenapi.Host@a6594848
>             progress: 1.0
>                 type: <none/>
>               result:
>            errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
>          otherConfig: {debug_info:cancel_points_seen=27}
>            subtaskOf: com.xensource.xenapi.Task@aaf13f6f
>             subtasks: []
> 2013-12-17 18:36:48,022 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) Unable to start VM(s-52-VM) on host(eb0add58-3df6-4870-8937-ac21abe5471b) due to Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
>            nameLabel: Async.VM.start_on
>      nameDescription:
>    allowedOperations: []
>    currentOperations: {}
>              created: Tue Dec 17 18:36:45 EST 2013
>             finished: Tue Dec 17 18:36:59 EST 2013
>               status: failure
>           residentOn: com.xensource.xenapi.Host@a6594848
>             progress: 1.0
>                 type: <none/>
>               result:
>            errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
>          otherConfig: {debug_info:cancel_points_seen=27}
>            subtaskOf: com.xensource.xenapi.Task@aaf13f6f
>             subtasks: []
> Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
>            nameLabel: Async.VM.start_on
>      nameDescription:
>    allowedOperations: []
>    currentOperations: {}
>              created: Tue Dec 17 18:36:45 EST 2013
>             finished: Tue Dec 17 18:36:59 EST 2013
>               status: failure
>           residentOn: com.xensource.xenapi.Host@a6594848
>             progress: 1.0
>                 type: <none/>
>               result:
>            errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
>          otherConfig: {debug_info:cancel_points_seen=27}
>            subtaskOf: com.xensource.xenapi.Task@aaf13f6f
>             subtasks: []
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3751)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3863)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1734)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:550)
>         at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
>         at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
>         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$Sync.innerRun(FutureTask.java:334)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>         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:1110)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:722)
> 2013-12-17 18:36:48,027 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) Catch Exception: class com.cloud.utils.exception.CloudRuntimeException due to com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(s-52-VM) on host(eb0add58-3df6-4870-8937-ac21abe5471b) due to Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
>            nameLabel: Async.VM.start_on
>      nameDescription:
>    allowedOperations: []
>    currentOperations: {}
>              created: Tue Dec 17 18:36:45 EST 2013
>             finished: Tue Dec 17 18:36:59 EST 2013
>               status: failure
>           residentOn: com.xensource.xenapi.Host@a6594848
>             progress: 1.0
>                 type: <none/>
>               result:
>            errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
>          otherConfig: {debug_info:cancel_points_seen=27}
>            subtaskOf: com.xensource.xenapi.Task@aaf13f6f
>             subtasks: []
> com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(s-52-VM) on host(eb0add58-3df6-4870-8937-ac21abe5471b) due to Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
>            nameLabel: Async.VM.start_on
>      nameDescription:
>    allowedOperations: []
>    currentOperations: {}
>              created: Tue Dec 17 18:36:45 EST 2013
>             finished: Tue Dec 17 18:36:59 EST 2013
>               status: failure
>           residentOn: com.xensource.xenapi.Host@a6594848
>             progress: 1.0
>                 type: <none/>
>               result:
>            errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
>          otherConfig: {debug_info:cancel_points_seen=27}
>            subtaskOf: com.xensource.xenapi.Task@aaf13f6f
>             subtasks: []
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3874)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1734)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:550)
>         at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
>         at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
>         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$Sync.innerRun(FutureTask.java:334)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>         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:1110)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:722)
> 2013-12-17 18:36:48,027 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) Unable to start s-52-VM due to
> com.cloud.utils.exception.CloudRuntimeException: Unable to start VM(s-52-VM) on host(eb0add58-3df6-4870-8937-ac21abe5471b) due to Task failed! Task record:                 uuid: f06cf2cc-6583-83aa-516e-6ea204d8dffe
>            nameLabel: Async.VM.start_on
>      nameDescription:
>    allowedOperations: []
>    currentOperations: {}
>              created: Tue Dec 17 18:36:45 EST 2013
>             finished: Tue Dec 17 18:36:59 EST 2013
>               status: failure
>           residentOn: com.xensource.xenapi.Host@a6594848
>             progress: 1.0
>                 type: <none/>
>               result:
>            errorInfo: [HANDLE_INVALID, VM, OpaqueRef:92a6a974-3e40-3acb-a633-cb2a40f5ad6f]
>          otherConfig: {debug_info:cancel_points_seen=27}
>            subtaskOf: com.xensource.xenapi.Task@aaf13f6f
>             subtasks: []
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.startVM(CitrixResourceBase.java:3874)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1734)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:550)
>         at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
>         at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
>         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$Sync.innerRun(FutureTask.java:334)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>         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:1110)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:722)
> 2013-12-17 18:36:48,033 WARN  [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) VM getRecord failed 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:209)
>         at com.xensource.xenapi.Connection.dispatch(Connection.java:368)
>         at com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:909)
>         at com.xensource.xenapi.VM.getRecord(VM.java:572)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.handleVmStartFailure(CitrixResourceBase.java:1427)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:1813)
>         at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:550)
>         at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:59)
>         at com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:106)
>         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$Sync.innerRun(FutureTask.java:334)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>         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:1110)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:722)
> 2013-12-17 18:36:48,033 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) The VM is in stopped state, detected problem during startup : s-52-VM
> 2013-12-17 18:36:48,036 DEBUG [c.c.h.x.r.CitrixResourceBase] (DirectAgent-13:ctx-fdae8cdf) null
> 2013-12-17 18:36:48,036 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-13:ctx-fdae8cdf) Seq 1-1541013657: Cancelling because one of the answers is false and it is stop on error.
> I am also not able to deploy Vms in this host.Following exception seen duing copyCommand.
> 2013-12-17 19:22:40,110 DEBUG [c.c.a.t.Request] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Seq 1-1541013760: Received:  { Ans: , MgmtId: 112516401760401, via: 1, Ver: v1, Flags: 10, { CopyCmdAnswer } }
> 2013-12-17 19:22:40,115 WARN  [o.a.c.s.d.ObjectInDataStoreManagerImpl] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@4ae577a4), no need to delete from object in store ref table
> 2013-12-17 19:22:40,117 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Unable to create Vol[55|vm=55|ROOT]:org.apache.xmlrpc.XmlRpcException: Failed to create input stream: Read timed out
> 2013-12-17 19:22:40,118 INFO  [c.c.v.VirtualMachineManagerImpl] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Unable to contact resource.
> com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is unreachable: Unable to create Vol[55|vm=55|ROOT]:org.apache.xmlrpc.XmlRpcException: Failed to create input stream: Read timed out
>         at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.recreateVolume(VolumeOrchestrator.java:1138)
>         at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.prepare(VolumeOrchestrator.java:1180)
>         at com.cloud.vm.VirtualMachineManagerImpl.orchestrateStart(VirtualMachineManagerImpl.java:904)
>         at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:710)
>         at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:556)
>         at org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:228)
>         at org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
>         at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3559)
>         at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3140)
>         at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3126)
>         at sun.reflect.GeneratedMethodAccessor397.invoke(Unknown Source)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>         at java.lang.reflect.Method.invoke(Method.java:601)
>         at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
>         at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
>         at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
>         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
>         at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
>         at $Proxy171.startVirtualMachine(Unknown Source)
>         at org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:443)
>         at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
>         at com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
>         at com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
>         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 com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
>         at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:521)
>         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$Sync.innerRun(FutureTask.java:334)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:722)
> 2013-12-17 19:22:40,121 DEBUG [c.c.v.VirtualMachineManagerImpl] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Cleaning up resources for the vm VM[User|new123] in Starting state
> 2013-12-17 19:22:40,124 DEBUG [c.c.a.t.Request] (Job-Executor-72:ctx-7d513c65 ctx-df7c39f6) Seq 1-1541013786: Sending  { Cmd , MgmtId: 11251640:
> There seem to be lot of tasks stuck in "Pending" state in the host:
> [root@Rack3Host20 log]# xe task-list
> uuid ( RO)                : 5f8cd758-c12a-e7e7-4b59-be4aaee22e69
>           name-label ( RO): VDI.clone
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : b97cb9c8-488a-d339-745b-81ad03a0dc97
>           name-label ( RO): SR.scan
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : 610e7fb1-337c-04b6-253d-b5affd56b253
>           name-label ( RO): SR.scan
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : f95e7e81-2c43-6a03-ed8a-66b00d47a9cc
>           name-label ( RO): VM.hard_shutdown
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : 2a1b41eb-d5c3-d629-42fa-e54bbbf72662
>           name-label ( RO): VDI.clone
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : af6abf9c-1f1f-ac9e-a5c6-596321ae754a
>           name-label ( RO): SR.scan
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : 2f5826ed-fe0f-4723-6a8a-31732915e684
>           name-label ( RO): SR.scan
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : da57bfe2-bf7f-6440-2e48-efa253938d6a
>           name-label ( RO): VDI.clone
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : 544012b5-d6b6-2e8a-a242-812ccd47da9c
>           name-label ( RO): VDI.clone
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : 5906ffc3-50bb-114f-9583-98a0b3227ecb
>           name-label ( RO): SR.scan
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : ba489995-38dc-8544-249f-bb98f3e07918
>           name-label ( RO): SR.scan
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : 21ec8dd4-107a-281b-a9f3-fe20d74a3004
>           name-label ( RO): VDI.clone
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : f44eba9c-4205-b168-9806-5cad9c37dd74
>           name-label ( RO): VDI.clone
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : aac69047-ef8d-64f6-adfc-e6e53dc501b5
>           name-label ( RO): VDI.clone
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : caeafcce-cd4c-51c5-601c-b5e8ddede2b5
>           name-label ( RO): VDI.clone
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : db237607-5e7b-91b5-05c2-6ca567f02134
>           name-label ( RO): SR.scan
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : fc299731-b9df-3542-0bf0-066a069a9f16
>           name-label ( RO): SR.scan
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : 18dd9bcb-3d72-4f29-49c9-9aa15a8d9632
>           name-label ( RO): VDI.clone
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : 3f285683-71fc-2c09-fdca-13c494de9beb
>           name-label ( RO): SR.scan
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : f464807c-74f2-92b6-53e2-210b581d981f
>           name-label ( RO): VDI.clone
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : 61e8769e-bfd9-6cc3-def7-9117806de5d3
>           name-label ( RO): SR.scan
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : 1c21be2b-4e45-bd52-46ba-aa1e83e6ca28
>           name-label ( RO): SR.scan
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : def10529-63eb-c283-2a99-6391ede7c723
>           name-label ( RO): VDI.clone
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : 9041d6d4-827a-0d4b-cff1-c19049239f10
>           name-label ( RO): VDI.destroy
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> uuid ( RO)                : 0e6634eb-cd01-e90f-3d06-b0b40460737e
>           name-label ( RO): VDI.clone
>     name-description ( RO):
>               status ( RO): pending
>             progress ( RO): 0.000
> [root@Rack3Host20 log]#



--
This message was sent by Atlassian JIRA
(v6.1.4#6159)

Mime
View raw message