manasaveloori created CLOUDSTACK-4363:
-----------------------------------------
Summary: [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
Priority: Critical
Fix For: 4.2.0
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
