Rayees Namathponnan created CLOUDSTACK-6551:
-----------------------------------------------
Summary: [Automation] Failed to revert vm snapshot in xen
Key: CLOUDSTACK-6551
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-6551
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Snapshot, XenServer
Affects Versions: 4.4.0
Environment: Xen 6.2
build 4.4-forward
Reporter: Rayees Namathponnan
Priority: Blocker
Fix For: 4.4.0
Steps to reproduce
Step 1) Create advanced zone on xen
Step 2) Deploy a vm
Step 3) create vm snapshot without memory
step 4) revert the snapshot
Result
Revert snapshot failed with below exception
2014-05-01 06:22:19,439 DEBUG [c.c.n.NetworkModelImpl]
(Work-Job-Executor-32:job-541/job-542 ctx-52a5f490) Service SecurityGroup is
not supported in the network id=241
2014-05-01 06:22:19,464 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-32:job-541/job-542 ctx-52a5f490) Seq 2-5867345889533626796:
Sending { Cmd , MgmtId: 6631563722783, via: 2(Rack1Pod1Host15), Ver: v1,
Flags: 100011,
[{"com.cloud.agent.api.RevertToVMSnapshotCommand":{"reloadVm":false,"volumeTOs":[{"uuid":"ee4093bf-e6f0-49e3-be37-3b5c05fd6845","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"cb8c6c62-71ea-3269-94b9-b1c0a4055d45","id":3,"poolType":"NetworkFilesystem","host":"10.147.28.8","path":"/vol/dgVol/automation/adv/pri_3","port":2049,"url":"NetworkFilesystem://10.147.28.8/vol/dgVol/automation/adv/pri_3/?ROLE=Primary&STOREUUID=cb8c6c62-71ea-3269-94b9-b1c0a4055d45"}},"name":"ROOT-77","size":21474836480,"path":"75f283c8-db97-4b95-96c2-72d981bc7f0c","volumeId":83,"vmName":"i-2-77-VM","accountId":2,"format":"VHD","id":83,"deviceId":0,"hypervisorType":"XenServer"}],"target":{"id":3,"snapshotName":"i-2-77-VM_VS_20140501005100","type":"Disk","createTime":1398905460000,"current":true,"description":"Test
","quiescevm":true},"vmName":"i-2-77-VM","guestOSType":"CentOS 5.6
(64-bit)","wait":0}}] }
2014-05-01 06:22:19,464 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-32:job-541/job-542 ctx-52a5f490) Seq 2-5867345889533626796:
Executing: { Cmd , MgmtId: 6631563722783, via: 2(Rack1Pod1Host15), Ver: v1,
Flags: 100011,
[{"com.cloud.agent.api.RevertToVMSnapshotCommand":{"reloadVm":false,"volumeTOs":[{"uuid":"ee4093bf-e6f0-49e3-be37-3b5c05fd6845","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"cb8c6c62-71ea-3269-94b9-b1c0a4055d45","id":3,"poolType":"NetworkFilesystem","host":"10.147.28.8","path":"/vol/dgVol/automation/adv/pri_3","port":2049,"url":"NetworkFilesystem://10.147.28.8/vol/dgVol/automation/adv/pri_3/?ROLE=Primary&STOREUUID=cb8c6c62-71ea-3269-94b9-b1c0a4055d45"}},"name":"ROOT-77","size":21474836480,"path":"75f283c8-db97-4b95-96c2-72d981bc7f0c","volumeId":83,"vmName":"i-2-77-VM","accountId":2,"format":"VHD","id":83,"deviceId":0,"hypervisorType":"XenServer"}],"target":{"id":3,"snapshotName":"i-2-77-VM_VS_20140501005100","type":"Disk","createTime":1398905460000,"current":true,"description":"Test
","quiescevm":true},"vmName":"i-2-77-VM","guestOSType":"CentOS 5.6
(64-bit)","wait":0}}] }
2014-05-01 06:22:19,465 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-233:ctx-acc9e792) Seq 2-5867345889533626796: Executing request
2014-05-01 06:22:20,084 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-2:null) SeqA 8-4288: Processing Seq 8-4288: { Cmd ,
MgmtId: -1, via: 8, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":3,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2014-05-01 06:22:20,089 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-2:null) SeqA 8-4288: Sending Seq 8-4288: { Ans: ,
MgmtId: 6631563722783, via: 8, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2014-05-01 06:22:20,524 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-233:ctx-acc9e792) Task failed! Task record: uuid:
1affb5ba-5bcf-4e86-f866-c3cbba89dff8
nameLabel: Async.host.call_plugin
nameDescription:
allowedOperations: []
currentOperations: {}
created: Wed Apr 30 20:08:59 IST 2014
finished: Wed Apr 30 20:08:59 IST 2014
status: failure
residentOn: com.xensource.xenapi.Host@e88e6ba5
progress: 1.0
type: <none/>
result:
errorInfo: [UNKNOWN_XENAPI_PLUGIN_FUNCTION, revert_memory_snapshot]
otherConfig: {}
subtaskOf: com.xensource.xenapi.Task@aaf13f6f
subtasks: []
2014-05-01 06:22:20,528 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-233:ctx-acc9e792) callHostPlugin failed for cmd:
revert_memory_snapshot with args hostUUID:
71567ecf-6bae-4aaf-8040-863d3175b885, snapshotUUID:
ca1506e7-63ca-8bcb-c920-3242b7f98d5d, oldVmUuid:
79cc862a-078e-df77-8e28-ffbccd3df635, snapshotMemory: false, vmName: i-2-77-VM,
due to Task failed! Task record: uuid:
1affb5ba-5bcf-4e86-f866-c3cbba89dff8
nameLabel: Async.host.call_plugin
nameDescription:
allowedOperations: []
currentOperations: {}
created: Wed Apr 30 20:08:59 IST 2014
finished: Wed Apr 30 20:08:59 IST 2014
status: failure
residentOn: com.xensource.xenapi.Host@e88e6ba5
progress: 1.0
type: <none/>
result:
errorInfo: [UNKNOWN_XENAPI_PLUGIN_FUNCTION, revert_memory_snapshot]
otherConfig: {}
subtaskOf: com.xensource.xenapi.Task@aaf13f6f
subtasks: []
Task failed! Task record: uuid:
1affb5ba-5bcf-4e86-f866-c3cbba89dff8
nameLabel: Async.host.call_plugin
nameDescription:
allowedOperations: []
currentOperations: {}
created: Wed Apr 30 20:08:59 IST 2014
finished: Wed Apr 30 20:08:59 IST 2014
status: failure
residentOn: com.xensource.xenapi.Host@e88e6ba5
progress: 1.0
type: <none/>
result:
errorInfo: [UNKNOWN_XENAPI_PLUGIN_FUNCTION, revert_memory_snapshot]
otherConfig: {}
subtaskOf: com.xensource.xenapi.Task@aaf13f6f
subtasks: []
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3346)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.callHostPluginAsync(CitrixResourceBase.java:3560)
at
com.cloud.hypervisor.xen.resource.Xenserver625Resource.revertToSnapshot(Xenserver625Resource.java:142)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:815)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:548)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:60)
at
com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:93)
at
com.cloud.hypervisor.xen.resource.XenServer620SP1Resource.executeRequest(XenServer620SP1Resource.java:64)
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(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown
Source)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
2014-05-01 06:22:20,533 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-233:ctx-acc9e792) unable to destroy
task(com.xensource.xenapi.Task@7f25d34d) on
host(71567ecf-6bae-4aaf-8040-863d3175b885) due to
You gave an invalid object reference. The object may have recently been
deleted. The class parameter gives the type of reference given, and the handle
parameter echoes the bad value given.
at com.xensource.xenapi.Types.checkResponse(Types.java:693)
at com.xensource.xenapi.Connection.dispatch(Connection.java:350)
at
com.cloud.hypervisor.xen.resource.XenServerConnectionPool$XenServerConnection.dispatch(XenServerConnectionPool.java:456)
at com.xensource.xenapi.Task.destroy(Task.java:616)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.callHostPluginAsync(CitrixResourceBase.java:3576)
at
com.cloud.hypervisor.xen.resource.Xenserver625Resource.revertToSnapshot(Xenserver625Resource.java:142)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:815)
at
com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:548)
at
com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:60)
at
com.cloud.hypervisor.xen.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:93)
at
com.cloud.hypervisor.xen.resource.XenServer620SP1Resource.executeRequest(XenServer620SP1Resource.java:64)
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(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown
Source)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown
Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
2014-05-01 06:22:20,534 WARN [c.c.h.x.r.Xenserver625Resource]
(DirectAgent-233:ctx-acc9e792) revert_memory_snapshot return null
2014-05-01 06:22:20,534 ERROR [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-233:ctx-acc9e792) revert vm i-2-77-VM to snapshot
i-2-77-VM_VS_20140501005100 failed due to revert_memory_snapshot return null
2014-05-01 06:22:20,534 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-233:ctx-acc9e792) Seq 2-5867345889533626796: Response Received:
2014-05-01 06:22:20,534 DEBUG [c.c.a.t.Request] (DirectAgent-233:ctx-acc9e792)
Seq 2-5867345889533626796: Processing: { Ans: , MgmtId: 6631563722783, via: 2,
Ver: v1, Flags: 10,
[{"com.cloud.agent.api.RevertToVMSnapshotAnswer":{"result":false,"details":"revert_memory_snapshot
return null","wait":0}}] }
2014-05-01 06:22:20,535 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-32:job-541/job-542 ctx-52a5f490) Seq 2-5867345889533626796:
Received: { Ans: , MgmtId: 6631563722783, via: 2, Ver: v1, Flags: 10, {
RevertToVMSnapshotAnswer } }
2014-05-01 06:22:20,535 ERROR [o.a.c.s.v.DefaultVMSnapshotStrategy]
(Work-Job-Executor-32:job-541/job-542 ctx-52a5f490) Revert VM: i-2-77-VM to
snapshot: i-2-77-VM_VS_20140501005100 failed due to revert_memory_snapshot
return null
2014-05-01 06:22:20,541 DEBUG [c.c.v.s.VMSnapshotManagerImpl]
(Work-Job-Executor-32:job-541/job-542 ctx-52a5f490) Failed to revert
vmsnapshot: 3
com.cloud.utils.exception.CloudRuntimeException: Revert VM: i-2-77-VM to
snapshot: i-2-77-VM_VS_20140501005100 failed due to revert_memory_snapshot
return null
at
org.apache.cloudstack.storage.vmsnapshot.DefaultVMSnapshotStrategy.revertVMSnapshot(DefaultVMSnapshotStrategy.java:348)
at
com.cloud.vm.snapshot.VMSnapshotManagerImpl.orchestrateRevertToVMSnapshot(VMSnapshotManagerImpl.java:692)
at
com.cloud.vm.snapshot.VMSnapshotManagerImpl.orchestrateRevertToVMSnapshot(VMSnapshotManagerImpl.java:1060)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.snapshot.VMSnapshotManagerImpl.handleVmWorkJob(VMSnapshotManagerImpl.java:1072)
at sun.reflect.GeneratedMethodAccessor442.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy182.handleVmWorkJob(Unknown Source)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:495)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:452)
at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
at java.util.concurrent.FutureTask.run(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
2014-05-01 06:22:20,543 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-32:job-541/job-542 ctx-52a5f490) Done executing VM work job:
com.cloud.vm.snapshot.VmWorkRevertToVMSnapshot{"vmSnapshotId":3,"userId":2,"accountId":2,"vmId":77,"handlerName":"VMSnapshotManagerImpl"}
2014-05-01 06:22:20,543 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-32:job-541/job-542 ctx-52a5f490) Complete async job-542,
jobStatus: SUCCEEDED, resultCode: 0, result: null
2014-05-01 06:22:20,552 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-32:job-541/job-542) Done with run of VM work job:
com.cloud.vm.snapshot.VmWorkRevertToVMSnapshot for VM 77, job origin: 541
2014-05-01 06:22:20,552 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-32:job-541/job-542) Done executing
com.cloud.vm.snapshot.VmWorkRevertToVMSnapshot for job-542
2014-05-01 06:22:20,571 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl]
(Work-Job-Executor-32:job-541/job-542) Sync queue (195) is currently empty
2014-05-01 06:22:20,571 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-32:job-541/job-542) Remove job-542 from job monitoring
2014-05-01 06:22:20,575 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-63:job-541 ctx-59a43e22) Complete async job-541, jobStatus:
SUCCEEDED, resultCode: 0, result:
org.apache.cloudstack.api.response.UserVmResponse/virtualmachine/{"id":"96d9c5bd-8c68-415c-ad63-b61f7f8a6df9","name":"ryzVM","displayname":"ryzVM","account":"admin","domainid":"22feae40-d076-11e3-8dca-06080800001f","domain":"ROOT","created":"2014-05-01T05:51:08+0530","state":"Stopped","haenable":false,"zoneid":"e7780fe8-fbc1-418a-b649-7180d01618e1","zonename":"Sandbox-XenServer","templateid":"2303a382-d076-11e3-8dca-06080800001f","templatename":"CentOS
5.6(64-bit) no GUI (XenServer)","templatedisplaytext":"CentOS 5.6(64-bit) no
GUI
(XenServer)","passwordenabled":false,"serviceofferingid":"2a4ab42a-c318-4691-b9d5-b3eb2597e9b2","serviceofferingname":"Tiny
Instance","cpunumber":1,"cpuspeed":100,"memory":256,"cpuused":"0%","networkkbsread":0,"networkkbswrite":0,"diskkbsread":0,"diskkbswrite":0,"diskioread":0,"diskiowrite":0,"guestosid":"2336f58e-d076-11e3-8dca-06080800001f","rootdeviceid":0,"rootdevicetype":"ROOT","securitygroup":[],"nic":[{"id":"972b91b8-9755-4c84-9827-504035930788","networkid":"71a4b205-ee49-443d-acf4-b56817a9afa5","networkname":"ryzNW","netmask":"255.255.255.0","gateway":"10.1.1.1","ipaddress":"10.1.1.240","traffictype":"Guest","type":"Isolated","isdefault":true,"macaddress":"02:00:02:34:00:01"}],"hypervisor":"XenServer","instancename":"i-2-77-VM","tags":[],"details":{"hypervisortoolsversion":"xenserver56"},"affinitygroup":[],"displayvm":true,"isdynamicallyscalable":true,"ostypeid":142}
2014-05-01 06:22:20,581 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-63:job-541) Done executing
org.apache.cloudstack.api.command.admin.vmsnapshot.RevertToVMSnapshotCmdByAdmin
for job-541
2014-05-01 06:22:20,585 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-63:job-541) Remove job-541 from job monitoring
2014-05-01 06:22:21,296 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-3:null) SeqA 11-3884: Processing Seq 11-3884: { Cmd ,
MgmtId: -1, via: 11, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":69,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2014-05-01 06:22:21,302 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-3:null) SeqA 11-3884: Sending Seq 11-3884: { Ans: ,
MgmtId: 6631563722783, via: 11, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
--
This message was sent by Atlassian JIRA
(v6.2#6252)
