Details
-
Bug
-
Status: Resolved
-
Major
-
Resolution: Fixed
-
4.4.0
-
Security Level: Public (Anyone can view this level - this is the default.)
-
None
-
Hyperv Setup with local storage, cluster wide primary storage and zone wide primary storage
Description
Steps :
========================
1. Deploy a hyperv Setup with multiple clusters having local storage, cluster wide primary storage and zone wide primary storage.
2. Deploy VMs with datadisk
v1 on local storage on host1, v2 on cwps and v3 on zwps, v4 on local storage on host2
3. Detach the data disk from v1 and attach to v2 or v3 or v4
Expected behavior :
=========================
Since the migration of a data disk on local storage to cpws , zwps or local storage on another host is not supported, we should error out the operation with appropriate error msg and should not throw any exception.
Observed behavior :
=========================
Expecptions are thrown during these operations :
MS logs when with conflicting Host and Cluster scope :
-------------------
2014-06-17 15:11:47,303 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-fb917520) ===START=== 10.144.6.9 – GET command=attachVolume&id=8fcefeed-9606-45a0-a482-48a52554ecd1&virtualMachineId=89612a65-8398-4a61-92b4-2431b9adbe52&response=json&sessionkey=usW3Wz8dQ4fHD24kCe9r5A27Tbc%3D&_=1402997805674
2014-06-17 15:11:47,348 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-18:ctx-fb917520 ctx-0622857b) submit async job-93, details: AsyncJobVO {id:93, userId: 2, accountId: 2, instanceType: Volume, instanceId: 23, cmd: org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin, cmdInfo: {"response":"json","id":"8fcefeed-9606-45a0-a482-48a52554ecd1","sessionkey":"usW3Wz8dQ4fHD24kCe9r5A27Tbc\u003d","ctxDetails":"
","cmdEventType":"VOLUME.ATTACH","ctxUserId":"2","virtualMachineId":"89612a65-8398-4a61-92b4-2431b9adbe52","httpmethod":"GET","_":"1402997805674","uuid":"8fcefeed-9606-45a0-a482-48a52554ecd1","ctxAccountId":"2","ctxStartEventId":"189"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 213737702773493, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-06-17 15:11:47,349 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-fb917520 ctx-0622857b) ===END=== 10.144.6.9 – GET command=attachVolume&id=8fcefeed-9606-45a0-a482-48a52554ecd1&virtualMachineId=89612a65-8398-4a61-92b4-2431b9adbe52&response=json&sessionkey=usW3Wz8dQ4fHD24kCe9r5A27Tbc%3D&_=1402997805674
2014-06-17 15:11:47,354 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-60:ctx-daa38c1b job-93) Add job-93 into job monitoring
2014-06-17 15:11:47,354 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-60:ctx-daa38c1b job-93) Executing AsyncJobVO {id:93, userId: 2, accountId: 2, instanceType: Volume, instanceId: 23, cmd: org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin, cmdInfo: {"response":"json","id":"8fcefeed-9606-45a0-a482-48a52554ecd1","sessionkey":"usW3Wz8dQ4fHD24kCe9r5A27Tbc\u003d","ctxDetails":"
","cmdEventType":"VOLUME.ATTACH","ctxUserId":"2","virtualMachineId":"89612a65-8398-4a61-92b4-2431b9adbe52","httpmethod":"GET","_":"1402997805674","uuid":"8fcefeed-9606-45a0-a482-48a52554ecd1","ctxAccountId":"2","ctxStartEventId":"189"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 213737702773493, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-06-17 15:11:47,372 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-60:ctx-daa38c1b job-93 ctx-9c523ebe) Sync job-94 execution on object VmWorkJobQueue.12
2014-06-17 15:11:47,375 DEBUG [c.c.s.VolumeApiServiceImpl] (API-Job-Executor-60:ctx-daa38c1b job-93 ctx-9c523ebe) New job 94, result field: null
2014-06-17 15:11:47,375 WARN [c.c.u.d.Merovingian2] (API-Job-Executor-60:ctx-daa38c1b job-93 ctx-9c523ebe) Was unable to find lock for the key vm_instance12 and thread id 1125522731
2014-06-17 15:11:47,967 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-f6e3f4a6) Execute sync-queue item: SyncQueueItemVO
2014-06-17 15:11:47,968 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-f6e3f4a6) Schedule queued job-94
2014-06-17 15:11:47,995 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-31:ctx-25770de9 job-93/job-94) Add job-94 into job monitoring
2014-06-17 15:11:47,995 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-31:ctx-25770de9 job-93/job-94) Executing AsyncJobVO
2014-06-17 15:11:47,995 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-31:ctx-25770de9 job-93/job-94) Run VM work job: com.cloud.storage.VmWorkAttachVolume for VM 12, job origin: 93
2014-06-17 15:11:47,997 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-31:ctx-25770de9 job-93/job-94 ctx-88f94614) Execute VM work job: com.cloud.storage.VmWorkAttachVolume
2014-06-17 15:11:48,021 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-31:ctx-25770de9 job-93/job-94 ctx-88f94614) Invocation exception, caused by: com.cloud.utils.exception.CloudRuntimeException: Can't move volume between scope: HOST and CLUSTER
2014-06-17 15:11:48,022 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-31:ctx-25770de9 job-93/job-94 ctx-88f94614) Rethrow exception com.cloud.utils.exception.CloudRuntimeException: Can't move volume between scope: HOST and CLUSTER
2014-06-17 15:11:48,022 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-31:ctx-25770de9 job-93/job-94) Done with run of VM work job: com.cloud.storage.VmWorkAttachVolume for VM 12, job origin: 93
2014-06-17 15:11:48,022 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-31:ctx-25770de9 job-93/job-94) Unable to complete AsyncJobVO
, job origin:93
com.cloud.utils.exception.CloudRuntimeException: Can't move volume between scope: HOST and CLUSTER
at com.cloud.storage.VolumeApiServiceImpl.needMoveVolume(VolumeApiServiceImpl.java:1989)
at com.cloud.storage.VolumeApiServiceImpl.attachVolumeToVM(VolumeApiServiceImpl.java:1196)
at com.cloud.storage.VolumeApiServiceImpl.orchestrateAttachVolumeToVM(VolumeApiServiceImpl.java:1055)
at com.cloud.storage.VolumeApiServiceImpl.orchestrateAttachVolumeToVM(VolumeApiServiceImpl.java:2480)
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:601)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.storage.VolumeApiServiceImpl.handleVmWorkJob(VolumeApiServiceImpl.java:2515)
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: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 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 $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:503)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$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)
2014-06-17 15:11:48,025 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-31:ctx-25770de9 job-93/job-94) Complete async job-94, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyABpqYXZhLmxhbmcuUnVudGltZUV4Y2VwdGlvbp5fBkcKNIPlAgAAeHIAE2phdmEubGFuZy5FeGNlcHRpb27Q_R8-GjscxAIAAHhyABNqYXZhLmxhbmcuVGhyb3dhYmxl1cY1Jzl3uMsDAARMAAVjYXVzZXQAFUxqYXZhL2xhbmcvVGhyb3dhYmxlO0wADWRldGFpbE1lc3NhZ2V0ABJMamF2YS9sYW5nL1N0cmluZztbAApzdGFja1RyYWNldAAeW0xqYXZhL2xhbmcvU3RhY2tUcmFjZUVsZW1lbnQ7TAAUc3VwcHJlc3NlZEV4Y2VwdGlvbnN0ABBMamF2YS91dGlsL0xpc3Q7eHBxAH4AB3QATUpvYiBmYWlsZWQgZHVlIHRvIGV4Y2VwdGlvbiBDYW4ndCBtb3ZlIHZvbHVtZSBiZXR3ZWVuIHNjb3BlOiBIT1NUIGFuZCBDTFVTVEVSdXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAOc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AARMAAhmaWxlTmFtZXEAfgAETAAKbWV0aG9kTmFtZXEAfgAEeHAAAABydAAgY29tLmNsb3VkLnZtLlZtV29ya0pvYkRpc3BhdGNoZXJ0ABhWbVdvcmtKb2JEaXNwYXRjaGVyLmphdmF0AAZydW5Kb2JzcQB-AAsAAAH3dAA_b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmZyYW1ld29yay5qb2JzLmltcGwuQXN5bmNKb2JNYW5hZ2VySW1wbCQ1dAAYQXN5bmNKb2JNYW5hZ2VySW1wbC5qYXZhdAAMcnVuSW5Db250ZXh0c3EAfgALAAAAMXQAPm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZSQxdAAbTWFuYWdlZENvbnRleHRSdW5uYWJsZS5qYXZhdAADcnVuc3EAfgALAAAAOHQAQm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHQkMXQAGkRlZmF1bHRNYW5hZ2VkQ29udGV4dC5qYXZhdAAEY2FsbHNxAH4ACwAAAGd0AEBvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0cQB-ABp0AA9jYWxsV2l0aENvbnRleHRzcQB-AAsAAAA1cQB-AB1xAH4AGnQADnJ1bldpdGhDb250ZXh0c3EAfgALAAAALnQAPG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZXEAfgAWcQB-ABdzcQB-AAsAAAHMcQB-ABFxAH4AEnEAfgAXc3EAfgALAAAB13QALmphdmEudXRpbC5jb25jdXJyZW50LkV4ZWN1dG9ycyRSdW5uYWJsZUFkYXB0ZXJ0AA5FeGVjdXRvcnMuamF2YXEAfgAbc3EAfgALAAABTnQAJGphdmEudXRpbC5jb25jdXJyZW50LkZ1dHVyZVRhc2skU3luY3QAD0Z1dHVyZVRhc2suamF2YXQACGlubmVyUnVuc3EAfgALAAAApnQAH2phdmEudXRpbC5jb25jdXJyZW50LkZ1dHVyZVRhc2txAH4AKXEAfgAXc3EAfgALAAAEVnQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgALAAACW3QALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4AL3EAfgAXc3EAfgALAAAC0nQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAXc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAZ4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AO3g
2014-06-17 15:11:48,034 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-31:ctx-25770de9 job-93/job-94) Done executing com.cloud.storage.VmWorkAttachVolume for job-94
2014-06-17 15:11:48,042 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-60:ctx-daa38c1b job-93) Unexpected exception while executing org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin
java.lang.RuntimeException: Unexpected exception
at com.cloud.storage.VolumeApiServiceImpl.attachVolumeToVM(VolumeApiServiceImpl.java:1045)
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: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 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 $Proxy182.attachVolumeToVM(Unknown Source)
at org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin.execute(AttachVolumeCmdByAdmin.java:38)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:141)
at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$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)
Caused by: java.lang.RuntimeException: Job failed due to exception Can't move volume between scope: HOST and CLUSTER
... 27 more
2014-06-17 15:11:48,050 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-60:ctx-daa38c1b job-93) Complete async job-93, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/
2014-06-17 15:11:48,065 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl] (Work-Job-Executor-31:ctx-25770de9 job-93/job-94) Sync queue (26) is currently empty
2014-06-17 15:11:48,066 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-31:ctx-25770de9 job-93/job-94) Remove job-94 from job monitoring
2014-06-17 15:11:48,072 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-60:ctx-daa38c1b job-93) Done executing org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin for job-93
2014-06-17 15:11:48,075 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-60:ctx-daa38c1b job-93) Remove job-93 from job monitoring
MS logs with conflicting Host and Zone scope :
----------------------
2014-06-17 15:10:41,946 DEBUG [c.c.a.ApiServlet] (catalina-exec-1:ctx-0d9c8530) ===START=== 10.144.6.9 – GET command=attachVolume&id=8fcefeed-9606-45a0-a482-48a52554ecd1&virtualMachineId=208efdec-7d2d-4227-8aaa-bb3dd7a008da&response=json&sessionkey=usW3Wz8dQ4fHD24kCe9r5A27Tbc%3D&_=1402997749078
2014-06-17 15:10:41,999 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-1:ctx-0d9c8530 ctx-ae5f4452) submit async job-91, details: AsyncJobVO {id:91, userId: 2, accountId: 2, instanceType: Volume, instanceId: 23, cmd: org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin, cmdInfo: {"response":"json","id":"8fcefeed-9606-45a0-a482-48a52554ecd1","sessionkey":"usW3Wz8dQ4fHD24kCe9r5A27Tbc\u003d","ctxDetails":"
","cmdEventType":"VOLUME.ATTACH","ctxUserId":"2","virtualMachineId":"208efdec-7d2d-4227-8aaa-bb3dd7a008da","httpmethod":"GET","_":"1402997749078","uuid":"8fcefeed-9606-45a0-a482-48a52554ecd1","ctxAccountId":"2","ctxStartEventId":"188"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 213737702773493, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-06-17 15:10:42,000 DEBUG [c.c.a.ApiServlet] (catalina-exec-1:ctx-0d9c8530 ctx-ae5f4452) ===END=== 10.144.6.9 – GET command=attachVolume&id=8fcefeed-9606-45a0-a482-48a52554ecd1&virtualMachineId=208efdec-7d2d-4227-8aaa-bb3dd7a008da&response=json&sessionkey=usW3Wz8dQ4fHD24kCe9r5A27Tbc%3D&_=1402997749078
2014-06-17 15:10:42,004 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-59:ctx-57829c30 job-91) Add job-91 into job monitoring
2014-06-17 15:10:42,005 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-59:ctx-57829c30 job-91) Executing AsyncJobVO {id:91, userId: 2, accountId: 2, instanceType: Volume, instanceId: 23, cmd: org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin, cmdInfo: {"response":"json","id":"8fcefeed-9606-45a0-a482-48a52554ecd1","sessionkey":"usW3Wz8dQ4fHD24kCe9r5A27Tbc\u003d","ctxDetails":"
","cmdEventType":"VOLUME.ATTACH","ctxUserId":"2","virtualMachineId":"208efdec-7d2d-4227-8aaa-bb3dd7a008da","httpmethod":"GET","_":"1402997749078","uuid":"8fcefeed-9606-45a0-a482-48a52554ecd1","ctxAccountId":"2","ctxStartEventId":"188"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 213737702773493, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-06-17 15:10:42,022 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-59:ctx-57829c30 job-91 ctx-e401bea2) Sync job-92 execution on object VmWorkJobQueue.10
2014-06-17 15:10:42,025 DEBUG [c.c.s.VolumeApiServiceImpl] (API-Job-Executor-59:ctx-57829c30 job-91 ctx-e401bea2) New job 92, result field: null
2014-06-17 15:10:42,025 WARN [c.c.u.d.Merovingian2] (API-Job-Executor-59:ctx-57829c30 job-91 ctx-e401bea2) Was unable to find lock for the key vm_instance10 and thread id 662244293
2014-06-17 15:10:43,881 DEBUG [c.c.s.StatsCollector] (StatsCollector-1:ctx-06c142d3) VmStatsCollector is running...
2014-06-17 15:10:43,895 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-72:ctx-3dabca4b) Seq 1-1221038448970832679: Executing request
2014-06-17 15:10:43,895 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-72:ctx-3dabca4b) POST request to https://10.102.244.20:8250/api/HypervResource/com.cloud.agent.api.GetVmStatsCommand with contents {"vmNames":["i-2-10-VM","i-2-12-VM"],"hostGuid":"c5034950-d1a2-3368-8c8f-77a2cb0d49d2-HypervResource","hostName":"10.102.244.20","contextMap":{},"wait":0}
2014-06-17 15:10:43,899 DEBUG [c.c.h.h.r.HypervDirectConnectResource] (DirectAgent-72:ctx-3dabca4b) Sending cmd to https://10.102.244.20:8250/api/HypervResource/com.cloud.agent.api.GetVmStatsCommand cmd data:{"vmNames":["i-2-10-VM","i-2-12-VM"],"hostGuid":"c5034950-d1a2-3368-8c8f-77a2cb0d49d2-HypervResource","hostName":"10.102.244.20","contextMap":{},"wait":0}
2014-06-17 15:10:43,966 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-adc9b9aa) Execute sync-queue item: SyncQueueItemVO
2014-06-17 15:10:43,968 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-adc9b9aa) Schedule queued job-92
2014-06-17 15:10:43,977 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-30:ctx-afb51cf2 job-91/job-92) Add job-92 into job monitoring
2014-06-17 15:10:43,978 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-30:ctx-afb51cf2 job-91/job-92) Executing AsyncJobVO
2014-06-17 15:10:43,978 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-30:ctx-afb51cf2 job-91/job-92) Run VM work job: com.cloud.storage.VmWorkAttachVolume for VM 10, job origin: 91
2014-06-17 15:10:43,980 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-30:ctx-afb51cf2 job-91/job-92 ctx-08d74b6b) Execute VM work job: com.cloud.storage.VmWorkAttachVolume
2014-06-17 15:10:44,004 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-30:ctx-afb51cf2 job-91/job-92 ctx-08d74b6b) Invocation exception, caused by: com.cloud.utils.exception.CloudRuntimeException: Can't move volume between scope: HOST and ZONE
2014-06-17 15:10:44,005 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-30:ctx-afb51cf2 job-91/job-92 ctx-08d74b6b) Rethrow exception com.cloud.utils.exception.CloudRuntimeException: Can't move volume between scope: HOST and ZONE
2014-06-17 15:10:44,005 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-30:ctx-afb51cf2 job-91/job-92) Done with run of VM work job: com.cloud.storage.VmWorkAttachVolume for VM 10, job origin: 91
2014-06-17 15:10:44,005 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-30:ctx-afb51cf2 job-91/job-92) Unable to complete AsyncJobVO
, job origin:91
com.cloud.utils.exception.CloudRuntimeException: Can't move volume between scope: HOST and ZONE
at com.cloud.storage.VolumeApiServiceImpl.needMoveVolume(VolumeApiServiceImpl.java:1989)
at com.cloud.storage.VolumeApiServiceImpl.attachVolumeToVM(VolumeApiServiceImpl.java:1196)
at com.cloud.storage.VolumeApiServiceImpl.orchestrateAttachVolumeToVM(VolumeApiServiceImpl.java:1055)
at com.cloud.storage.VolumeApiServiceImpl.orchestrateAttachVolumeToVM(VolumeApiServiceImpl.java:2480)
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:601)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.storage.VolumeApiServiceImpl.handleVmWorkJob(VolumeApiServiceImpl.java:2515)
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: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 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 $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:503)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$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)
2014-06-17 15:10:44,025 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-30:ctx-afb51cf2 job-91/job-92) Complete async job-92, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyABpqYXZhLmxhbmcuUnVudGltZUV4Y2VwdGlvbp5fBkcKNIPlAgAAeHIAE2phdmEubGFuZy5FeGNlcHRpb27Q_R8-GjscxAIAAHhyABNqYXZhLmxhbmcuVGhyb3dhYmxl1cY1Jzl3uMsDAARMAAVjYXVzZXQAFUxqYXZhL2xhbmcvVGhyb3dhYmxlO0wADWRldGFpbE1lc3NhZ2V0ABJMamF2YS9sYW5nL1N0cmluZztbAApzdGFja1RyYWNldAAeW0xqYXZhL2xhbmcvU3RhY2tUcmFjZUVsZW1lbnQ7TAAUc3VwcHJlc3NlZEV4Y2VwdGlvbnN0ABBMamF2YS91dGlsL0xpc3Q7eHBxAH4AB3QASkpvYiBmYWlsZWQgZHVlIHRvIGV4Y2VwdGlvbiBDYW4ndCBtb3ZlIHZvbHVtZSBiZXR3ZWVuIHNjb3BlOiBIT1NUIGFuZCBaT05FdXIAHltMamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50OwJGKjw8_SI5AgAAeHAAAAAOc3IAG2phdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudGEJxZomNt2FAgAESQAKbGluZU51bWJlckwADmRlY2xhcmluZ0NsYXNzcQB-AARMAAhmaWxlTmFtZXEAfgAETAAKbWV0aG9kTmFtZXEAfgAEeHAAAABydAAgY29tLmNsb3VkLnZtLlZtV29ya0pvYkRpc3BhdGNoZXJ0ABhWbVdvcmtKb2JEaXNwYXRjaGVyLmphdmF0AAZydW5Kb2JzcQB-AAsAAAH3dAA_b3JnLmFwYWNoZS5jbG91ZHN0YWNrLmZyYW1ld29yay5qb2JzLmltcGwuQXN5bmNKb2JNYW5hZ2VySW1wbCQ1dAAYQXN5bmNKb2JNYW5hZ2VySW1wbC5qYXZhdAAMcnVuSW5Db250ZXh0c3EAfgALAAAAMXQAPm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZSQxdAAbTWFuYWdlZENvbnRleHRSdW5uYWJsZS5qYXZhdAADcnVuc3EAfgALAAAAOHQAQm9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHQkMXQAGkRlZmF1bHRNYW5hZ2VkQ29udGV4dC5qYXZhdAAEY2FsbHNxAH4ACwAAAGd0AEBvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0cQB-ABp0AA9jYWxsV2l0aENvbnRleHRzcQB-AAsAAAA1cQB-AB1xAH4AGnQADnJ1bldpdGhDb250ZXh0c3EAfgALAAAALnQAPG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuTWFuYWdlZENvbnRleHRSdW5uYWJsZXEAfgAWcQB-ABdzcQB-AAsAAAHMcQB-ABFxAH4AEnEAfgAXc3EAfgALAAAB13QALmphdmEudXRpbC5jb25jdXJyZW50LkV4ZWN1dG9ycyRSdW5uYWJsZUFkYXB0ZXJ0AA5FeGVjdXRvcnMuamF2YXEAfgAbc3EAfgALAAABTnQAJGphdmEudXRpbC5jb25jdXJyZW50LkZ1dHVyZVRhc2skU3luY3QAD0Z1dHVyZVRhc2suamF2YXQACGlubmVyUnVuc3EAfgALAAAApnQAH2phdmEudXRpbC5jb25jdXJyZW50LkZ1dHVyZVRhc2txAH4AKXEAfgAXc3EAfgALAAAEVnQAJ2phdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgALAAACW3QALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4AL3EAfgAXc3EAfgALAAAC0nQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAXc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAZ4cgAsamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXhwAAAAAHcEAAAAAHhxAH4AO3g
2014-06-17 15:10:44,034 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-30:ctx-afb51cf2 job-91/job-92) Done executing com.cloud.storage.VmWorkAttachVolume for job-92
2014-06-17 15:10:44,059 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-59:ctx-57829c30 job-91) Unexpected exception while executing org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin
java.lang.RuntimeException: Unexpected exception
at com.cloud.storage.VolumeApiServiceImpl.attachVolumeToVM(VolumeApiServiceImpl.java:1045)
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: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 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 $Proxy182.attachVolumeToVM(Unknown Source)
at org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin.execute(AttachVolumeCmdByAdmin.java:38)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:141)
at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$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)
Caused by: java.lang.RuntimeException: Job failed due to exception Can't move volume between scope: HOST and ZONE
... 27 more
2014-06-17 15:10:44,063 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-59:ctx-57829c30 job-91) Complete async job-91, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/
2014-06-17 15:10:44,075 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl] (Work-Job-Executor-30:ctx-afb51cf2 job-91/job-92) Sync queue (21) is currently empty
2014-06-17 15:10:44,076 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-30:ctx-afb51cf2 job-91/job-92) Remove job-92 from job monitoring
2014-06-17 15:10:44,077 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-59:ctx-57829c30 job-91) Done executing org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin for job-91
MS logs with conflicting Host and Host scope :
-------------------
2014-06-17 16:01:00,265 DEBUG [c.c.a.ApiServlet] (catalina-exec-1:ctx-5b9b3f00) ===START=== 10.144.6.9 – GET command=attachVolume&id=0a540ecf-e74e-460d-b4ee-6daf9b386bda&virtualMachineId=00404e30-fcd6-42c8-9123-9d28b50af54f&response=json&sessionkey=usW3Wz8dQ4fHD24kCe9r5A27Tbc%3D&_=1403000546126
2014-06-17 16:01:00,298 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-1:ctx-5b9b3f00 ctx-9cbe450b) submit async job-154, details: AsyncJobVO {id:154, userId: 2, accountId: 2, instanceType: Volume, instanceId: 31, cmd: org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin, cmdInfo: {"response":"json","id":"0a540ecf-e74e-460d-b4ee-6daf9b386bda","sessionkey":"usW3Wz8dQ4fHD24kCe9r5A27Tbc\u003d","ctxDetails":"
","cmdEventType":"VOLUME.ATTACH","ctxUserId":"2","virtualMachineId":"00404e30-fcd6-42c8-9123-9d28b50af54f","httpmethod":"GET","_":"1403000546126","uuid":"0a540ecf-e74e-460d-b4ee-6daf9b386bda","ctxAccountId":"2","ctxStartEventId":"254"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 213737702773493, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-06-17 16:01:00,299 DEBUG [c.c.a.ApiServlet] (catalina-exec-1:ctx-5b9b3f00 ctx-9cbe450b) ===END=== 10.144.6.9 – GET command=attachVolume&id=0a540ecf-e74e-460d-b4ee-6daf9b386bda&virtualMachineId=00404e30-fcd6-42c8-9123-9d28b50af54f&response=json&sessionkey=usW3Wz8dQ4fHD24kCe9r5A27Tbc%3D&_=1403000546126
2014-06-17 16:01:00,304 INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-91:ctx-45781625 job-154) Add job-154 into job monitoring
2014-06-17 16:01:00,304 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-91:ctx-45781625 job-154) Executing AsyncJobVO {id:154, userId: 2, accountId: 2, instanceType: Volume, instanceId: 31, cmd: org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin, cmdInfo: {"response":"json","id":"0a540ecf-e74e-460d-b4ee-6daf9b386bda","sessionkey":"usW3Wz8dQ4fHD24kCe9r5A27Tbc\u003d","ctxDetails":"
","cmdEventType":"VOLUME.ATTACH","ctxUserId":"2","virtualMachineId":"00404e30-fcd6-42c8-9123-9d28b50af54f","httpmethod":"GET","_":"1403000546126","uuid":"0a540ecf-e74e-460d-b4ee-6daf9b386bda","ctxAccountId":"2","ctxStartEventId":"254"}, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 213737702773493, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2014-06-17 16:01:00,322 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-91:ctx-45781625 job-154 ctx-a512d611) Sync job-155 execution on object VmWorkJobQueue.14
2014-06-17 16:01:00,324 DEBUG [c.c.s.VolumeApiServiceImpl] (API-Job-Executor-91:ctx-45781625 job-154 ctx-a512d611) New job 155, result field: null
2014-06-17 16:01:00,325 WARN [c.c.u.d.Merovingian2] (API-Job-Executor-91:ctx-45781625 job-154 ctx-a512d611) Was unable to find lock for the key vm_instance14 and thread id 810345278
2014-06-17 16:01:01,967 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-3f4e9b09) Execute sync-queue item: SyncQueueItemVO
2014-06-17 16:01:01,968 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-3f4e9b09) Schedule queued job-155
2014-06-17 16:01:01,986 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-61:ctx-b4c6f6d0 job-154/job-155) Add job-155 into job monitoring
2014-06-17 16:01:01,987 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-61:ctx-b4c6f6d0 job-154/job-155) Executing AsyncJobVO
2014-06-17 16:01:01,987 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-61:ctx-b4c6f6d0 job-154/job-155) Run VM work job: com.cloud.storage.VmWorkAttachVolume for VM 14, job origin: 154
2014-06-17 16:01:01,989 DEBUG [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-61:ctx-b4c6f6d0 job-154/job-155 ctx-cb1d3774) Execute VM work job: com.cloud.storage.VmWorkAttachVolume
2014-06-17 16:01:02,021 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-61:ctx-b4c6f6d0 job-154/job-155 ctx-cb1d3774) Invocation exception, caused by: com.cloud.utils.exception.CloudRuntimeException: Failed to attach local data volume data2 to VM local2 as migration of local data volume is not allowed
2014-06-17 16:01:02,022 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-61:ctx-b4c6f6d0 job-154/job-155 ctx-cb1d3774) Rethrow exception com.cloud.utils.exception.CloudRuntimeException: Failed to attach local data volume data2 to VM local2 as migration of local data volume is not allowed
2014-06-17 16:01:02,022 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-61:ctx-b4c6f6d0 job-154/job-155) Done with run of VM work job: com.cloud.storage.VmWorkAttachVolume for VM 14, job origin: 154
2014-06-17 16:01:02,022 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-61:ctx-b4c6f6d0 job-154/job-155) Unable to complete AsyncJobVO
, job origin:154
com.cloud.utils.exception.CloudRuntimeException: Failed to attach local data volume data2 to VM local2 as migration of local data volume is not allowed
at com.cloud.storage.VolumeApiServiceImpl.attachVolumeToVM(VolumeApiServiceImpl.java:1201)
at com.cloud.storage.VolumeApiServiceImpl.orchestrateAttachVolumeToVM(VolumeApiServiceImpl.java:1055)
at com.cloud.storage.VolumeApiServiceImpl.orchestrateAttachVolumeToVM(VolumeApiServiceImpl.java:2480)
at sun.reflect.GeneratedMethodAccessor430.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at com.cloud.vm.VmWorkJobHandlerProxy.handleVmWorkJob(VmWorkJobHandlerProxy.java:107)
at com.cloud.storage.VolumeApiServiceImpl.handleVmWorkJob(VolumeApiServiceImpl.java:2515)
at sun.reflect.GeneratedMethodAccessor423.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 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 $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:503)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$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)
2014-06-17 16:01:02,025 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-61:ctx-b4c6f6d0 job-154/job-155) Complete async job-155, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyABpqYXZhLmxhbmcuUnVudGltZUV4Y2VwdGlvbp5fBkcKNIPlAgAAeHIAE2phdmEubGFuZy5FeGNlcHRpb27Q_R8-GjscxAIAAHhyABNqYXZhLmxhbmcuVGhyb3dhYmxl1cY1Jzl3uMsDAARMAAVjYXVzZXQAFUxqYXZhL2xhbmcvVGhyb3dhYmxlO0wADWRldGFpbE1lc3NhZ2V0ABJMamF2YS9sYW5nL1N0cmluZztbAApzdGFja1RyYWNldAAeW0xqYXZhL2xhbmcvU3RhY2tUcmFjZUVsZW1lbnQ7TAAUc3VwcHJlc3NlZEV4Y2VwdGlvbnN0ABBMamF2YS91dGlsL0xpc3Q7eHBxAH4AB3QAgkpvYiBmYWlsZWQgZHVlIHRvIGV4Y2VwdGlvbiBGYWlsZWQgdG8gYXR0YWNoIGxvY2FsIGRhdGEgdm9sdW1lIGRhdGEyIHRvIFZNIGxvY2FsMiBhcyBtaWdyYXRpb24gb2YgbG9jYWwgZGF0YSB2b2x1bWUgaXMgbm90IGFsbG93ZWR1cgAeW0xqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnQ7AkYqPDz9IjkCAAB4cAAAAA5zcgAbamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50YQnFmiY23YUCAARJAApsaW5lTnVtYmVyTAAOZGVjbGFyaW5nQ2xhc3NxAH4ABEwACGZpbGVOYW1lcQB-AARMAAptZXRob2ROYW1lcQB-AAR4cAAAAHJ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ACwAAAfd0AD9vcmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-AAsAAAAxdAA-b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-AAsAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgALAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvbnRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4AGnQAD2NhbGxXaXRoQ29udGV4dHNxAH4ACwAAADVxAH4AHXEAfgAadAAOcnVuV2l0aENvbnRleHRzcQB-AAsAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ABZxAH4AF3NxAH4ACwAAAcxxAH4AEXEAfgAScQB-ABdzcQB-AAsAAAHXdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmxlQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ABtzcQB-AAsAAAFOdAAkamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFzayRTeW5jdAAPRnV0dXJlVGFzay5qYXZhdAAIaW5uZXJSdW5zcQB-AAsAAACmdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3EAfgApcQB-ABdzcQB-AAsAAARWdAAnamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9ydAAXVGhyZWFkUG9vbEV4ZWN1dG9yLmphdmF0AAlydW5Xb3JrZXJzcQB-AAsAAAJbdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuVGhyZWFkUG9vbEV4ZWN1dG9yJFdvcmtlcnEAfgAvcQB-ABdzcQB-AAsAAALSdAAQamF2YS5sYW5nLlRocmVhZHQAC1RocmVhZC5qYXZhcQB-ABdzcgAmamF2YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUxpc3T8DyUxteyOEAIAAUwABGxpc3RxAH4ABnhyACxqYXZhLnV0aWwuQ29sbGVjdGlvbnMkVW5tb2RpZmlhYmxlQ29sbGVjdGlvbhlCAIDLXvceAgABTAABY3QAFkxqYXZhL3V0aWwvQ29sbGVjdGlvbjt4cHNyABNqYXZhLnV0aWwuQXJyYXlMaXN0eIHSHZnHYZ0DAAFJAARzaXpleHAAAAAAdwQAAAAAeHEAfgA7eA
2014-06-17 16:01:02,035 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-61:ctx-b4c6f6d0 job-154/job-155) Done executing com.cloud.storage.VmWorkAttachVolume for job-155
2014-06-17 16:01:02,040 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-91:ctx-45781625 job-154) Unexpected exception while executing org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin
java.lang.RuntimeException: Unexpected exception
at com.cloud.storage.VolumeApiServiceImpl.attachVolumeToVM(VolumeApiServiceImpl.java:1045)
at sun.reflect.GeneratedMethodAccessor429.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 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 $Proxy182.attachVolumeToVM(Unknown Source)
at org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin.execute(AttachVolumeCmdByAdmin.java:38)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:141)
at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:503)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:460)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$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)
Caused by: java.lang.RuntimeException: Job failed due to exception Failed to attach local data volume data2 to VM local2 as migration of local data volume is not allowed
... 26 more
2014-06-17 16:01:02,074 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-91:ctx-45781625 job-154) Complete async job-154, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/
2014-06-17 16:01:02,079 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl] (Work-Job-Executor-61:ctx-b4c6f6d0 job-154/job-155) Sync queue (32) is currently empty
2014-06-17 16:01:02,083 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-61:ctx-b4c6f6d0 job-154/job-155) Remove job-155 from job monitoring
2014-06-17 16:01:02,088 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-91:ctx-45781625 job-154) Done executing org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin for job-154