Sanjeev N created CLOUDSTACK-4106:
-------------------------------------
Summary: [Object_Store_Refactor] Volume creation from the snapshot
fails with error Unable to find snapshot OVA file
Key: CLOUDSTACK-4106
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4106
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Storage Controller, VMware, Volumes
Affects Versions: 4.2.0
Environment: Latest build from ACS 4.2 branch
Storage: S3 for secondary storage and ISCSI for primary
Reporter: Sanjeev N
Priority: Blocker
Fix For: 4.2.0
Volume creation from the snapshot fails with error Unable to find snapshot OVA
file
Steps to Reproduce:
================
1.Bring up CS with VMWare cluster using S3 for the secondary storage, ISCSI for
primary and NFS for staging starge.
2.Deploy guest vm with default cent os template
3.Take snapshot from the root disk of the vm
4.Try to create volume from the snapshot
Result:
======
1.Failed to create volume from the snapshot.
2.An entry was made in volumes table with state Allocated. Upon failure entry
should also be deleted from volumes table.
Following is the log snippet during volume creation:
=======================================
2013-08-06 06:05:03,445 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-11:null) submit async job-17 = [
79ca534e-19b6-4a05-8fc6-537611a0cb1b ], details: AsyncJobVO {id:17, userId: 2,
accountId: 2, sessionKey: null, instanceType: Volume, instanceId: 9, cmd:
org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd, cmdOriginator:
null, cmdInfo:
{"id":"9","response":"json","sessionkey":"foQa9K4dPmYo8uEiAcolaTVR6yI\u003d","cmdEventType":"VOLUME.CREATE","ctxUserId":"2","snapshotid":"621251e4-3d40-4f86-b35c-b6b4008f3639","name":"fromSnap","httpmethod":"GET","_":"1375783491630","ctxAccountId":"2","ctxStartEventId":"68"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
processStatus: 0, resultCode: 0, result: null, initMsid: 6615759585382,
completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
2013-08-06 06:05:03,448 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null)
===END=== 10.146.0.20 -- GET
command=createVolume&response=json&sessionkey=foQa9K4dPmYo8uEiAcolaTVR6yI%3D&snapshotid=621251e4-3d40-4f86-b35c-b6b4008f3639&name=fromSnap&_=1375783491630
2013-08-06 06:05:03,450 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-18:job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Executing
org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd for job-17 = [
79ca534e-19b6-4a05-8fc6-537611a0cb1b ]
2013-08-06 06:05:03,480 DEBUG [storage.allocator.LocalStoragePoolAllocator]
(Job-Executor-18:job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ])
LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-08-06 06:05:03,480 DEBUG
[storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-18:job-17 =
[ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) ClusterScopeStoragePoolAllocator
looking for storage pool
2013-08-06 06:05:03,480 DEBUG
[storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-18:job-17 =
[ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Looking for pools in dc: 1 pod:1
cluster:null
2013-08-06 06:05:03,486 DEBUG [storage.allocator.AbstractStoragePoolAllocator]
(Job-Executor-18:job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Checking if
storage pool is suitable, name: null ,poolId: 1
2013-08-06 06:05:03,493 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-18:job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Checking
pool 1 for storage, totalSize: 93952409600, usedBytes: 4602200064, usedPct:
0.048984375, disable threshold: 0.85
2013-08-06 06:05:03,513 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-18:job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Checking
pool: 1 for volume allocation [Vol[9|vm=null|DATADISK]], maxSize : 93952409600,
totalAllocatedSize : 1769926656, askingSize : 459320832, allocated disable
threshold: 0.85
2013-08-06 06:05:03,513 DEBUG
[storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-18:job-17 =
[ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) FirstFitStoragePoolAllocator
returning 1 suitable storage pools
2013-08-06 06:05:03,517 DEBUG [allocator.impl.UserConcentratedAllocator]
(Job-Executor-18:job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) There are
no pods with enough memory/CPU capacity in zone Adv-vmware
2013-08-06 06:05:03,556 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-18:job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) copyAsync
inspecting src type SNAPSHOT copyAsync inspecting dest type VOLUME
2013-08-06 06:05:03,585 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-18:job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) copyAsync
inspecting src type SNAPSHOT copyAsync inspecting dest type SNAPSHOT
2013-08-06 06:05:03,677 DEBUG [agent.transport.Request] (Job-Executor-18:job-17
= [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Seq 3-1317535761: Sending { Cmd ,
MgmtId: 6615759585382, via: 3, Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/6/a11be62f-4879-494d-85b3-9bf93ba7fee0.ova","volume":{"uuid":"1a9b0706-cab8-4fb8-9b9b-330efe44c18c","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b845e7d4-562a-3b2d-8e59-b1df565f99e5","id":1,"poolType":"VMFS","host":"VMFS
datastore:
/sanjeev/openFiler","path":"/sanjeev/openFiler","port":0}},"name":"ROOT-6","size":459320832,"path":"ROOT-6","volumeId":6,"vmName":"i-2-6-VM","accountId":2,"format":"OVA","id":6,"hypervisorType":"VMware"},"dataStore":{"com.cloud.agent.api.to.S3TO":{"id":7,"uuid":"575684ac-a5df-4eab-821a-2b7dd214fb86","endPoint":"10.147.29.57:8080","bucketName":"imagestore","httpsFlag":false,"connectionTimeout":500000,"maxErrorRetry":2,"socketTimeout":500000,"created":"Aug
6, 2013 4:56:09
AM","enableRRS":false}},"vmName":"i-2-6-VM","name":"vm1_ROOT-6_20130806095732","hypervisorType":"VMware","id":1}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/6","volume":{"uuid":"1a9b0706-cab8-4fb8-9b9b-330efe44c18c","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b845e7d4-562a-3b2d-8e59-b1df565f99e5","id":1,"poolType":"VMFS","host":"VMFS
datastore:
/sanjeev/openFiler","path":"/sanjeev/openFiler","port":0}},"name":"ROOT-6","size":459320832,"path":"ROOT-6","volumeId":6,"vmName":"i-2-6-VM","accountId":2,"format":"OVA","id":6,"hypervisorType":"VMware"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_esx_os","_role":"ImageCache"}},"vmName":"i-2-6-VM","name":"vm1_ROOT-6_20130806095732","hypervisorType":"VMware","id":1}},"executeInSequence":false,"wait":21600}}]
}
2013-08-06 06:05:43,912 DEBUG [agent.transport.Request]
(AgentManager-Handler-7:null) Seq 3-1317535761: Processing: { Ans: , MgmtId:
6615759585382, via: 3, Ver: v1, Flags: 10,
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/6/a11be62f-4879-494d-85b3-9bf93ba7fee0.ova","id":0}},"result":true,"wait":0}}]
}
2013-08-06 06:05:43,912 DEBUG [agent.transport.Request] (Job-Executor-18:job-17
= [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Seq 3-1317535761: Received: { Ans:
, MgmtId: 6615759585382, via: 3, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2013-08-06 06:05:44,082 DEBUG [agent.transport.Request] (Job-Executor-18:job-17
= [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Seq 3-1317535762: Sending { Cmd ,
MgmtId: 6615759585382, via: 3, Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/6/a11be62f-4879-494d-85b3-9bf93ba7fee0.ova","volume":{"uuid":"1a9b0706-cab8-4fb8-9b9b-330efe44c18c","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b845e7d4-562a-3b2d-8e59-b1df565f99e5","id":1,"poolType":"VMFS","host":"VMFS
datastore:
/sanjeev/openFiler","path":"/sanjeev/openFiler","port":0}},"name":"ROOT-6","size":459320832,"path":"ROOT-6","volumeId":6,"vmName":"i-2-6-VM","accountId":2,"format":"OVA","id":6,"hypervisorType":"VMware"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_esx_os","_role":"ImageCache"}},"vmName":"i-2-6-VM","name":"vm1_ROOT-6_20130806095732","hypervisorType":"VMware","id":1}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"5ccce35d-c8fa-4ad8-8884-1adc12f58e28","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b845e7d4-562a-3b2d-8e59-b1df565f99e5","id":1,"poolType":"VMFS","host":"VMFS
datastore:
/sanjeev/openFiler","path":"/sanjeev/openFiler","port":0}},"name":"fromSnap","size":459320832,"volumeId":9,"accountId":2,"format":"OVA","id":9,"hypervisorType":"None"}},"executeInSequence":false,"wait":10800}}]
}
2013-08-06 06:05:44,579 DEBUG [agent.transport.Request]
(AgentManager-Handler-8:null) Seq 3-1317535762: Processing: { Ans: , MgmtId:
6615759585382, via: 3, Ver: v1, Flags: 10,
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"CreateVolumeFromSnapshotCommand
exception: java.lang.Exception: Unable to find snapshot OVA file at:
/mnt/SecStorage/21ac712e-6690-39a2-9c7b-cc3d5108db5f/snapshots/2/6/a11be62f-4879-494d-85b3-9bf93ba7fee0.ova.ova","wait":0}}]
}
2013-08-06 06:05:44,581 DEBUG [agent.transport.Request] (Job-Executor-18:job-17
= [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Seq 3-1317535762: Received: { Ans:
, MgmtId: 6615759585382, via: 3, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2013-08-06 06:05:44,600 DEBUG [storage.image.BaseImageStoreDriverImpl]
(Job-Executor-18:job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Unable to
destoy SNAPSHOT: 1
com.cloud.utils.exception.CloudRuntimeException: not implemented yet
at
org.apache.cloudstack.storage.endpoint.DefaultEndPointSelector.select(DefaultEndPointSelector.java:231)
at
org.apache.cloudstack.storage.endpoint.DefaultEndPointSelector.select(DefaultEndPointSelector.java:217)
at
org.apache.cloudstack.storage.image.BaseImageStoreDriverImpl.deleteAsync(BaseImageStoreDriverImpl.java:238)
at
org.apache.cloudstack.storage.image.store.ImageStoreImpl.delete(ImageStoreImpl.java:148)
at
org.apache.cloudstack.storage.cache.manager.StorageCacheManagerImpl.deleteCacheObject(StorageCacheManagerImpl.java:258)
at
org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.deleteSnapshotCacheChain(AncientDataMotionStrategy.java:229)
at
org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyVolumeFromSnapshot(AncientDataMotionStrategy.java:261)
at
org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:369)
at
org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:55)
at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromSnapshot(VolumeServiceImpl.java:572)
at
com.cloud.storage.VolumeManagerImpl.createVolumeFromSnapshot(VolumeManagerImpl.java:553)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
com.cloud.storage.VolumeManagerImpl.createVolumeFromSnapshot(VolumeManagerImpl.java:603)
at
com.cloud.storage.VolumeManagerImpl.createVolume(VolumeManagerImpl.java:1047)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
com.cloud.storage.VolumeManagerImpl.createVolume(VolumeManagerImpl.java:183)
at
org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd.execute(CreateVolumeCmd.java:189)
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-06 06:05:44,620 WARN [storage.datastore.ObjectInDataStoreManagerImpl]
(Job-Executor-18:job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Unsupported
data object (VOLUME,
org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@3c8f4b49)
2013-08-06 06:05:44,633 DEBUG [cloud.storage.VolumeManagerImpl]
(Job-Executor-18:job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Failed to
create volume from snapshot:CreateVolumeFromSnapshotCommand exception:
java.lang.Exception: Unable to find snapshot OVA file at:
/mnt/SecStorage/21ac712e-6690-39a2-9c7b-cc3d5108db5f/snapshots/2/6/a11be62f-4879-494d-85b3-9bf93ba7fee0.ova.ova
2013-08-06 06:05:44,633 DEBUG [cloud.storage.VolumeManagerImpl]
(Job-Executor-18:job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Failed to
create volume: 9
com.cloud.utils.exception.CloudRuntimeException: Failed to create volume from
snapshot:CreateVolumeFromSnapshotCommand exception: java.lang.Exception: Unable
to find snapshot OVA file at:
/mnt/SecStorage/21ac712e-6690-39a2-9c7b-cc3d5108db5f/snapshots/2/6/a11be62f-4879-494d-85b3-9bf93ba7fee0.ova.ova
at
com.cloud.storage.VolumeManagerImpl.createVolumeFromSnapshot(VolumeManagerImpl.java:558)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
com.cloud.storage.VolumeManagerImpl.createVolumeFromSnapshot(VolumeManagerImpl.java:603)
at
com.cloud.storage.VolumeManagerImpl.createVolume(VolumeManagerImpl.java:1047)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
com.cloud.storage.VolumeManagerImpl.createVolume(VolumeManagerImpl.java:183)
at
org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd.execute(CreateVolumeCmd.java:189)
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-06 06:05:44,661 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-18:job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ]) Complete
async job-17 = [ 79ca534e-19b6-4a05-8fc6-537611a0cb1b ], jobStatus: 2,
resultCode: 530, result: Error Code: 530 Error text: Failed to create a volume
--
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
