You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Koushik Das (JIRA)" <ji...@apache.org> on 2014/07/25 13:33:38 UTC
[jira] [Commented] (CLOUDSTACK-7132) [Automation] Failed to detach
Volume from the VM due to RuntimeException: Unexpected exception
[ https://issues.apache.org/jira/browse/CLOUDSTACK-7132?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14074304#comment-14074304 ]
Koushik Das commented on CLOUDSTACK-7132:
-----------------------------------------
Not able to repro this issue. Also the attached logs are not sufficient as the error is coming from XS. Please attach the XS logs along with MS logs if the issue is seen again.
> [Automation] Failed to detach Volume from the VM due to RuntimeException: Unexpected exception
> ----------------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-7132
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-7132
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: Storage Controller, Volumes, XenServer
> Affects Versions: 4.5.0
> Reporter: Chandan Purushothama
> Assignee: Koushik Das
> Priority: Critical
> Fix For: 4.5.0
>
> Attachments: management-server(1).zip
>
>
> ==============================================
> Unexpected Exception while detaching Volume from the VM:
> ==============================================
> 2014-07-11 17:28:06,154 WARN [c.c.h.x.r.XenServerStorageProcessor] (DirectAgent-143:ctx-bc033f6e) Failed dettach volume: 80f0f1cd-a1e7-4dec-b706-cebc3a1c6b5f
> 2014-07-11 17:28:06,154 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-143:ctx-bc033f6e) Seq 1-3992722544640656559: Response Received:
> 2014-07-11 17:28:06,154 DEBUG [c.c.a.t.Request] (DirectAgent-143:ctx-bc033f6e) Seq 1-3992722544640656559: Processing: { Ans: , MgmtId: 161135757057464, via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.DettachAnswer":{"result":false,"details":"Failed dettach volume: 80f0f1cd-a1e7-4dec-b706-cebc3a1c6b5f, due to The server failed to handle your request, due to an internal error. The given message may give details useful for debugging the problem.","wait":0}}] }
> 2014-07-11 17:28:06,154 DEBUG [c.c.a.t.Request] (Work-Job-Executor-45:ctx-0bbb5e9c job-1154/job-1155 ctx-41f3befc) Seq 1-3992722544640656559: Received: { Ans: , MgmtId: 161135757057464, via: 1, Ver: v1, Flags: 10, { DettachAnswer } }
> 2014-07-11 17:28:06,154 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-45:ctx-0bbb5e9c job-1154/job-1155 ctx-41f3befc) Invocation exception, caused by: com.cloud.utils.exception.CloudRuntimeException: Failed to detach volume DATA-118 from VM VM-6ab214a7-7df9-4317-9564-4da0f5a58a86; Failed dettach volume: 80f0f1cd-a1e7-4dec-b706-cebc3a1c6b5f, due to The server failed to handle your request, due to an internal error. The given message may give details useful for debugging the problem.
> 2014-07-11 17:28:06,155 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-45:ctx-0bbb5e9c job-1154/job-1155 ctx-41f3befc) Rethrow exception com.cloud.utils.exception.CloudRuntimeException: Failed to detach volume DATA-118 from VM VM-6ab214a7-7df9-4317-9564-4da0f5a58a86; Failed dettach volume: 80f0f1cd-a1e7-4dec-b706-cebc3a1c6b5f, due to The server failed to handle your request, due to an internal error. The given message may give details useful for debugging the problem.
> 2014-07-11 17:28:06,155 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-45:ctx-0bbb5e9c job-1154/job-1155) Done with run of VM work job: com.cloud.storage.VmWorkDetachVolume for VM 118, job origin: 1154
> 2014-07-11 17:28:06,155 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-45:ctx-0bbb5e9c job-1154/job-1155) Unable to complete AsyncJobVO {id:1155, userId: 2, accountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.storage.VmWorkDetachVolume, cmdInfo: rO0ABXNyACRjb20uY2xvdWQuc3RvcmFnZS5WbVdvcmtEZXRhY2hWb2x1bWWG9F4D6zzUAwIAAUwACHZvbHVtZUlkdAAQTGphdmEvbGFuZy9Mb25nO3hyABNjb20uY2xvdWQudm0uVm1Xb3Jrn5m2VvAlZ2sCAARKAAlhY2NvdW50SWRKAAZ1c2VySWRKAAR2bUlkTAALaGFuZGxlck5hbWV0ABJMamF2YS9sYW5nL1N0cmluZzt4cAAAAAAAAAACAAAAAAAAAAIAAAAAAAAAdnQAFFZvbHVtZUFwaVNlcnZpY2VJbXBsc3IADmphdmEubGFuZy5Mb25nO4vkkMyPI98CAAFKAAV2YWx1ZXhyABBqYXZhLmxhbmcuTnVtYmVyhqyVHQuU4IsCAAB4cAAAAAAAAACW, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 161135757057464, completeMsid: null, lastUpdated: null, lastPolled: null, created: Fri Jul 11 17:23:04 UTC 2014}, job origin:1154
> com.cloud.utils.exception.CloudRuntimeException: Failed to detach volume DATA-118 from VM VM-6ab214a7-7df9-4317-9564-4da0f5a58a86; Failed dettach volume: 80f0f1cd-a1e7-4dec-b706-cebc3a1c6b5f, due to The server failed to handle your request, due to an internal error. The given message may give details useful for debugging the problem.
> at com.cloud.storage.VolumeApiServiceImpl.orchestrateDetachVolumeFromVM(VolumeApiServiceImpl.java:1564)
> at com.cloud.storage.VolumeApiServiceImpl.orchestrateDetachVolumeFromVM(VolumeApiServiceImpl.java:2525)
> 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:2556)
> at sun.reflect.GeneratedMethodAccessor477.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 $Proxy183.handleVmWorkJob(Unknown Source)
> at com.cloud.vm.VmWorkJobDispatcher.runJob(VmWorkJobDispatcher.java:102)
> at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:507)
> 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:464)
> 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-07-11 17:28:06,157 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-45:ctx-0bbb5e9c job-1154/job-1155) Complete async job-1155, jobStatus: FAILED, resultCode: 0, result: rO0ABXNyABpqYXZhLmxhbmcuUnVudGltZUV4Y2VwdGlvbp5fBkcKNIPlAgAAeHIAE2phdmEubGFuZy5FeGNlcHRpb27Q_R8-GjscxAIAAHhyABNqYXZhLmxhbmcuVGhyb3dhYmxl1cY1Jzl3uMsDAARMAAVjYXVzZXQAFUxqYXZhL2xhbmcvVGhyb3dhYmxlO0wADWRldGFpbE1lc3NhZ2V0ABJMamF2YS9sYW5nL1N0cmluZztbAApzdGFja1RyYWNldAAeW0xqYXZhL2xhbmcvU3RhY2tUcmFjZUVsZW1lbnQ7TAAUc3VwcHJlc3NlZEV4Y2VwdGlvbnN0ABBMamF2YS91dGlsL0xpc3Q7eHBxAH4AB3QBO0pvYiBmYWlsZWQgZHVlIHRvIGV4Y2VwdGlvbiBGYWlsZWQgdG8gZGV0YWNoIHZvbHVtZSBEQVRBLTExOCBmcm9tIFZNIFZNLTZhYjIxNGE3LTdkZjktNDMxNy05NTY0LTRkYTBmNWE1OGE4NjsgRmFpbGVkIGRldHRhY2ggdm9sdW1lOiA4MGYwZjFjZC1hMWU3LTRkZWMtYjcwNi1jZWJjM2ExYzZiNWYsIGR1ZSB0byBUaGUgc2VydmVyIGZhaWxlZCB0byBoYW5kbGUgeW91ciByZXF1ZXN0LCBkdWUgdG8gYW4gaW50ZXJuYWwgZXJyb3IuICBUaGUgZ2l2ZW4gbWVzc2FnZSBtYXkgZ2l2ZSBkZXRhaWxzIHVzZWZ1bCBmb3IgZGVidWdnaW5nIHRoZSBwcm9ibGVtLnVyAB5bTGphdmEubGFuZy5TdGFja1RyYWNlRWxlbWVudDsCRio8PP0iOQIAAHhwAAAADnNyABtqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnRhCcWaJjbdhQIABEkACmxpbmVOdW1iZXJMAA5kZWNsYXJpbmdDbGFzc3EAfgAETAAIZmlsZU5hbWVxAH4ABEwACm1ldGhvZE5hbWVxAH4ABHhwAAAAcnQAIGNvbS5jbG91ZC52bS5WbVdvcmtKb2JEaXNwYXRjaGVydAAYVm1Xb3JrSm9iRGlzcGF0Y2hlci5qYXZhdAAGcnVuSm9ic3EAfgALAAAB-3QAP29yZy5hcGFjaGUuY2xvdWRzdGFjay5mcmFtZXdvcmsuam9icy5pbXBsLkFzeW5jSm9iTWFuYWdlckltcGwkNXQAGEFzeW5jSm9iTWFuYWdlckltcGwuamF2YXQADHJ1bkluQ29udGV4dHNxAH4ACwAAADF0AD5vcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGUkMXQAG01hbmFnZWRDb250ZXh0UnVubmFibGUuamF2YXQAA3J1bnNxAH4ACwAAADh0AEJvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0LmltcGwuRGVmYXVsdE1hbmFnZWRDb250ZXh0JDF0ABpEZWZhdWx0TWFuYWdlZENvbnRleHQuamF2YXQABGNhbGxzcQB-AAsAAABndABAb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dHEAfgAadAAPY2FsbFdpdGhDb250ZXh0c3EAfgALAAAANXEAfgAdcQB-ABp0AA5ydW5XaXRoQ29udGV4dHNxAH4ACwAAAC50ADxvcmcuYXBhY2hlLmNsb3Vkc3RhY2subWFuYWdlZC5jb250ZXh0Lk1hbmFnZWRDb250ZXh0UnVubmFibGVxAH4AFnEAfgAXc3EAfgALAAAB0HEAfgARcQB-ABJxAH4AF3NxAH4ACwAAAdd0AC5qYXZhLnV0aWwuY29uY3VycmVudC5FeGVjdXRvcnMkUnVubmFibGVBZGFwdGVydAAORXhlY3V0b3JzLmphdmFxAH4AG3NxAH4ACwAAAU50ACRqYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrJFN5bmN0AA9GdXR1cmVUYXNrLmphdmF0AAhpbm5lclJ1bnNxAH4ACwAAAKZ0AB9qYXZhLnV0aWwuY29uY3VycmVudC5GdXR1cmVUYXNrcQB-AClxAH4AF3NxAH4ACwAABFZ0ACdqYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3J0ABdUaHJlYWRQb29sRXhlY3V0b3IuamF2YXQACXJ1bldvcmtlcnNxAH4ACwAAAlt0AC5qYXZhLnV0aWwuY29uY3VycmVudC5UaHJlYWRQb29sRXhlY3V0b3IkV29ya2VycQB-AC9xAH4AF3NxAH4ACwAAAtJ0ABBqYXZhLmxhbmcuVGhyZWFkdAALVGhyZWFkLmphdmFxAH4AF3NyACZqYXZhLnV0aWwuQ29sbGVjdGlvbnMkVW5tb2RpZmlhYmxlTGlzdPwPJTG17I4QAgABTAAEbGlzdHEAfgAGeHIALGphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVDb2xsZWN0aW9uGUIAgMte9x4CAAFMAAFjdAAWTGphdmEvdXRpbC9Db2xsZWN0aW9uO3hwc3IAE2phdmEudXRpbC5BcnJheUxpc3R4gdIdmcdhnQMAAUkABHNpemV4cAAAAAB3BAAAAAB4cQB-ADt4
> 2014-07-11 17:28:06,162 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-45:ctx-0bbb5e9c job-1154/job-1155) Done executing com.cloud.storage.VmWorkDetachVolume for job-1155
> 2014-07-11 17:28:06,170 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl] (Work-Job-Executor-45:ctx-0bbb5e9c job-1154/job-1155) Sync queue (376) is currently empty
> 2014-07-11 17:28:06,171 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-45:ctx-0bbb5e9c job-1154/job-1155) Remove job-1155 from job monitoring
> 2014-07-11 17:28:06,174 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-33:ctx-2445cce0 job-1154) Unexpected exception while executing org.apache.cloudstack.api.command.admin.volume.DetachVolumeCmdByAdmin
> java.lang.RuntimeException: Unexpected exception
> at com.cloud.storage.VolumeApiServiceImpl.detachVolumeFromVM(VolumeApiServiceImpl.java:1467)
> 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.apache.cloudstack.network.contrail.management.EventUtils$EventInterceptor.invoke(EventUtils.java:106)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
> at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:51)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
> at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> at $Proxy183.detachVolumeFromVM(Unknown Source)
> at org.apache.cloudstack.api.command.admin.volume.DetachVolumeCmdByAdmin.execute(DetachVolumeCmdByAdmin.java:39)
> 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:507)
> 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:464)
> 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 detach volume DATA-118 from VM VM-6ab214a7-7df9-4317-9564-4da0f5a58a86; Failed dettach volume: 80f0f1cd-a1e7-4dec-b706-cebc3a1c6b5f, due to The server failed to handle your request, due to an internal error. The given message may give details useful for debugging the problem.
> ... 31 more
> 2014-07-11 17:28:06,197 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-33:ctx-2445cce0 job-1154) Complete async job-1154, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unexpected exception"}
--
This message was sent by Atlassian JIRA
(v6.2#6252)