Abhinandan Prateek created CLOUDSTACK-8196:
----------------------------------------------
Summary: Local storage - Live VM migration fails
Key: CLOUDSTACK-8196
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-8196
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Volumes
Affects Versions: 4.5.0
Environment: Xenserver 6.5
Reporter: Abhinandan Prateek
Priority: Blocker
Fix For: 4.5.0
When you live migrate a VM with its root volume on local storage it fails with
following in the logs:
2015-02-03 17:41:17,697 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Executing AsyncJobVO {id:30,
userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd:
com.cloud.vm.VmWorkMigrate, cmdInfo:
rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZVdpdGhTdG9yYWdlsew9z6UxtXMCAANKAApkZXN0SG9zdElkSgAJc3JjSG9zdElkTAAMdm9sdW1lVG9Qb29sdAAPTGphdmEvdXRpbC9NYXA7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAIAAAAAAAAAAgAAAAAAAAAEdAAZVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbAAAAAAAAAAEAAAAAAAAAAFzcgARamF2YS51dGlsLkhhc2hNYXAFB9rBwxZg0QMAAkYACmxvYWRGYWN0b3JJAAl0aHJlc2hvbGR4cD9AAAAAAAAQdwgAAAAQAAAAAHg,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 345043735628, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Tue Feb 03 17:41:16 IST 2015}
2015-02-03 17:41:17,698 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Run VM work job:
com.cloud.vm.VmWorkMigrate for VM 4, job origin: 29
2015-02-03 17:41:17,699 DEBUG [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Execute VM work
job:
com.cloud.vm.VmWorkMigrateWithStorage{"srcHostId":1,"destHostId":4,"volumeToPool":{},"userId":2,"accountId":2,"vmId":4,"handlerName":"VirtualMachineManagerImpl"}
2015-02-03 17:41:17,699 DEBUG [o.a.c.s.SecondaryStorageManagerImpl]
(secstorage-1:ctx-821cceb5) Zone 1 is ready to launch secondary storage VM
2015-02-03 17:41:17,706 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611)
LocalStoragePoolAllocator trying to find storage pool to fit the vm
2015-02-03 17:41:17,710 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Checking if
storage pool is suitable, name: null ,poolId: 2
2015-02-03 17:41:17,712 INFO [c.c.s.StorageManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Storage pool null
(2) does not supply IOPS capacity, assuming enough capacity
2015-02-03 17:41:17,714 DEBUG [c.c.s.StorageManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Checking pool 2
for storage, totalSize: 34347155456, usedBytes: 4194304, usedPct:
1.2211503236048357E-4, disable threshold: 0.99
2015-02-03 17:41:17,718 DEBUG [c.c.s.StorageManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Found storage
pool xen652 Local Storage of type LVM
2015-02-03 17:41:17,718 DEBUG [c.c.s.StorageManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Total capacity of
the pool xen652 Local Storage id: 2 is 34347155456
2015-02-03 17:41:17,718 DEBUG [c.c.s.StorageManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Checking pool: 2
for volume allocation [Vol[4|vm=4|ROOT]], maxSize : 34347155456,
totalAllocatedSize : 0, askingSize : 0, allocated disable threshold: 0.99
2015-02-03 17:41:17,718 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Found suitable
local storage pool 2, adding to list
2015-02-03 17:41:17,718 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611)
LocalStoragePoolAllocator returning 1 suitable storage pools
2015-02-03 17:41:17,719 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611)
ClusterScopeStoragePoolAllocator looking for storage pool
2015-02-03 17:41:17,719 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611)
ZoneWideStoragePoolAllocator to find storage pool
2015-02-03 17:41:17,723 DEBUG [c.c.n.NetworkModelImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Service
SecurityGroup is not supported in the network id=204
2015-02-03 17:41:17,726 DEBUG [o.a.c.e.o.VolumeOrchestrator]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Preparing 1
volumes for VM[User|i-2-4-VM]
2015-02-03 17:41:17,747 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) VM state
transitted from :Running to Migrating with event: MigrationRequestedvm's
original host id: 1 new host id: 4 host id before state transition: 1
2015-02-03 17:41:17,754 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Hosts's actual
total CPU: 6382 and CPU after applying overprovisioning: 25528
2015-02-03 17:41:17,754 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) We are allocating
VM, increasing the used capacity of this host:4
2015-02-03 17:41:17,754 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Current Used CPU:
0 , Free CPU:25528 ,Requested CPU: 500
2015-02-03 17:41:17,754 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Current Used RAM:
0 , Free RAM:3266390016 ,Requested RAM: 134217728
2015-02-03 17:41:17,754 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) CPU STATS after
allocation: for host: 4, old used: 0, old reserved: 0, actual total: 6382,
total with overprovisioning: 25528; new used:500, reserved:0; requested
cpu:500,alloc_from_last:false
2015-02-03 17:41:17,754 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) RAM STATS after
allocation: for host: 4, old used: 0, old reserved: 0, total: 3266390016; new
used: 134217728, reserved: 0; requested mem: 134217728,alloc_from_last:false
2015-02-03 17:41:17,777 DEBUG [c.c.c.ConsoleProxyManagerImpl]
(consoleproxy-1:ctx-656ffab6) Zone 1 is ready to launch console proxy
2015-02-03 17:41:17,785 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Seq
4-379428268605964298: Sending { Cmd , MgmtId: 345043735628, via: 4(xen652),
Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.MigrateWithStorageCommand":{"vm":{"id":4,"name":"i-2-4-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"CentOS
5.6 (64-bit)","platformEmulator":"CentOS 5
(64-bit)","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":true,"vncPassword":"2M0FMXjOhAukbg729Jj05Q==","params":{"memoryOvercommitRatio":"1.0","platform":"viridian:true;acpi:1;apic:true;pae:true;nx:true","cpuOvercommitRatio":"4.0","hypervisortoolsversion":"xenserver56"},"uuid":"e9b86cce-fdc2-4b26-bb6e-322118f30ddf","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"cfae7b2b-d019-414a-8332-b87a59577392","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"70d1dc4e-b70c-0b44-9f87-794905e5863d","id":1,"poolType":"LVM","host":"192.168.217.12","path":"lvm","port":0,"url":"LVM://192.168.217.12/lvm/?ROLE=Primary&STOREUUID=70d1dc4e-b70c-0b44-9f87-794905e5863d"}},"name":"ROOT-4","size":21474836480,"path":"b2baca19-68e9-4b11-8091-48f95f11e9c7","volumeId":4,"vmName":"i-2-4-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":4,"deviceId":0,"hypervisorType":"XenServer"}},"diskSeq":0,"path":"b2baca19-68e9-4b11-8091-48f95f11e9c7","type":"ROOT","_details":{"managed":"false","storagePort":"0","storageHost":"192.168.217.12","volumeSize":"21474836480"}},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":-1,"defaultNic":true,"pxeDisable":false,"nicUuid":"d868298c-70ce-4523-a61e-4d201a091d9f","uuid":"198d58c3-333b-43f1-92d1-7163a6207059","ip":"10.1.1.132","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:39:b9:00:02","dns1":"192.168.100.1","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://646","isolationUri":"vlan://646","isSecurityGroupEnabled":false,"name":"GUEST"}],"vcpuMaxLimit":16},"volumeToFiler":{"Vol[4|ROOT|b2baca19-68e9-4b11-8091-48f95f11e9c7|21474836480]":{"id":2,"uuid":"d3e92b9d-1ae5-616c-aa17-dc22edb614e6","host":"192.168.217.14","path":"lvm","port":0,"type":"LVM"}},"wait":0}}]
}
2015-02-03 17:41:17,786 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Seq
4-379428268605964298: Executing: { Cmd , MgmtId: 345043735628, via: 4(xen652),
Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.MigrateWithStorageCommand":{"vm":{"id":4,"name":"i-2-4-VM","bootloader":"PyGrub","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"CentOS
5.6 (64-bit)","platformEmulator":"CentOS 5
(64-bit)","bootArgs":"","enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":true,"vncPassword":"2M0FMXjOhAukbg729Jj05Q==","params":{"memoryOvercommitRatio":"1.0","platform":"viridian:true;acpi:1;apic:true;pae:true;nx:true","cpuOvercommitRatio":"4.0","hypervisortoolsversion":"xenserver56"},"uuid":"e9b86cce-fdc2-4b26-bb6e-322118f30ddf","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"cfae7b2b-d019-414a-8332-b87a59577392","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"70d1dc4e-b70c-0b44-9f87-794905e5863d","id":1,"poolType":"LVM","host":"192.168.217.12","path":"lvm","port":0,"url":"LVM://192.168.217.12/lvm/?ROLE=Primary&STOREUUID=70d1dc4e-b70c-0b44-9f87-794905e5863d"}},"name":"ROOT-4","size":21474836480,"path":"b2baca19-68e9-4b11-8091-48f95f11e9c7","volumeId":4,"vmName":"i-2-4-VM","accountId":2,"format":"VHD","provisioningType":"THIN","id":4,"deviceId":0,"hypervisorType":"XenServer"}},"diskSeq":0,"path":"b2baca19-68e9-4b11-8091-48f95f11e9c7","type":"ROOT","_details":{"managed":"false","storagePort":"0","storageHost":"192.168.217.12","volumeSize":"21474836480"}},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":-1,"defaultNic":true,"pxeDisable":false,"nicUuid":"d868298c-70ce-4523-a61e-4d201a091d9f","uuid":"198d58c3-333b-43f1-92d1-7163a6207059","ip":"10.1.1.132","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:39:b9:00:02","dns1":"192.168.100.1","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://646","isolationUri":"vlan://646","isSecurityGroupEnabled":false,"name":"GUEST"}],"vcpuMaxLimit":16},"volumeToFiler":{"Vol[4|ROOT|b2baca19-68e9-4b11-8091-48f95f11e9c7|21474836480]":{"id":2,"uuid":"d3e92b9d-1ae5-616c-aa17-dc22edb614e6","host":"192.168.217.14","path":"lvm","port":0,"type":"LVM"}},"wait":0}}]
}
2015-02-03 17:41:17,786 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-47:ctx-d9cdee8c) Seq 4-379428268605964298: Executing request
2015-02-03 17:41:17,838 DEBUG [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-47:ctx-d9cdee8c) SR retrieved for
d3e92b9d-1ae5-616c-aa17-dc22edb614e6
2015-02-03 17:41:17,843 DEBUG [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-47:ctx-d9cdee8c) Checking d3e92b9d-1ae5-616c-aa17-dc22edb614e6 or
SR d3e92b9d-1ae5-616c-aa17-dc22edb614e6 on
XS[2df4562d-5f47-4345-9fed-95da6b798b45-192.168.217.14]
2015-02-03 17:41:19,879 DEBUG [c.c.a.ApiServlet]
(1369188023@qtp-2043850624-13:ctx-2054c360) ===START=== 192.168.100.30 -- GET
command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945678234
2015-02-03 17:41:19,896 DEBUG [c.c.a.ApiServlet]
(1369188023@qtp-2043850624-13:ctx-2054c360 ctx-2341000e) ===END===
192.168.100.30 -- GET
command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945678234
2015-02-03 17:41:21,092 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-2:null) SeqA 2-248: Processing Seq 2-248: { Cmd ,
MgmtId: -1, via: 2, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2015-02-03 17:41:21,096 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-2:null) SeqA 2-248: Sending Seq 2-248: { Ans: , MgmtId:
345043735628, via: 2, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-02-03 17:41:21,691 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-66d27604) Begin cleanup expired async-jobs
2015-02-03 17:41:21,694 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-66d27604) End cleanup expired async-jobs
2015-02-03 17:41:22,881 DEBUG [c.c.a.ApiServlet]
(1369188023@qtp-2043850624-13:ctx-ab1c5d96) ===START=== 192.168.100.30 -- GET
command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945681235
2015-02-03 17:41:22,900 DEBUG [c.c.a.ApiServlet]
(1369188023@qtp-2043850624-13:ctx-ab1c5d96 ctx-2593d89e) ===END===
192.168.100.30 -- GET
command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945681235
2015-02-03 17:41:25,885 DEBUG [c.c.a.ApiServlet]
(1369188023@qtp-2043850624-13:ctx-427870e5) ===START=== 192.168.100.30 -- GET
command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945684238
2015-02-03 17:41:25,894 DEBUG [c.c.a.ApiServlet]
(1369188023@qtp-2043850624-13:ctx-427870e5 ctx-5d7c65ce) ===END===
192.168.100.30 -- GET
command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945684238
2015-02-03 17:41:25,898 WARN [c.c.h.x.r.CitrixResourceBase]
(DirectAgent-47:ctx-d9cdee8c) Task failed! Task record: uuid:
80e2ab71-fa8d-ebbd-fdae-3edb3657f459
nameLabel: Async.VM.migrate_send
nameDescription:
allowedOperations: []
currentOperations: {}
created: Sat Jan 31 11:38:59 IST 2015
finished: Sat Jan 31 11:39:07 IST 2015
status: failure
residentOn: com.xensource.xenapi.Host@50b4f213
progress: 1.0
type: <none/>
result:
errorInfo: [SR_BACKEND_FAILURE_44, , There is insufficient space]
otherConfig: {}
subtaskOf: com.xensource.xenapi.Task@aaf13f6f
subtasks: []
2015-02-03 17:41:25,904 WARN [c.c.h.x.r.XenServer610Resource]
(DirectAgent-47:ctx-d9cdee8c) Catch Exception
com.xensource.xenapi.Types$BadAsyncResult. Storage motion failed due to Task
failed! Task record: uuid: 80e2ab71-fa8d-ebbd-fdae-3edb3657f459
nameLabel: Async.VM.migrate_send
nameDescription:
allowedOperations: []
currentOperations: {}
created: Sat Jan 31 11:38:59 IST 2015
finished: Sat Jan 31 11:39:07 IST 2015
status: failure
residentOn: com.xensource.xenapi.Host@50b4f213
progress: 1.0
type: <none/>
result:
errorInfo: [SR_BACKEND_FAILURE_44, , There is insufficient space]
otherConfig: {}
subtaskOf: com.xensource.xenapi.Task@aaf13f6f
subtasks: []
Task failed! Task record: uuid:
80e2ab71-fa8d-ebbd-fdae-3edb3657f459
nameLabel: Async.VM.migrate_send
nameDescription:
allowedOperations: []
currentOperations: {}
created: Sat Jan 31 11:38:59 IST 2015
finished: Sat Jan 31 11:39:07 IST 2015
status: failure
residentOn: com.xensource.xenapi.Host@50b4f213
progress: 1.0
type: <none/>
result:
errorInfo: [SR_BACKEND_FAILURE_44, , There is insufficient space]
otherConfig: {}
subtaskOf: com.xensource.xenapi.Task@aaf13f6f
subtasks: []
at
com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3203)
at
com.cloud.hypervisor.xenserver.resource.XenServer610Resource.execute(XenServer610Resource.java:170)
at
com.cloud.hypervisor.xenserver.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:77)
at
com.cloud.hypervisor.xenserver.resource.XenServer620SP1Resource.executeRequest(XenServer620SP1Resource.java:65)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:304)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-03 17:41:25,910 DEBUG [c.c.h.x.r.XenServer610Resource]
(DirectAgent-47:ctx-d9cdee8c) Unable to destroy task
com.xensource.xenapi.Task@75fb5c on host 2df4562d-5f47-4345-9fed-95da6b798b45
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.
2015-02-03 17:41:25,910 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-47:ctx-d9cdee8c) Seq 4-379428268605964298: Response Received:
2015-02-03 17:41:25,910 DEBUG [c.c.a.t.Request] (DirectAgent-47:ctx-d9cdee8c)
Seq 4-379428268605964298: Processing: { Ans: , MgmtId: 345043735628, via: 4,
Ver: v1, Flags: 110,
[{"com.cloud.agent.api.MigrateWithStorageAnswer":{"result":false,"details":"Exception:
com.xensource.xenapi.Types$BadAsyncResult\nMessage: null\nStack: Task failed!
Task record: uuid: 80e2ab71-fa8d-ebbd-fdae-3edb3657f459\n
nameLabel: Async.VM.migrate_send\n nameDescription: \n
allowedOperations: []\n currentOperations: {}\n created: Sat Jan
31 11:38:59 IST 2015\n finished: Sat Jan 31 11:39:07 IST 2015\n
status: failure\n residentOn:
com.xensource.xenapi.Host@50b4f213\n progress: 1.0\n
type: <none/>\n result: \n errorInfo:
[SR_BACKEND_FAILURE_44, , There is insufficient space]\n otherConfig:
{}\n subtaskOf: com.xensource.xenapi.Task@aaf13f6f\n
subtasks: []\n\n\tat
com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3203)\n\tat
com.cloud.hypervisor.xenserver.resource.XenServer610Resource.execute(XenServer610Resource.java:170)\n\tat
com.cloud.hypervisor.xenserver.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:77)\n\tat
com.cloud.hypervisor.xenserver.resource.XenServer620SP1Resource.executeRequest(XenServer620SP1Resource.java:65)\n\tat
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:304)\n\tat
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)\n\tat
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)\n\tat
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)\n\tat
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)\n\tat
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)\n\tat
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)\n\tat
java.util.concurrent.FutureTask.run(FutureTask.java:262)\n\tat
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)\n\tat
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat
java.lang.Thread.run(Thread.java:745)\n","wait":0}}] }
2015-02-03 17:41:25,910 DEBUG [c.c.a.m.AgentAttache]
(DirectAgent-47:ctx-d9cdee8c) Seq 4-379428268605964298: No more commands found
2015-02-03 17:41:25,910 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Seq
4-379428268605964298: Received: { Ans: , MgmtId: 345043735628, via: 4, Ver:
v1, Flags: 110, { MigrateWithStorageAnswer } }
2015-02-03 17:41:25,910 ERROR [o.a.c.s.m.XenServerStorageMotionStrategy]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Migration with
storage of vm VM[User|i-2-4-VM] failed. Details: Exception:
com.xensource.xenapi.Types$BadAsyncResult
Message: null
Stack: Task failed! Task record: uuid:
80e2ab71-fa8d-ebbd-fdae-3edb3657f459
nameLabel: Async.VM.migrate_send
nameDescription:
allowedOperations: []
currentOperations: {}
created: Sat Jan 31 11:38:59 IST 2015
finished: Sat Jan 31 11:39:07 IST 2015
status: failure
residentOn: com.xensource.xenapi.Host@50b4f213
progress: 1.0
type: <none/>
result:
errorInfo: [SR_BACKEND_FAILURE_44, , There is insufficient space]
otherConfig: {}
subtaskOf: com.xensource.xenapi.Task@aaf13f6f
subtasks: []
at
com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3203)
at
com.cloud.hypervisor.xenserver.resource.XenServer610Resource.execute(XenServer610Resource.java:170)
at
com.cloud.hypervisor.xenserver.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:77)
at
com.cloud.hypervisor.xenserver.resource.XenServer620SP1Resource.executeRequest(XenServer620SP1Resource.java:65)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:304)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-03 17:41:25,911 ERROR [o.a.c.s.m.XenServerStorageMotionStrategy]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) copy failed
com.cloud.utils.exception.CloudRuntimeException: Error while migrating the vm
VM[User|i-2-4-VM] to host Host[-4-Routing]. Exception:
com.xensource.xenapi.Types$BadAsyncResult
Message: null
Stack: Task failed! Task record: uuid:
80e2ab71-fa8d-ebbd-fdae-3edb3657f459
nameLabel: Async.VM.migrate_send
nameDescription:
allowedOperations: []
currentOperations: {}
created: Sat Jan 31 11:38:59 IST 2015
finished: Sat Jan 31 11:39:07 IST 2015
status: failure
residentOn: com.xensource.xenapi.Host@50b4f213
progress: 1.0
type: <none/>
result:
errorInfo: [SR_BACKEND_FAILURE_44, , There is insufficient space]
otherConfig: {}
subtaskOf: com.xensource.xenapi.Task@aaf13f6f
subtasks: []
at
com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3203)
at
com.cloud.hypervisor.xenserver.resource.XenServer610Resource.execute(XenServer610Resource.java:170)
at
com.cloud.hypervisor.xenserver.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:77)
at
com.cloud.hypervisor.xenserver.resource.XenServer620SP1Resource.executeRequest(XenServer620SP1Resource.java:65)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:304)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
at
org.apache.cloudstack.storage.motion.XenServerStorageMotionStrategy.migrateVmWithVolumesWithinCluster(XenServerStorageMotionStrategy.java:211)
at
org.apache.cloudstack.storage.motion.XenServerStorageMotionStrategy.copyAsync(XenServerStorageMotionStrategy.java:115)
at
org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:90)
at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.migrateVolumes(VolumeServiceImpl.java:1156)
at
org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:986)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2169)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4493)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4596)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:536)
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:493)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-03 17:41:25,920 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Unsupported data
object (VOLUME,
org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@739ed156), no need
to delete from object in store ref table
2015-02-03 17:41:25,920 DEBUG [o.a.c.e.o.VolumeOrchestrator]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Failed to
migrated vm VM[User|i-2-4-VM] along with its volumes.
com.cloud.utils.exception.CloudRuntimeException: Error while migrating the vm
VM[User|i-2-4-VM] to host Host[-4-Routing]. Exception:
com.xensource.xenapi.Types$BadAsyncResult
Message: null
Stack: Task failed! Task record: uuid:
80e2ab71-fa8d-ebbd-fdae-3edb3657f459
nameLabel: Async.VM.migrate_send
nameDescription:
allowedOperations: []
currentOperations: {}
created: Sat Jan 31 11:38:59 IST 2015
finished: Sat Jan 31 11:39:07 IST 2015
status: failure
residentOn: com.xensource.xenapi.Host@50b4f213
progress: 1.0
type: <none/>
result:
errorInfo: [SR_BACKEND_FAILURE_44, , There is insufficient space]
otherConfig: {}
subtaskOf: com.xensource.xenapi.Task@aaf13f6f
subtasks: []
at
com.cloud.hypervisor.xenserver.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3203)
at
com.cloud.hypervisor.xenserver.resource.XenServer610Resource.execute(XenServer610Resource.java:170)
at
com.cloud.hypervisor.xenserver.resource.XenServer610Resource.executeRequest(XenServer610Resource.java:77)
at
com.cloud.hypervisor.xenserver.resource.XenServer620SP1Resource.executeRequest(XenServer620SP1Resource.java:65)
at
com.cloud.agent.manager.DirectAgentAttache$Task.runInContext(DirectAgentAttache.java:304)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at
org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at
org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-03 17:41:25,920 INFO [c.c.v.VirtualMachineManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Migration was
unsuccessful. Cleaning up: VM[User|i-2-4-VM]
2015-02-03 17:41:25,922 WARN [o.a.c.alerts] (Work-Job-Executor-5:ctx-bf4fe907
job-29/job-30 ctx-4ddcb611) alertType:: 17 // dataCenterId:: 1 // podId:: 1 //
clusterId:: null // message:: Unable to migrate vm i-2-4-VM from host xen651 in
zone ZoneA and pod ZoneA
2015-02-03 17:41:25,928 DEBUG [c.c.a.m.AgentAttache]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Seq
4-379428268605964299: Routed from 345043735628
2015-02-03 17:41:25,929 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Seq
4-379428268605964299: Sending { Cmd , MgmtId: 345043735628, via: 4(xen652),
Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"i-2-4-VM","wait":0}}]
}
2015-02-03 17:41:25,929 DEBUG [c.c.a.t.Request]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Seq
4-379428268605964299: Executing: { Cmd , MgmtId: 345043735628, via: 4(xen652),
Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"checkBeforeCleanup":false,"vmName":"i-2-4-VM","wait":0}}]
}
2015-02-03 17:41:25,929 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-24:ctx-aa18b608) Seq 4-379428268605964299: Executing request
2015-02-03 17:41:25,938 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) VM state
transitted from :Migrating to Running with event: OperationFailedvm's original
host id: 1 new host id: 1 host id before state transition: 4
2015-02-03 17:41:25,947 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgent-24:ctx-aa18b608) Seq 4-379428268605964299: Response Received:
2015-02-03 17:41:25,947 DEBUG [c.c.a.t.Request] (DirectAgent-24:ctx-aa18b608)
Seq 4-379428268605964299: Processing: { Ans: , MgmtId: 345043735628, via: 4,
Ver: v1, Flags: 10,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"details":"VM does not
exist","wait":0}}] }
2015-02-03 17:41:25,947 DEBUG [c.c.a.m.AgentAttache]
(DirectAgent-24:ctx-aa18b608) Seq 4-379428268605964299: Unable to find listener.
2015-02-03 17:41:25,950 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Hosts's actual
total CPU: 6382 and CPU after applying overprovisioning: 25528
2015-02-03 17:41:25,950 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Hosts's actual
total RAM: 3266390144 and RAM after applying overprovisioning: 3266390016
2015-02-03 17:41:25,950 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) release cpu from
host: 4, old used: 500,reserved: 0, actual total: 6382, total with
overprovisioning: 25528; new used: 0,reserved:0; movedfromreserved:
false,moveToReserveredfalse
2015-02-03 17:41:25,950 DEBUG [c.c.c.CapacityManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) release mem from
host: 4, old used: 134217728,reserved: 0, total: 3266390016; new used:
0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-02-03 17:41:25,956 ERROR [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Invocation
exception, caused by: com.cloud.utils.exception.CloudRuntimeException: Failed
to migrated vm VM[User|i-2-4-VM] along with its volumes.
2015-02-03 17:41:25,956 INFO [c.c.v.VmWorkJobHandlerProxy]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30 ctx-4ddcb611) Rethrow exception
com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm
VM[User|i-2-4-VM] along with its volumes.
2015-02-03 17:41:25,956 DEBUG [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Done with run of VM work job:
com.cloud.vm.VmWorkMigrate for VM 4, job origin: 29
2015-02-03 17:41:25,957 ERROR [c.c.v.VmWorkJobDispatcher]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Unable to complete AsyncJobVO
{id:30, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd:
com.cloud.vm.VmWorkMigrate, cmdInfo:
rO0ABXNyACVjb20uY2xvdWQudm0uVm1Xb3JrTWlncmF0ZVdpdGhTdG9yYWdlsew9z6UxtXMCAANKAApkZXN0SG9zdElkSgAJc3JjSG9zdElkTAAMdm9sdW1lVG9Qb29sdAAPTGphdmEvdXRpbC9NYXA7eHIAE2NvbS5jbG91ZC52bS5WbVdvcmufmbZW8CVnawIABEoACWFjY291bnRJZEoABnVzZXJJZEoABHZtSWRMAAtoYW5kbGVyTmFtZXQAEkxqYXZhL2xhbmcvU3RyaW5nO3hwAAAAAAAAAAIAAAAAAAAAAgAAAAAAAAAEdAAZVmlydHVhbE1hY2hpbmVNYW5hZ2VySW1wbAAAAAAAAAAEAAAAAAAAAAFzcgARamF2YS51dGlsLkhhc2hNYXAFB9rBwxZg0QMAAkYACmxvYWRGYWN0b3JJAAl0aHJlc2hvbGR4cD9AAAAAAAAQdwgAAAAQAAAAAHg,
cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
null, initMsid: 345043735628, completeMsid: null, lastUpdated: null,
lastPolled: null, created: Tue Feb 03 17:41:16 IST 2015}, job origin:29
com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm
VM[User|i-2-4-VM] along with its volumes.
at
org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:991)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2169)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4493)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4596)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:536)
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:493)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-03 17:41:25,968 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Complete async job-30,
jobStatus: FAILED, resultCode: 0, result:
rO0ABXNyAC9jb20uY2xvdWQudXRpbHMuZXhjZXB0aW9uLkNsb3VkUnVudGltZUV4Y2VwdGlvbgAAAABWTU9yAwABSQALY3NFcnJvckNvZGV4cgAaamF2YS5sYW5nLlJ1bnRpbWVFeGNlcHRpb26eXwZHCjSD5QIAAHhyABNqYXZhLmxhbmcuRXhjZXB0aW9u0P0fPho7HMQCAAB4cgATamF2YS5sYW5nLlRocm93YWJsZdXGNSc5d7jLAwAETAAFY2F1c2V0ABVMamF2YS9sYW5nL1Rocm93YWJsZTtMAA1kZXRhaWxNZXNzYWdldAASTGphdmEvbGFuZy9TdHJpbmc7WwAKc3RhY2tUcmFjZXQAHltMamF2YS9sYW5nL1N0YWNrVHJhY2VFbGVtZW50O0wAFHN1cHByZXNzZWRFeGNlcHRpb25zdAAQTGphdmEvdXRpbC9MaXN0O3hwcQB-AAh0AEBGYWlsZWQgdG8gbWlncmF0ZWQgdm0gVk1bVXNlcnxpLTItNC1WTV0gYWxvbmcgd2l0aCBpdHMgdm9sdW1lcy4gdXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAWc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AAVMAAhmaWxlTmFtZXEAfgAFTAAKbWV0aG9kTmFtZXEAfgAFeHAAAAPfdAA9b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmVuZ2luZS5vcmNoZXN0cmF0aW9uLlZvbHVtZU9yY2hlc3RyYXRvcnQAF1ZvbHVtZU9yY2hlc3RyYXRvci5qYXZhdAAObWlncmF0ZVZvbHVtZXNzcQB-AAwAAAh5dAAmY29tLmNsb3VkLnZtLlZpcnR1YWxNYWNoaW5lTWFuYWdlckltcGx0AB5WaXJ0dWFsTWFjaGluZU1hbmFnZXJJbXBsLmphdmF0AB1vcmNoZXN0cmF0ZU1pZ3JhdGVXaXRoU3RvcmFnZXNxAH4ADAAAEY1xAH4AEnEAfgATcQB-ABRzcQB-AAz____-dAAkc3VuLnJlZmxlY3QuTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsdAAdTmF0aXZlTWV0aG9kQWNjZXNzb3JJbXBsLmphdmF0AAdpbnZva2Uwc3EAfgAMAAAAOXEAfgAXcQB-ABh0AAZpbnZva2VzcQB-AAwAAAArdAAoc3VuLnJlZmxlY3QuRGVsZWdhdGluZ01ldGhvZEFjY2Vzc29ySW1wbHQAIURlbGVnYXRpbmdNZXRob2RBY2Nlc3NvckltcGwuamF2YXEAfgAbc3EAfgAMAAACXnQAGGphdmEubGFuZy5yZWZsZWN0Lk1ldGhvZHQAC01ldGhvZC5qYXZhcQB-ABtzcQB-AAwAAABrdAAiY29tLmNsb3VkLnZtLlZtV29ya0pvYkhhbmRsZXJQcm94eXQAGlZtV29ya0pvYkhhbmRsZXJQcm94eS5qYXZhdAAPaGFuZGxlVm1Xb3JrSm9ic3EAfgAMAAAR9HEAfgAScQB-ABNxAH4AJXNxAH4ADAAAAGZ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ADAAAAhh0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-AAwAAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-AAwAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgAMAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4ANXQAD2NhbGxXaXRoQ29udGV4dHNxAH4ADAAAADVxAH4AOHEAfgA1dAAOcnVuV2l0aENvbnRleHRzcQB-AAwAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ADFxAH4AMnNxAH4ADAAAAe1xAH4ALHEAfgAtcQB-ADJzcQB-AAwAAAHXdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ADZzcQB-AAwAAAEGdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgAyc3EAfgAMAAAEeXQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgAMAAACZ3QALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4AR3EAfgAyc3EAfgAMAAAC6XQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAyc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAd4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AU3gAABCadwgAAAAAAAAAAHg
2015-02-03 17:41:25,970 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Publish async job-30 complete
on message bus
2015-02-03 17:41:25,970 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Wake up jobs related to job-30
2015-02-03 17:41:25,970 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Update db status for job-30
2015-02-03 17:41:25,972 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Wake up jobs joined with
job-30 and disjoin all subjobs created from job- 30
2015-02-03 17:41:25,998 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Done executing
com.cloud.vm.VmWorkMigrate for job-30
2015-02-03 17:41:25,999 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Sync queue (4) is currently
empty
2015-02-03 17:41:26,000 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(Work-Job-Executor-5:ctx-bf4fe907 job-29/job-30) Remove job-30 from job
monitoring
2015-02-03 17:41:26,009 ERROR [c.c.a.ApiAsyncJobDispatcher]
(API-Job-Executor-17:ctx-d145a559 job-29) Unexpected exception while executing
org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd
com.cloud.utils.exception.CloudRuntimeException: Failed to migrated vm
VM[User|i-2-4-VM] along with its volumes.
at
org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.migrateVolumes(VolumeOrchestrator.java:991)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:2169)
at
com.cloud.vm.VirtualMachineManagerImpl.orchestrateMigrateWithStorage(VirtualMachineManagerImpl.java:4493)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at
com.cloud.vm.VirtualMachineManagerImpl.handleVmWorkJob(VirtualMachineManagerImpl.java:4596)
at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
at
org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:536)
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:493)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-02-03 17:41:26,011 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-17:ctx-d145a559 job-29) Complete async job-29, jobStatus:
FAILED, resultCode: 530, result:
org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed
to migrated vm VM[User|i-2-4-VM] along with its volumes. "}
2015-02-03 17:41:26,012 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-17:ctx-d145a559 job-29) Publish async job-29 complete on
message bus
2015-02-03 17:41:26,012 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-17:ctx-d145a559 job-29) Wake up jobs related to job-29
2015-02-03 17:41:26,012 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-17:ctx-d145a559 job-29) Update db status for job-29
2015-02-03 17:41:26,013 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-17:ctx-d145a559 job-29) Wake up jobs joined with job-29 and
disjoin all subjobs created from job- 29
2015-02-03 17:41:26,017 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
(API-Job-Executor-17:ctx-d145a559 job-29) Done executing
org.apache.cloudstack.api.command.admin.vm.MigrateVirtualMachineWithVolumeCmd
for job-29
2015-02-03 17:41:26,017 INFO [o.a.c.f.j.i.AsyncJobMonitor]
(API-Job-Executor-17:ctx-d145a559 job-29) Remove job-29 from job monitoring
2015-02-03 17:41:28,888 DEBUG [c.c.a.ApiServlet]
(1369188023@qtp-2043850624-13:ctx-55cb7646) ===START=== 192.168.100.30 -- GET
command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945687242
2015-02-03 17:41:28,906 DEBUG [c.c.a.ApiServlet]
(1369188023@qtp-2043850624-13:ctx-55cb7646 ctx-eeffe1a8) ===END===
192.168.100.30 -- GET
command=queryAsyncJobResult&jobId=e5f2660a-4c59-46f5-99ad-240e833354f9&response=json&sessionkey=siNTLV8YaFC1WTwW5bGuCzZIKE8%3D&_=1422945687242
2015-02-03 17:41:31,091 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-3:null) SeqA 2-249: Processing Seq 2-249: { Cmd ,
MgmtId: -1, via: 2, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2015-02-03 17:41:31,096 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-3:null) SeqA 2-249: Sending Seq 2-249: { Ans: , MgmtId:
345043735628, via: 2, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-02-03 17:41:31,691 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-c2a39692) Begin cleanup expired async-jobs
2015-02-03 17:41:31,694 INFO [o.a.c.f.j.i.AsyncJobManagerImpl]
(AsyncJobMgr-Heartbeat-1:ctx-c2a39692) End cleanup expired async-jobs
2015-02-03 17:41:31,721 INFO [c.c.n.v.VpcManagerImpl]
(VpcChecker-1:ctx-21a431b7) Found 0 removed VPCs to cleanup
2015-02-03 17:41:31,759 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-ce1bdd15) Found 1 routers to update status.
2015-02-03 17:41:31,759 DEBUG [c.c.n.r.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:ctx-ce1bdd15) Found 0 networks to update RvR status.
2015-02-03 17:41:31,864 INFO [c.c.u.AccountManagerImpl]
(AccountChecker-1:ctx-387c4fa4) Found 0 removed accounts to cleanup
2015-02-03 17:41:31,865 INFO [c.c.u.AccountManagerImpl]
(AccountChecker-1:ctx-387c4fa4) Found 0 disabled accounts to cleanup
2015-02-03 17:41:31,865 INFO [c.c.u.AccountManagerImpl]
(AccountChecker-1:ctx-387c4fa4) Found 0 inactive domains to cleanup
2015-02-03 17:41:31,866 INFO [c.c.u.AccountManagerImpl]
(AccountChecker-1:ctx-387c4fa4) Found 0 disabled projects to cleanup
2015-02-03 17:41:36,092 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-4:null) SeqA 2-250: Processing Seq 2-250: { Cmd ,
MgmtId: -1, via: 2, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2015-02-03 17:41:36,094 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-4:null) SeqA 2-250: Sending Seq 2-250: { Ans: , MgmtId:
345043735628, via: 2, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2015-02-03 17:41:37,331 DEBUG [c.c.a.m.DirectAgentAttache]
(DirectAgentCronJob-12:ctx-c0c8a6a8) Ping from 1(xen651)
2015-02-03 17:41:37,332 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(DirectAgentCronJob-12:ctx-c0c8a6a8) Process host VM state report from ping
process. host: 1
2015-02-03 17:41:37,335 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(DirectAgentCronJob-12:ctx-c0c8a6a8) Process VM state report. host: 1, number
of records in report: 4
2015-02-03 17:41:37,335 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(DirectAgentCronJob-12:ctx-c0c8a6a8) VM state report. host: 1, vm id: 1, power
state: PowerOn
2015-02-03 17:41:37,335 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(DirectAgentCronJob-12:ctx-c0c8a6a8) VM power state does not change, skip DB
writing. vm id: 1
2015-02-03 17:41:37,335 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(DirectAgentCronJob-12:ctx-c0c8a6a8) VM state report. host: 1, vm id: 2, power
state: PowerOn
2015-02-03 17:41:37,336 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(DirectAgentCronJob-12:ctx-c0c8a6a8) VM power state does not change, skip DB
writing. vm id: 2
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
