Likitha Shetty created CLOUDSTACK-8120: ------------------------------------------
Summary: Propagate error message to UI for attach/detach volume failure operations. Key: CLOUDSTACK-8120 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-8120 Project: CloudStack Issue Type: Bug Security Level: Public (Anyone can view this level - this is the default.) Affects Versions: 4.5.0 Reporter: Likitha Shetty Assignee: Likitha Shetty Priority: Critical Fix For: Future Steps: 1. Have a VMware setup. 2. Deploy Windows XP instance with one Datadisk. 3. Try to attach a volume to the running Win XP instance - Fails. 4. Try to detach the additional datadisk attached to the running Win XP instance - Fails. Reason for the above failures is that in case of VMware a Windows XP instance need to be in powered off state to be able to perform attach/detach on the instance. But the UI failure reads - 'Unexpected Exception'. CS should instead throw the right error message. Logs - {noformat} 2014-11-26 11:02:49,663 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-27:ctx-19c52bfe job-84/job-85) Done executing com.cloud.vm.VmWorkAttachVolume for job-85 2014-11-26 11:02:49,666 DEBUG [o.a.c.f.j.i.SyncQueueManagerImpl] (Work-Job-Executor-27:ctx-19c52bfe job-84/job-85) Sync queue (5) is currently empty 2014-11-26 11:02:49,667 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Work-Job-Executor-27:ctx-19c52bfe job-84/job-85) Remove job-85 from job monitoring 2014-11-26 11:02:49,671 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-40:ctx-15db2b48 job-84) 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:1386) at com.cloud.storage.VolumeApiServiceImpl.attachVolumeToVM(VolumeApiServiceImpl.java:1168) 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 $Proxy185.attachVolumeToVM(Unknown Source) at org.apache.cloudstack.api.command.admin.volume.AttachVolumeCmdByAdmin.execute(AttachVolumeCmdByAdmin.java:40) 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: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$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: com.cloud.utils.exception.CloudRuntimeException: Failed to attach volume DATA-3 to VM win16GBinst1; AttachVolumeCommand failed due to Exception: java.lang.Exception Message: Adding a virtual disk over IDE controller is not supported while VM is running in VMware hypervisor. Please re-try when VM is not running. at com.cloud.storage.VolumeApiServiceImpl.sendAttachVolumeCommand(VolumeApiServiceImpl.java:2304) at com.cloud.storage.VolumeApiServiceImpl.orchestrateAttachVolumeToVM(VolumeApiServiceImpl.java:1237) at com.cloud.storage.VolumeApiServiceImpl.orchestrateAttachVolumeToVM(VolumeApiServiceImpl.java:2590) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ... 28 more 2014-11-26 11:02:49,674 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-40:ctx-15db2b48 job-84) Complete async job-84, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/ {"uuidList":[],"errorcode":530,"errortext":"Unexpected exception"} 2014-11-26 11:02:49,675 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-40:ctx-15db2b48 job-84) Publish async job-84 complete on message bus 2014-11-26 10:53:40,379 ERROR [c.c.s.r.VmwareStorageProcessor] (DirectAgent-423:ctx-4cb899f6 10.220.163.20, job-78/job-79, cmd: DettachCommand) AttachVolumeCommand failed due to Exception: java.lang.RuntimeException Message: The attempted operation cannot be performed in the current state (Powered on). java.lang.RuntimeException: The attempted operation cannot be performed in the current state (Powered on). at com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:335) at com.cloud.hypervisor.vmware.mo.VirtualMachineMO.detachDisk(VirtualMachineMO.java:1303) at com.cloud.storage.resource.VmwareStorageProcessor.attachVolume(VmwareStorageProcessor.java:1359) at com.cloud.storage.resource.VmwareStorageProcessor.dettachVolume(VmwareStorageProcessor.java:1490) at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:148) at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:61) at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:468) 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$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722) 2014-11-26 10:53:40,381 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-423:ctx-4cb899f6) Seq 2-2049700780406999002: Response Received: 2014-11-26 10:53:40,381 DEBUG [c.c.a.t.Request] (DirectAgent-423:ctx-4cb899f6) Seq 2-2049700780406999002: Processing: { Ans: , MgmtId: 77653631560287, via: 2, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.AttachAnswer":{"result":false,"details":"AttachVolumeCommand failed due to Exception: java.lang.RuntimeException\nMessage: The attempted operation cannot be performed in the current state (Powered on).\n","wait":0}}] } 2014-11-26 10:53:40,381 DEBUG [c.c.a.t.Request] (Work-Job-Executor-24:ctx-fdee3122 job-78/job-79 ctx-ce1b49eb) Seq 2-2049700780406999002: Received: { Ans: , MgmtId: 77653631560287, via: 2, Ver: v1, Flags: 10, { AttachAnswer } } 2014-11-26 10:53:40,381 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-24:ctx-fdee3122 job-78/job-79 ctx-ce1b49eb) Invocation exception, caused by: com.cloud.utils.exception.CloudRuntimeException: Failed to detach volume DATA-7 from VM secondvminst1; AttachVolumeCommand failed due to Exception: java.lang.RuntimeException Message: The attempted operation cannot be performed in the current state (Powered on). 2014-11-26 10:53:40,381 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-24:ctx-fdee3122 job-78/job-79 ctx-ce1b49eb) Rethrow exception com.cloud.utils.exception.CloudRuntimeException: Failed to detach volume DATA-7 from VM secondvminst1; AttachVolumeCommand failed due to Exception: java.lang.RuntimeException Message: The attempted operation cannot be performed in the current state (Powered on). 2014-11-26 10:53:40,381 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-24:ctx-fdee3122 job-78/job-79) Done with run of VM work job: com.cloud.vm.VmWorkDetachVolume for VM 7, job origin: 78 2014-11-26 10:53:40,381 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-24:ctx-fdee3122 job-78/job-79) Unable to complete AsyncJobVO {id:79, userId: 4, accountId: 4, instanceType: null, instanceId: null, cmd: com.cloud.vm.VmWorkDetachVolume, cmdInfo: rO0ABXNyAB9jb20uY2xvdWQudm0uVm1Xb3JrRGV0YWNoVm9sdW1lhvReA-s81AMCAAFMAAh2b2x1bWVJZHQAEExqYXZhL2xhbmcvTG9uZzt4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOYW1ldAASTGphdmEvbGFuZy9TdHJpbmc7eHAAAAAAAAAABAAAAAAAAAAEAAAAAAAAAAd0ABRWb2x1bWVBcGlTZXJ2aWNlSW1wbHNyAA5qYXZhLmxhbmcuTG9uZzuL5JDMjyPfAgABSgAFdmFsdWV4cgAQamF2YS5sYW5nLk51bWJlcoaslR0LlOCLAgAAeHAAAAAAAAAACg, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 77653631560287, completeMsid: null, lastUpdated: null, lastPolled: null, created: Wed Nov 26 10:53:38 UTC 2014} , job origin:78 com.cloud.utils.exception.CloudRuntimeException: Failed to detach volume DATA-7 from VM secondvminst1; AttachVolumeCommand failed due to Exception: java.lang.RuntimeException Message: The attempted operation cannot be performed in the current state (Powered on). {noformat} -- This message was sent by Atlassian JIRA (v6.3.4#6332)