You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Sangeetha Hariharan (JIRA)" <ji...@apache.org> on 2013/12/18 20:35:07 UTC
[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.
[ 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)