[
https://issues.apache.org/jira/browse/CLOUDSTACK-4363?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13744367#comment-13744367
]
ASF subversion and git services commented on CLOUDSTACK-4363:
-------------------------------------------------------------
Commit 0040c4adef4f7b92aa63737a8f2c5405a07fabda in branch refs/heads/master
from [~edison]
[ https://git-wip-us.apache.org/repos/asf?p=cloudstack.git;h=0040c4a ]
CLOUDSTACK-4363: fix possible NPE, if copy volume failed.
> [VMware]Migration of data volume is throwing NPE
> -------------------------------------------------
>
> Key: CLOUDSTACK-4363
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4363
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Storage Controller
> Affects Versions: 4.2.0
> Reporter: manasaveloori
> Assignee: Kelven Yang
> Priority: Critical
> Fix For: 4.2.0
>
> Attachments: management-server.log
>
>
> Steps:
> 1. Have a CS 4.2 with VMware host.
> 2. Have primary- 1 local and 2 shared(NFS) and secondary-NFS.
> 3. Create a shared data volume.
> 4. Migrate it to either shared primary or local primary.
> Observation.
> Migration of the volume is failing with NPE:
> 2013-08-16 19:13:13,754 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null)
> ===START=== 10.252.192.69 -- GET
> command=migrateVolume&storageid=9c5838f1-4874-4dea-b396-d318f56ff192&volumeid=53059246-e850-480a-9315-9fa647c9b17d&response=json&sessionkey=x3AM9LcYvZ%2FzkGJ8%2BLR2uNIPzOs%3D&_=1376641214226
> 2013-08-16 19:13:14,719 DEBUG [cloud.async.AsyncJobManagerImpl]
> (catalina-exec-5:null) submit async job-33 = [
> 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ], details: AsyncJobVO {id:33, userId:
> 2, accountId: 2, sessionKey: null, instanceType: None, instanceId: null, cmd:
> org.apache.cloudstack.api.command.user.volume.MigrateVolumeCmd,
> cmdOriginator: null, cmdInfo:
> {"response":"json","sessionkey":"x3AM9LcYvZ/zkGJ8+LR2uNIPzOs\u003d","cmdEventType":"VOLUME.MIGRATE","ctxUserId":"2","storageid":"9c5838f1-4874-4dea-b396-d318f56ff192","httpmethod":"GET","volumeid":"53059246-e850-480a-9315-9fa647c9b17d","_":"1376641214226","ctxAccountId":"2","ctxStartEventId":"106"},
> cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
> processStatus: 0, resultCode: 0, result: null, initMsid: 7067804893289,
> completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2013-08-16 19:13:14,723 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null)
> ===END=== 10.252.192.69 -- GET
> command=migrateVolume&storageid=9c5838f1-4874-4dea-b396-d318f56ff192&volumeid=53059246-e850-480a-9315-9fa647c9b17d&response=json&sessionkey=x3AM9LcYvZ%2FzkGJ8%2BLR2uNIPzOs%3D&_=1376641214226
> 2013-08-16 19:13:14,727 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Executing
> org.apache.cloudstack.api.command.user.volume.MigrateVolumeCmd for job-33 = [
> 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]
> 2013-08-16 19:13:14,780 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-5:null) SeqA 2-786: Processing Seq 2-786: { Cmd ,
> MgmtId: -1, via: 2, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2013-08-16 19:13:14,799 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-5:null) SeqA 2-786: Sending Seq 2-786: { Ans: ,
> MgmtId: 7067804893289, via: 2, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> 2013-08-16 19:13:14,835 DEBUG [storage.motion.AncientDataMotionStrategy]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) copyAsync
> inspecting src type VOLUME copyAsync inspecting dest type VOLUME
> 2013-08-16 19:13:14,845 DEBUG [cache.allocator.StorageCacheRandomAllocator]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Can't
> find staging storage in zone: 1
> 2013-08-16 19:13:14,973 DEBUG [agent.transport.Request]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Seq
> 3-173277305: Sending { Cmd , MgmtId: 7067804893289, via: 3, Ver: v1, Flags:
> 100011,
> [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"53059246-e850-480a-9315-9fa647c9b17d","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"f672eae0-b400-3767-808f-b787a5c04d5f","id":2,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/manasa/primaryVMw","port":2049}},"name":"shared","size":5368709120,"path":"1d3265f1faa2452e860d13bcd05c9ec7","volumeId":9,"accountId":2,"format":"OVA","id":9,"hypervisorType":"VMware"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"53059246-e850-480a-9315-9fa647c9b17d","volumeType":"DATADISK","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/manasa/secondaryVMw","_role":"Image"}},"name":"shared","size":5368709120,"path":"volumes/2/9","volumeId":9,"accountId":2,"format":"OVA","id":9,"hypervisorType":"VMware"}},"executeInSequence":false,"wait":10800}}]
> }
> 2013-08-16 19:13:16,331 DEBUG [agent.transport.Request]
> (AgentManager-Handler-7:null) Seq 3-173277305: Processing: { Ans: , MgmtId:
> 7067804893289, via: 3, Ver: v1, Flags: 10,
> [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"copy
> volume from primary to secondary failed due to exception: Exception:
> java.lang.NullPointerException\nMessage: null\n","wait":0}}] }
> 2013-08-16 19:13:16,331 DEBUG [agent.transport.Request]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Seq
> 3-173277305: Received: { Ans: , MgmtId: 7067804893289, via: 3, Ver: v1,
> Flags: 10, { CopyCmdAnswer } }
> 2013-08-16 19:13:16,338 DEBUG [storage.motion.AncientDataMotionStrategy]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) copy to
> image store failed: copy volume from primary to secondary failed due to
> exception: Exception: java.lang.NullPointerException
> Message: null
> 2013-08-16 19:13:16,361 DEBUG [storage.image.BaseImageStoreDriverImpl]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Unable to
> destoy VOLUME: 9
> java.lang.NullPointerException
> at
> org.apache.cloudstack.storage.volume.VolumeObject.getPath(VolumeObject.java:338)
> at
> org.apache.cloudstack.storage.to.VolumeObjectTO.<init>(VolumeObjectTO.java:53)
> at
> org.apache.cloudstack.storage.volume.VolumeObject.getTO(VolumeObject.java:460)
> at
> org.apache.cloudstack.storage.image.BaseImageStoreDriverImpl.deleteAsync(BaseImageStoreDriverImpl.java:237)
> at
> org.apache.cloudstack.storage.image.store.ImageStoreImpl.delete(ImageStoreImpl.java:148)
> at
> org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyVolumeBetweenPools(AncientDataMotionStrategy.java:323)
> at
> org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:406)
> at
> org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:55)
> at
> org.apache.cloudstack.storage.volume.VolumeServiceImpl.copyVolume(VolumeServiceImpl.java:790)
> at
> com.cloud.storage.VolumeManagerImpl.migrateVolume(VolumeManagerImpl.java:2239)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> com.cloud.storage.VolumeManagerImpl.migrateVolume(VolumeManagerImpl.java:2228)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> org.apache.cloudstack.api.command.user.volume.MigrateVolumeCmd.execute(MigrateVolumeCmd.java:103)
> 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-08-16 19:13:16,365 WARN
> [storage.datastore.ObjectInDataStoreManagerImpl] (Job-Executor-33:job-33 = [
> 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Volume 9 is not found on image store
> 1, so no need to delete
> 2013-08-16 19:13:16,379 WARN
> [storage.datastore.ObjectInDataStoreManagerImpl] (Job-Executor-33:job-33 = [
> 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Unsupported data object (VOLUME,
> org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@4b78a0af), no
> need to delete from object in store ref table
> 2013-08-16 19:13:16,394 WARN
> [storage.datastore.ObjectInDataStoreManagerImpl] (Job-Executor-33:job-33 = [
> 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Unsupported data object (VOLUME,
> org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@3af189a6), no
> need to delete from object in store ref table
> 2013-08-16 19:13:16,491 DEBUG [agent.transport.Request]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Seq
> 1-473956798: Sending { Cmd , MgmtId: 7067804893289, via: 1, Ver: v1, Flags:
> 100011,
> [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"a35ac140-b3a6-4aa7-a84b-950bf3f51789","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9c5838f1-4874-4dea-b396-d318f56ff192","id":1,"poolType":"LVM","host":"10.147.40.25","path":"datastore-11514","port":0}},"name":"shared","size":5368709120,"path":"1d3265f1faa2452e860d13bcd05c9ec7","volumeId":10,"accountId":2,"id":10,"hypervisorType":"VMware"}},"wait":0}}]
> }
> 2013-08-16 19:13:16,492 DEBUG [agent.transport.Request]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Seq
> 1-473956798: Executing: { Cmd , MgmtId: 7067804893289, via: 1, Ver: v1,
> Flags: 100011,
> [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"a35ac140-b3a6-4aa7-a84b-950bf3f51789","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9c5838f1-4874-4dea-b396-d318f56ff192","id":1,"poolType":"LVM","host":"10.147.40.25","path":"datastore-11514","port":0}},"name":"shared","size":5368709120,"path":"1d3265f1faa2452e860d13bcd05c9ec7","volumeId":10,"accountId":2,"id":10,"hypervisorType":"VMware"}},"wait":0}}]
> }
> 2013-08-16 19:13:16,492 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-114:null) Seq 1-473956798: Executing request
> 2013-08-16 19:13:16,503 INFO [storage.resource.VmwareStorageProcessor]
> (DirectAgent-114:10.147.40.25) Executing resource DestroyCommand:
> {"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"a35ac140-b3a6-4aa7-a84b-950bf3f51789","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"9c5838f1-4874-4dea-b396-d318f56ff192","id":1,"poolType":"LVM","host":"10.147.40.25","path":"datastore-11514","port":0}},"name":"shared","size":5368709120,"path":"1d3265f1faa2452e860d13bcd05c9ec7","volumeId":10,"accountId":2,"id":10,"hypervisorType":"VMware"}},"wait":0}
> 2013-08-16 19:13:16,625 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) Search file
> 1d3265f1faa2452e860d13bcd05c9ec7.vmdk on [datastore1]
> 2013-08-16 19:13:16,649 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) File [datastore1]
> 1d3265f1faa2452e860d13bcd05c9ec7.vmdk does not exist on datastore
> 2013-08-16 19:13:16,654 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) Search file
> 1d3265f1faa2452e860d13bcd05c9ec7.vmdk on [datastore1]
> 2013-08-16 19:13:16,676 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) File [datastore1]
> 1d3265f1faa2452e860d13bcd05c9ec7.vmdk does not exist on datastore
> 2013-08-16 19:13:16,676 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) Searching file
> 1d3265f1faa2452e860d13bcd05c9ec7.vmdk in [datastore1]
> 2013-08-16 19:13:16,706 WARN [storage.resource.VmwareStorageLayoutHelper]
> (DirectAgent-114:10.147.40.25) Unable to locate VMDK file:
> 1d3265f1faa2452e860d13bcd05c9ec7.vmdk
> 2013-08-16 19:13:16,711 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) Search file
> 1d3265f1faa2452e860d13bcd05c9ec7-flat.vmdk on [datastore1]
> 2013-08-16 19:13:16,733 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) File [datastore1]
> 1d3265f1faa2452e860d13bcd05c9ec7-flat.vmdk does not exist on datastore
> 2013-08-16 19:13:16,737 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) Search file
> 1d3265f1faa2452e860d13bcd05c9ec7-flat.vmdk on [datastore1]
> 2013-08-16 19:13:16,761 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) File [datastore1]
> 1d3265f1faa2452e860d13bcd05c9ec7-flat.vmdk does not exist on datastore
> 2013-08-16 19:13:16,761 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) Searching file
> 1d3265f1faa2452e860d13bcd05c9ec7-flat.vmdk in [datastore1]
> 2013-08-16 19:13:16,790 WARN [storage.resource.VmwareStorageLayoutHelper]
> (DirectAgent-114:10.147.40.25) Unable to locate VMDK file:
> 1d3265f1faa2452e860d13bcd05c9ec7-flat.vmdk
> 2013-08-16 19:13:16,794 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) Search file
> 1d3265f1faa2452e860d13bcd05c9ec7-delta.vmdk on [datastore1]
> 2013-08-16 19:13:16,814 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) File [datastore1]
> 1d3265f1faa2452e860d13bcd05c9ec7-delta.vmdk does not exist on datastore
> 2013-08-16 19:13:16,818 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) Search file
> 1d3265f1faa2452e860d13bcd05c9ec7-delta.vmdk on [datastore1]
> 2013-08-16 19:13:16,841 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) File [datastore1]
> 1d3265f1faa2452e860d13bcd05c9ec7-delta.vmdk does not exist on datastore
> 2013-08-16 19:13:16,842 INFO [vmware.mo.DatastoreMO]
> (DirectAgent-114:10.147.40.25) Searching file
> 1d3265f1faa2452e860d13bcd05c9ec7-delta.vmdk in [datastore1]
> 2013-08-16 19:13:16,867 WARN [storage.resource.VmwareStorageLayoutHelper]
> (DirectAgent-114:10.147.40.25) Unable to locate VMDK file:
> 1d3265f1faa2452e860d13bcd05c9ec7-delta.vmdk
> 2013-08-16 19:13:16,868 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-114:null) Seq 1-473956798: Response Received:
> 2013-08-16 19:13:16,869 DEBUG [agent.transport.Request]
> (DirectAgent-114:null) Seq 1-473956798: Processing: { Ans: , MgmtId:
> 7067804893289, via: 1, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.Answer":{"result":true,"details":"Success","wait":0}}]
> }
> 2013-08-16 19:13:16,869 DEBUG [agent.transport.Request]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Seq
> 1-473956798: Received: { Ans: , MgmtId: 7067804893289, via: 1, Ver: v1,
> Flags: 10, { Answer } }
> 2013-08-16 19:13:16,888 INFO [storage.volume.VolumeServiceImpl]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Volume 10
> is not referred anywhere, remove it from volumes table
> 2013-08-16 19:13:16,902 ERROR [cloud.storage.VolumeManagerImpl]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) migrate
> volume failed:copy volume from primary to secondary failed due to exception:
> Exception: java.lang.NullPointerException
> Message: null
> 2013-08-16 19:13:16,904 DEBUG [cloud.storage.VolumeManagerImpl]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Failed to
> migrate volume:
> com.cloud.exception.StorageUnavailableException: Resource [StoragePool:1] is
> unreachable: migrate volume failed: copy volume from primary to secondary
> failed due to exception: Exception: java.lang.NullPointerException
> Message: null
> at
> com.cloud.storage.VolumeManagerImpl.migrateVolume(VolumeManagerImpl.java:2244)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> com.cloud.storage.VolumeManagerImpl.migrateVolume(VolumeManagerImpl.java:2228)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> org.apache.cloudstack.api.command.user.volume.MigrateVolumeCmd.execute(MigrateVolumeCmd.java:103)
> 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-08-16 19:13:16,908 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-33:job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ]) Complete
> async job-33 = [ 44dc9aa6-1655-4bfd-9252-f96cbc6b55eb ], jobStatus: 2,
> resultCode: 530, result: Error Code: 530 Error text: Failed to migrate volume
> Attaching the MS logs
--
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
