[
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
