You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Sailaja Mada (JIRA)" <ji...@apache.org> on 2013/07/26 12:01:51 UTC
[jira] [Reopened] (CLOUDSTACK-3107) NPE while attaching the volume
which is added thru uploadVolume
[ https://issues.apache.org/jira/browse/CLOUDSTACK-3107?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Sailaja Mada reopened CLOUDSTACK-3107:
--------------------------------------
Regressed with latest build. Still failed to attach volume which is added thru upload volume :
2013-07-26 15:17:17,234 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===START=== 10.144.6.19 -- GET command=attachVolume&id=eca38be7-ca72-4785-b6d3-26e7ac57081f&virtualMachineId=217af38a-f1da-4be7-8ae4-cdeca8113eec&response=json&sessionkey=Oq%2FsiRUjhlt%2FW1AOUct6N0uHgtI%3D&_=1374832256894
2013-07-26 15:17:17,551 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-5:null) submit async job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ], details: AsyncJobVO {id:19, userId: 3, accountId: 3, sessionKey: null, instanceType: Volume, instanceId: 7, cmd: org.apache.cloudstack.api.command.user.volume.AttachVolumeCmd, cmdOriginator: null, cmdInfo: {"id":"eca38be7-ca72-4785-b6d3-26e7ac57081f","response":"json","sessionkey":"Oq/siRUjhlt/W1AOUct6N0uHgtI\u003d","cmdEventType":"VOLUME.ATTACH","ctxUserId":"3","virtualMachineId":"217af38a-f1da-4be7-8ae4-cdeca8113eec","httpmethod":"GET","_":"1374832256894","ctxAccountId":"3","ctxStartEventId":"77"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 55638679939377, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-07-26 15:17:17,554 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===END=== 10.144.6.19 -- GET command=attachVolume&id=eca38be7-ca72-4785-b6d3-26e7ac57081f&virtualMachineId=217af38a-f1da-4be7-8ae4-cdeca8113eec&response=json&sessionkey=Oq%2FsiRUjhlt%2FW1AOUct6N0uHgtI%3D&_=1374832256894
2013-07-26 15:17:17,557 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) Executing org.apache.cloudstack.api.command.user.volume.AttachVolumeCmd for job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]
2013-07-26 15:17:17,672 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) Access to org.apache.cloudstack.storage.volume.VolumeObject@26fef29 granted to Acct[3-cdcuser1] by DomainChecker_EnhancerByCloudStack_37913e36
2013-07-26 15:17:17,673 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) Access to VM[User|cdcuser1i1] granted to Acct[3-cdcuser1] by DomainChecker_EnhancerByCloudStack_37913e36
2013-07-26 15:17:17,698 DEBUG [storage.allocator.LocalStoragePoolAllocator] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-07-26 15:17:17,700 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) ClusterScopeStoragePoolAllocator looking for storage pool
2013-07-26 15:17:17,700 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) Looking for pools in dc: 1 pod:1 cluster:null
2013-07-26 15:17:17,703 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) No storage pools available for shared volume allocation, returning
2013-07-26 15:17:17,703 DEBUG [storage.allocator.ZoneWideStoragePoolAllocator] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) ZoneWideStoragePoolAllocator to find storage pool
2013-07-26 15:17:17,725 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) Checking pool 1 for storage, totalSize: 879609303040, usedBytes: 590736277504, usedPct: 0.6715893925432215, disable threshold: 0.85
2013-07-26 15:17:17,746 DEBUG [cloud.storage.StorageManagerImpl] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) Checking pool: 1 for volume allocation [Vol[7|vm=null|DATADISK]], maxSize : 1759218606080, totalAllocatedSize : 0, askingSize : 2147483648, allocated disable threshold: 0.85
2013-07-26 15:17:17,808 DEBUG [storage.motion.AncientDataMotionStrategy] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) copyAsync inspecting src type VOLUME copyAsync inspecting dest type VOLUME
2013-07-26 15:17:17,822 DEBUG [agent.transport.Request] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) Seq 1-107151876: Sending { Cmd , MgmtId: 55638679939377, via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"eca38be7-ca72-4785-b6d3-26e7ac57081f","volumeType":"DATADISK","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.102.192.100/cpg_vol/sailaja/vmware51ss1","_role":"Image"}},"name":"CentOS5.3-x86_64","size":2147483648,"path":"volumes/3/7/66d185f1-3933-36ed-9919-d512c930cbec.ova","volumeId":7,"accountId":3,"format":"OVA","id":7,"hypervisorType":"None"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"eca38be7-ca72-4785-b6d3-26e7ac57081f","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a5d175a7-fc4b-3184-879a-9c1c475311c0","id":1,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/vmware51ps1","port":2049}},"name":"CentOS5.3-x86_64","size":2147483648,"volumeId":7,"accountId":3,"format":"OVA","id":7,"hypervisorType":"None"}},"executeInSequence":false,"wait":10800}}] }
2013-07-26 15:17:17,823 DEBUG [agent.transport.Request] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) Seq 1-107151876: Executing: { Cmd , MgmtId: 55638679939377, via: 1, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"eca38be7-ca72-4785-b6d3-26e7ac57081f","volumeType":"DATADISK","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.102.192.100/cpg_vol/sailaja/vmware51ss1","_role":"Image"}},"name":"CentOS5.3-x86_64","size":2147483648,"path":"volumes/3/7/66d185f1-3933-36ed-9919-d512c930cbec.ova","volumeId":7,"accountId":3,"format":"OVA","id":7,"hypervisorType":"None"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"eca38be7-ca72-4785-b6d3-26e7ac57081f","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a5d175a7-fc4b-3184-879a-9c1c475311c0","id":1,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/vmware51ps1","port":2049}},"name":"CentOS5.3-x86_64","size":2147483648,"volumeId":7,"accountId":3,"format":"OVA","id":7,"hypervisorType":"None"}},"executeInSequence":false,"wait":10800}}] }
2013-07-26 15:17:17,823 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-298:null) Seq 1-107151876: Executing request
2013-07-26 15:17:17,875 ERROR [storage.resource.VmwareStorageProcessor] (DirectAgent-298:10.102.192.19) Unable to find snapshot OVA file at: /var/cloudstack/mnt/VM/55638679939377.58f6e6c2/volumes/3/7/66d185f1-3933-36ed-9919-d512c930cbec.ova/66d185f1-3933-36ed-9919-d512c930cbec.ova.ova
2013-07-26 15:17:17,876 ERROR [storage.resource.VmwareStorageProcessor] (DirectAgent-298:10.102.192.19) Unable to execute CopyVolumeCommand due to exception
java.lang.Exception: Unable to find snapshot OVA file at: /var/cloudstack/mnt/VM/55638679939377.58f6e6c2/volumes/3/7/66d185f1-3933-36ed-9919-d512c930cbec.ova/66d185f1-3933-36ed-9919-d512c930cbec.ova.ova
at com.cloud.storage.resource.VmwareStorageProcessor.restoreVolumeFromSecStorage(VmwareStorageProcessor.java:1573)
at com.cloud.storage.resource.VmwareStorageProcessor.copyVolumeFromSecStorage(VmwareStorageProcessor.java:431)
at com.cloud.storage.resource.VmwareStorageProcessor.copyVolumeFromImageCacheToPrimary(VmwareStorageProcessor.java:477)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:76)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:566)
at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
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$101(ScheduledThreadPoolExecutor.java:165)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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:679)
2013-07-26 15:17:17,883 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-298:null) Seq 1-107151876: Response Received:
2013-07-26 15:17:17,883 DEBUG [agent.transport.Request] (DirectAgent-298:null) Seq 1-107151876: Processing: { Ans: , MgmtId: 55638679939377, via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"CopyVolumeCommand failed due to exception: java.lang.Exception: Unable to find snapshot OVA file at: /var/cloudstack/mnt/VM/55638679939377.58f6e6c2/volumes/3/7/66d185f1-3933-36ed-9919-d512c930cbec.ova/66d185f1-3933-36ed-9919-d512c930cbec.ova.ova","wait":0}}] }
2013-07-26 15:17:17,883 DEBUG [agent.transport.Request] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) Seq 1-107151876: Received: { Ans: , MgmtId: 55638679939377, via: 1, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2013-07-26 15:17:17,913 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) copy volume failed: java.lang.NullPointerException
2013-07-26 15:17:17,942 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) Unexpected exception while executing org.apache.cloudstack.api.command.user.volume.AttachVolumeCmd
com.cloud.utils.exception.CloudRuntimeException: copy volume failed: java.lang.NullPointerException
at com.cloud.storage.VolumeManagerImpl.copyVolumeFromSecToPrimary(VolumeManagerImpl.java:652)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at com.cloud.storage.VolumeManagerImpl.copyVolume(VolumeManagerImpl.java:1529)
at com.cloud.storage.VolumeManagerImpl.createVolumeOnPrimaryStorage(VolumeManagerImpl.java:1560)
at com.cloud.storage.VolumeManagerImpl.attachVolumeToVM(VolumeManagerImpl.java:1853)
at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at org.apache.cloudstack.api.command.user.volume.AttachVolumeCmd.execute(AttachVolumeCmd.java:122)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
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:679)
2013-07-26 15:17:17,947 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-22:job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ]) Complete async job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ], jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: copy volume failed: java.lang.NullPointerException
2013-07-26 15:17:20,581 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null) ===START=== 10.144.6.19 -- GET command=queryAsyncJobResult&jobId=dd72fef1-9ef8-47e2-a1cd-92d91b4d0277&response=json&sessionkey=Oq%2FsiRUjhlt%2FW1AOUct6N0uHgtI%3D&_=1374832260281
2013-07-26 15:17:20,595 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-11:null) Async job-19 = [ dd72fef1-9ef8-47e2-a1cd-92d91b4d0277 ] completed
2013-07-26 15:17:20,619 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null) ===END=== 10.144.6.19 -- GET command=queryAsyncJobResult&jobId=dd72fef1-9ef8-47e2-a1cd-92d91b4d0277&response=json&sessionkey=Oq%2FsiRUjhlt%2FW1AOUct6N0uHgtI%3D&_=1374832260281
> NPE while attaching the volume which is added thru uploadVolume
> ----------------------------------------------------------------
>
> Key: CLOUDSTACK-3107
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-3107
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: Storage Controller, VMware
> Affects Versions: 4.2.0
> Environment: MS : RHEL 6.3
> Reporter: Sailaja Mada
> Assignee: Likitha Shetty
> Priority: Critical
> Fix For: 4.2.0
>
> Attachments: apilog.log, management-server.log
>
>
> Steps:
> 1. Configured Advanced Zone with VMWARE
> 2. Added new volume with .ova format using upload volume
> 3. When the volume got in to uploaded state , tried to add to the instance
> Observation: It failed with NPE. (Attached the log)
> 2013-06-21 11:20:42,793 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-1:null) submit async job-76, details: AsyncJobVO {id:76, userId: 3, accountId: 3, sessionKey: null, instanceType: Volume, instanceId: 18, cmd: org.apache.cloudstack.api.command.user.volume.AttachVolumeCmd, cmdOriginator: null, cmdInfo: {"response":"json","id":"df818343-2c19-4129-9ca7-ebe886a1063c","sessionkey":"RNaZZnzH0NfhX0IJaRwpz7wq9sY\u003d","ctxUserId":"3","virtualMachineId":"54536078-e4c5-4ad0-a87e-2817061264f0","httpmethod":"GET","_":"1371794030143","ctxAccountId":"3","ctxStartEventId":"326"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 94838926819810, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2013-06-21 11:20:42,796 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===END=== 10.144.6.19 -- GET command=attachVolume&id=df818343-2c19-4129-9ca7-ebe886a1063c&virtualMachineId=54536078-e4c5-4ad0-a87e-2817061264f0&response=json&sessionkey=RNaZZnzH0NfhX0IJaRwpz7wq9sY%3D&_=1371794030143
> 2013-06-21 11:20:42,826 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-102:job-76) Executing org.apache.cloudstack.api.command.user.volume.AttachVolumeCmd for job-76
> 2013-06-21 11:20:42,938 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-102:job-76) Access to org.apache.cloudstack.storage.volume.VolumeObject@6876d38e granted to Acct[3-user1] by DomainChecker_EnhancerByCloudStack_97621a92
> 2013-06-21 11:20:42,939 DEBUG [cloud.user.AccountManagerImpl] (Job-Executor-102:job-76) Access to VM[User|useri2] granted to Acct[3-user1] by DomainChecker_EnhancerByCloudStack_97621a92
> 2013-06-21 11:20:42,966 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-102:job-76) Unexpected exception while executing org.apache.cloudstack.api.command.user.volume.AttachVolumeCmd
> java.lang.NullPointerException
> at com.cloud.storage.VolumeManagerImpl.copyVolume(VolumeManagerImpl.java:1443)
> at com.cloud.storage.VolumeManagerImpl.createVolumeOnPrimaryStorage(VolumeManagerImpl.java:1487)
> at com.cloud.storage.VolumeManagerImpl.attachVolumeToVM(VolumeManagerImpl.java:1733)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.api.command.user.volume.AttachVolumeCmd.execute(AttachVolumeCmd.java:122)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:155)
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437)
> 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:679)
> 2013-06-21 11:20:42,984 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-102:job-76) Complete async job-76, jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: null
> 2013-06-21 11:20:44,071 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-199:null) Ping from 1
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira