cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "edison su (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CLOUDSTACK-7130) [Automation] Attach volume to VM failing in KVM with "Unexpected exception"
Date Thu, 07 Aug 2014 23:31:12 GMT

    [ https://issues.apache.org/jira/browse/CLOUDSTACK-7130?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14090027#comment-14090027
] 

edison su commented on CLOUDSTACK-7130:
---------------------------------------

Hi Gaurav, if the issue is observed, could you attach the latest error logs of both mgt server
and kvm agent? The issue is fixed in certain period of time, then occurred again, means some
new code changes recently break it.  

> [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)

Mime
View raw message