You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Rayees Namathponnan (JIRA)" <ji...@apache.org> on 2014/07/18 19:54:05 UTC
[jira] [Resolved] (CLOUDSTACK-7130) [Automation] Attach volume to
VM failing in KVM with "Unexpected exception"
[ https://issues.apache.org/jira/browse/CLOUDSTACK-7130?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Rayees Namathponnan resolved CLOUDSTACK-7130.
---------------------------------------------
Resolution: Fixed
> [Automation] Attach volume to VM failing in KVM with "Unexpected exception"
> ---------------------------------------------------------------------------
>
> Key: CLOUDSTACK-7130
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-7130
> 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: KVM
> Reporter: Gaurav Aradhye
> Assignee: edison su
> Labels: automation
> Fix For: 4.5.0
>
> Attachments: KVMAttachVolumeFailureLog.txt, agent.zip
>
>
> Steps to reproduce:
> 1. Deploy a VM
> 2. Create a data volume
> 3. Attach volume to VM
> The operation fails with "Unexpected exception"
> Log:
> 2014-07-18 05:27:37,182 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Work-Job-Executor-108:ctx-4fd8d076 job-5653/job-5654 ctx-4c56de83) create volume failed: java.lang.NullPo
> interException
> 2014-07-18 05:27:37,182 ERROR [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-108:ctx-4fd8d076 job-5653/job-5654 ctx-4c56de83) Invocation exception, caused by: com.cl
> oud.utils.exception.CloudRuntimeException: create volume failed:java.lang.NullPointerException
> 2014-07-18 05:27:37,183 INFO [c.c.v.VmWorkJobHandlerProxy] (Work-Job-Executor-108:ctx-4fd8d076 job-5653/job-5654 ctx-4c56de83) Rethrow exception com.cloud.utils.excep
> tion.CloudRuntimeException: create volume failed:java.lang.NullPointerException
> 2014-07-18 05:27:37,183 DEBUG [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-108:ctx-4fd8d076 job-5653/job-5654) Done with run of VM work job: com.cloud.storage.VmWork
> AttachVolume for VM 864, job origin: 5653
> 2014-07-18 05:27:37,183 ERROR [c.c.v.VmWorkJobDispatcher] (Work-Job-Executor-108:ctx-4fd8d076 job-5653/job-5654) Unable to complete AsyncJobVO {id:5654, userId: 2, acc
> ountId: 2, instanceType: null, instanceId: null, cmd: com.cloud.storage.VmWorkAttachVolume, cmdInfo: rO0ABXNyACRjb20uY2xvdWQuc3RvcmFnZS5WbVdvcmtBdHRhY2hWb2x1bWUHra_5YY
> fiHAIAAkwACGRldmljZUlkdAAQTGphdmEvbGFuZy9Mb25nO0wACHZvbHVtZUlkcQB-AAF4cgATY29tLmNsb3VkLnZtLlZtV29ya5-ZtlbwJWdrAgAESgAJYWNjb3VudElkSgAGdXNlcklkSgAEdm1JZEwAC2hhbmRsZXJOY
> W1ldAASTGphdmEvbGFuZy9TdHJpbmc7eHAAAAAAAAAAAgAAAAAAAAACAAAAAAAAA2B0ABRWb2x1bWVBcGlTZXJ2aWNlSW1wbHBzcgAOamF2YS5sYW5nLkxvbmc7i-SQzI8j3wIAAUoABXZhbHVleHIAEGphdmEubGFuZy5O
> dW1iZXKGrJUdC5TgiwIAAHhwAAAAAAAAA5g, cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 29066118877352, completeMsid: null, l
> astUpdated: null, lastPolled: null, created: Fri Jul 18 05:27:35 PDT 2014}, job origin:5653
> com.cloud.utils.exception.CloudRuntimeException: create volume failed:java.lang.NullPointerException
> at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.createVolume(VolumeOrchestrator.java:482)
> at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.createVolumeOnPrimaryStorage(VolumeOrchestrator.java:763)
> at com.cloud.storage.VolumeApiServiceImpl.attachVolumeToVM(VolumeApiServiceImpl.java:1306)
> at com.cloud.storage.VolumeApiServiceImpl.orchestrateAttachVolumeToVM(VolumeApiServiceImpl.java:1173)
> at com.cloud.storage.VolumeApiServiceImpl.orchestrateAttachVolumeToVM(VolumeApiServiceImpl.java:2601)
> at sun.reflect.GeneratedMethodAccessor790.invoke(Unknown Source)
> 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.storage.VolumeApiServiceImpl.handleVmWorkJob(VolumeApiServiceImpl.java:2640)
> at sun.reflect.GeneratedMethodAccessor668.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
> at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> at com.sun.proxy.$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.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:744)
> 2014-07-18 05:27:37,191 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-108:ctx-4fd8d076 job-5653/job-5654) Complete async job-5654, jobStatus: FAILED, resu
> ltCode: 0, result: rO0ABXNyABpqYXZhLmxhbmcuUnVudGltZUV4Y2VwdGlvbp5fBkcKNIPlAgAAeHIAE2phdmEubGFuZy5FeGNlcHRpb27Q_R8-GjscxAIAAHhyABNqYXZhLmxhbmcuVGhyb3dhYmxl1cY1Jzl3uMsD
> AARMAAVjYXVzZXQAFUxqYXZhL2xhbmcvVGhyb3dhYmxlO0wADWRldGFpbE1lc3NhZ2V0ABJMamF2YS9sYW5nL1N0cmluZztbAApzdGFja1RyYWNldAAeW0xqYXZhL2xhbmcvU3RhY2tUcmFjZUVsZW1lbnQ7TAAUc3VwcHJ
> lc3NlZEV4Y2VwdGlvbnN0ABBMamF2YS91dGlsL0xpc3Q7eHBxAH4AB3QAT0pvYiBmYWlsZWQgZHVlIHRvIGV4Y2VwdGlvbiBjcmVhdGUgdm9sdW1lIGZhaWxlZDpqYXZhLmxhbmcuTnVsbFBvaW50ZXJFeGNlcHRpb251cg
> AeW0xqYXZhLmxhbmcuU3RhY2tUcmFjZUVsZW1lbnQ7AkYqPDz9IjkCAAB4cAAAAA1zcgAbamF2YS5sYW5nLlN0YWNrVHJhY2VFbGVtZW50YQnFmiY23YUCAARJAApsaW5lTnVtYmVyTAAOZGVjbGFyaW5nQ2xhc3NxAH4AB
> EwACGZpbGVOYW1lcQB-AARMAAptZXRob2ROYW1lcQB-AAR4cAAAAHJ0ACBjb20uY2xvdWQudm0uVm1Xb3JrSm9iRGlzcGF0Y2hlcnQAGFZtV29ya0pvYkRpc3BhdGNoZXIuamF2YXQABnJ1bkpvYnNxAH4ACwAAAft0AD9v
> cmcuYXBhY2hlLmNsb3Vkc3RhY2suZnJhbWV3b3JrLmpvYnMuaW1wbC5Bc3luY0pvYk1hbmFnZXJJbXBsJDV0ABhBc3luY0pvYk1hbmFnZXJJbXBsLmphdmF0AAxydW5JbkNvbnRleHRzcQB-AAsAAAAxdAA-b3JnLmFwYWN
> oZS5jbG91ZHN0YWNrLm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlJDF0ABtNYW5hZ2VkQ29udGV4dFJ1bm5hYmxlLmphdmF0AANydW5zcQB-AAsAAAA4dABCb3JnLmFwYWNoZS5jbG91ZHN0YWNrLm
> 1hbmFnZWQuY29udGV4dC5pbXBsLkRlZmF1bHRNYW5hZ2VkQ29udGV4dCQxdAAaRGVmYXVsdE1hbmFnZWRDb250ZXh0LmphdmF0AARjYWxsc3EAfgALAAAAZ3QAQG9yZy5hcGFjaGUuY2xvdWRzdGFjay5tYW5hZ2VkLmNvb
> nRleHQuaW1wbC5EZWZhdWx0TWFuYWdlZENvbnRleHRxAH4AGnQAD2NhbGxXaXRoQ29udGV4dHNxAH4ACwAAADVxAH4AHXEAfgAadAAOcnVuV2l0aENvbnRleHRzcQB-AAsAAAAudAA8b3JnLmFwYWNoZS5jbG91ZHN0YWNr
> Lm1hbmFnZWQuY29udGV4dC5NYW5hZ2VkQ29udGV4dFJ1bm5hYmxlcQB-ABZxAH4AF3NxAH4ACwAAAdBxAH4AEXEAfgAScQB-ABdzcQB-AAsAAAHXdAAuamF2YS51dGlsLmNvbmN1cnJlbnQuRXhlY3V0b3JzJFJ1bm5hYmx
> lQWRhcHRlcnQADkV4ZWN1dG9ycy5qYXZhcQB-ABtzcQB-AAsAAAEGdAAfamF2YS51dGlsLmNvbmN1cnJlbnQuRnV0dXJlVGFza3QAD0Z1dHVyZVRhc2suamF2YXEAfgAXc3EAfgALAAAEeXQAJ2phdmEudXRpbC5jb25jdX
> JyZW50LlRocmVhZFBvb2xFeGVjdXRvcnQAF1RocmVhZFBvb2xFeGVjdXRvci5qYXZhdAAJcnVuV29ya2Vyc3EAfgALAAACZ3QALmphdmEudXRpbC5jb25jdXJyZW50LlRocmVhZFBvb2xFeGVjdXRvciRXb3JrZXJxAH4AL
> HEAfgAXc3EAfgALAAAC6HQAEGphdmEubGFuZy5UaHJlYWR0AAtUaHJlYWQuamF2YXEAfgAXc3IAJmphdmEudXRpbC5Db2xsZWN0aW9ucyRVbm1vZGlmaWFibGVMaXN0_A8lMbXsjhACAAFMAARsaXN0cQB-AAZ4cgAsamF2
> YS51dGlsLkNvbGxlY3Rpb25zJFVubW9kaWZpYWJsZUNvbGxlY3Rpb24ZQgCAy173HgIAAUwAAWN0ABZMamF2YS91dGlsL0NvbGxlY3Rpb247eHBzcgATamF2YS51dGlsLkFycmF5TGlzdHiB0h2Zx2GdAwABSQAEc2l6ZXh
> wAAAAAHcEAAAAAHhxAH4AOHg
> 2014-07-18 05:27:37,191 DEBUG [c.c.u.AccountManagerImpl] (API-Job-Executor-98:ctx-edfbaaad job-5626 ctx-603d061b) Access granted to Acct[6c1f4112-0e3c-11e4-b040-1a6f7b
> b0d0a8-admin] to Domain:1/ by AffinityGroupAccessChecker
> 2014-07-18 05:27:37,196 DEBUG [c.c.a.ApiServlet] (catalina-exec-18:ctx-97285f9a ctx-3c862f88 ctx-cd3889d2) ===END=== 10.223.240.194 -- GET jobid=2b42f4a8-889e-46b1-a
> c4d-0119e34486c7&apiKey=f9YPqloMoF-X1F_WwTICLVc-hJZc1S9kh3vBiLss1LCdw2RRHx2ZNulLpoXnxVFd9_tceNkH1adteoVEg6HToA&command=queryAsyncJobResult&response=json&signature=MAja
> itWQuzjYlYh1OFSGfBA8iT8%3D
> 2014-07-18 05:27:37,196 INFO [c.c.r.ResourceLimitManagerImpl] (API-Job-Executor-98:ctx-edfbaaad job-5626 ctx-603d061b) Discrepency in the resource count (original cou
> nt=8589934592 correct count = 0) for type primary_storage for account ID 548 is fixed during resource count recalculation.
> 2014-07-18 05:27:37,203 DEBUG [c.c.a.ApiServlet] (catalina-exec-4:ctx-9c10b178) ===START=== 10.223.240.194 -- GET account=test-TestTemplates-test_01_create_template-
> FAA0XP&domainid=100ceaf0-0e3c-11e4-b040-1a6f7bb0d0a8&response=json&apiKey=f9YPqloMoF-X1F_WwTICLVc-hJZc1S9kh3vBiLss1LCdw2RRHx2ZNulLpoXnxVFd9_tceNkH1adteoVEg6HToA&comman
> d=listVirtualMachines&signature=sGFKKxkiF%2BHEBsJ5ON9cjoSx0Tw%3D&id=a79520dd-8e3e-43e8-b630-3d4cc2d8cc4f&listall=True
> 2014-07-18 05:27:37,211 DEBUG [c.c.v.UserVmManagerImpl] (API-Job-Executor-98:ctx-edfbaaad job-5626 ctx-603d061b) Starting cleaning up vm VM[User|i-548-858-VM] resource
> s...
> 2014-07-18 05:27:37,212 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Work-Job-Executor-108:ctx-4fd8d076 job-5653/job-5654) Done executing com.cloud.storage.VmWorkAttachVol
> ume for job-5654
> 2014-07-18 05:27:37,230 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-111:ctx-5bced597 job-5653) 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:1163)
> at sun.reflect.GeneratedMethodAccessor789.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
> at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> at com.sun.proxy.$Proxy183.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: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.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:744)
> Caused by: java.lang.RuntimeException: Job failed due to exception create volume failed:java.lang.NullPointerException
> ... 25 more
> 2014-07-18 05:27:37,234 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-111:ctx-5bced597 job-5653) Complete async job-5653, jobStatus: FAILED, resultCode: 53
> 0, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unexpected exception"}
--
This message was sent by Atlassian JIRA
(v6.2#6252)