[
https://issues.apache.org/jira/browse/CLOUDSTACK-4106?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Sanjeev N reopened CLOUDSTACK-4106:
-----------------------------------
Volume creation from the snapshot is still failing with the latest build. As a
result of this failure DeleteCommand is getting executed and deleting the
snapshot from S3 and from snapshot_store_ref table.
Here is the log snippet :
2013-08-09 01:53:05,152 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-10:null) submit async job-56 = [
8837d16a-bced-4a75-863f-e65b8a1f99a0 ], details: AsyncJobVO {id:56, userId: 2,
accountId: 2, sessionKey: null, instanceType: Volume, instanceId: 23, cmd:
org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd, cmdOriginator:
null, cmdInfo:
{"id":"23","response":"json","sessionkey":"KRUhaR3yBjHqW5ijalRTOluCvJI\u003d","cmdEventType":"VOLUME.CREATE","ctxUserId":"2","snapshotid":"3eb60ca1-4026-4e7d-9e2b-81bef64ee985","name":"CS-4106","httpmethod":"GET","_":"1376027584956","ctxAccountId":"2","ctxStartEventId":"234"},
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-09 01:53:05,155 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null)
===END=== 10.146.0.20 -- GET
command=createVolume&response=json&sessionkey=KRUhaR3yBjHqW5ijalRTOluCvJI%3D&snapshotid=3eb60ca1-4026-4e7d-9e2b-81bef64ee985&name=CS-4106&_=1376027584956
2013-08-09 01:53:05,159 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Executing
org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd for job-56 = [
8837d16a-bced-4a75-863f-e65b8a1f99a0 ]
2013-08-09 01:53:05,195 DEBUG [storage.allocator.LocalStoragePoolAllocator]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ])
LocalStoragePoolAllocator trying to find storage pool to fit the vm
2013-08-09 01:53:05,195 DEBUG
[storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-57:job-56 =
[ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) ClusterScopeStoragePoolAllocator
looking for storage pool
2013-08-09 01:53:05,195 DEBUG
[storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-57:job-56 =
[ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Looking for pools in dc: 3 pod:3
cluster:null
2013-08-09 01:53:05,201 DEBUG [storage.allocator.AbstractStoragePoolAllocator]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Checking if
storage pool is suitable, name: null ,poolId: 4
2013-08-09 01:53:05,207 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Checking
pool 4 for storage, totalSize: 93952409600, usedBytes: 7689207808, usedPct:
0.08184151785714286, disable threshold: 0.85
2013-08-09 01:53:05,227 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Checking
pool: 4 for volume allocation [Vol[23|vm=null|DATADISK]], maxSize :
93952409600, totalAllocatedSize : 2972329984, askingSize : 459320832, allocated
disable threshold: 0.85
2013-08-09 01:53:05,227 DEBUG
[storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-57:job-56 =
[ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) FirstFitStoragePoolAllocator
returning 1 suitable storage pools
2013-08-09 01:53:05,231 DEBUG [allocator.impl.UserConcentratedAllocator]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) There are
no pods with enough memory/CPU capacity in zone Adv-vmware
2013-08-09 01:53:05,269 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) copyAsync
inspecting src type SNAPSHOT copyAsync inspecting dest type VOLUME
2013-08-09 01:53:05,299 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) copyAsync
inspecting src type SNAPSHOT copyAsync inspecting dest type SNAPSHOT
2013-08-09 01:53:05,389 DEBUG [agent.transport.Request] (Job-Executor-57:job-56
= [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Seq 7-983236627: Sending { Cmd ,
MgmtId: 6615759585382, via: 7, Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/19/a259fb83-f819-4215-9efd-37dfef7adc65.ova","volume":{"uuid":"b08d99ed-304e-40d6-a846-12379f277ddb","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b845e7d4-562a-3b2d-8e59-b1df565f99e5","id":4,"poolType":"VMFS","host":"VMFS
datastore:
/sanjeev/openFiler","path":"/sanjeev/openFiler","port":0}},"name":"ROOT-16","size":459320832,"path":"ROOT-16","volumeId":19,"vmName":"i-2-16-VM","accountId":2,"format":"OVA","id":19,"hypervisorType":"VMware"},"dataStore":{"com.cloud.agent.api.to.S3TO":{"id":6,"uuid":"4f8c91be-94ce-4e44-a05d-f08584f1d56d","endPoint":"10.147.29.56:8080","bucketName":"imagestore","httpsFlag":false,"created":"Aug
8, 2013 6:25:36
AM","enableRRS":false}},"vmName":"i-2-16-VM","name":"vm1-def_ROOT-16_20130808134707","hypervisorType":"VMware","id":1}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/19","volume":{"uuid":"b08d99ed-304e-40d6-a846-12379f277ddb","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b845e7d4-562a-3b2d-8e59-b1df565f99e5","id":4,"poolType":"VMFS","host":"VMFS
datastore:
/sanjeev/openFiler","path":"/sanjeev/openFiler","port":0}},"name":"ROOT-16","size":459320832,"path":"ROOT-16","volumeId":19,"vmName":"i-2-16-VM","accountId":2,"format":"OVA","id":19,"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-16-VM","name":"vm1-def_ROOT-16_20130808134707","hypervisorType":"VMware","id":1}},"executeInSequence":false,"wait":21600}}]
}
2013-08-09 01:53:41,392 DEBUG [agent.transport.Request]
(AgentManager-Handler-4:null) Seq 7-983236627: Processing: { Ans: , MgmtId:
6615759585382, via: 7, Ver: v1, Flags: 10,
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/19/a259fb83-f819-4215-9efd-37dfef7adc65.ova","id":0}},"result":true,"wait":0}}]
}
2013-08-09 01:53:41,393 DEBUG [agent.transport.Request] (Job-Executor-57:job-56
= [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Seq 7-983236627: Received: { Ans:
, MgmtId: 6615759585382, via: 7, Ver: v1, Flags: 10, { CopyCmdAnswer } }
2013-08-09 01:53:41,413 DEBUG [storage.snapshot.SnapshotObject]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Failed to
update state:com.cloud.utils.fsm.NoTransitionException: Unable to transition to
a new state from Allocated via OperationSuccessed
2013-08-09 01:53:41,413 ERROR [storage.motion.AncientDataMotionStrategy]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Failed to
create volume from vm1-def_ROOT-16_20130808134707 on pool
org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@617e1437
com.cloud.utils.exception.CloudRuntimeException: Failed to update state:
com.cloud.utils.fsm.NoTransitionException: Unable to transition to a new state
from Allocated via OperationSuccessed
at
org.apache.cloudstack.storage.snapshot.SnapshotObject.processEvent(SnapshotObject.java:160)
at
org.apache.cloudstack.storage.snapshot.SnapshotObject.processEvent(SnapshotObject.java:274)
at
org.apache.cloudstack.storage.cache.manager.StorageCacheManagerImpl.createCacheObject(StorageCacheManagerImpl.java:212)
at
org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.cacheSnapshotChain(AncientDataMotionStrategy.java:218)
at
org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyVolumeFromSnapshot(AncientDataMotionStrategy.java:244)
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-09 01:53:41,444 DEBUG [agent.transport.Request] (Job-Executor-57:job-56
= [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Seq 4-629801009: Sending { Cmd ,
MgmtId: 6615759585382, via: 4, Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/19/a259fb83-f819-4215-9efd-37dfef7adc65.ova","volume":{"uuid":"b08d99ed-304e-40d6-a846-12379f277ddb","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b845e7d4-562a-3b2d-8e59-b1df565f99e5","id":4,"poolType":"VMFS","host":"VMFS
datastore:
/sanjeev/openFiler","path":"/sanjeev/openFiler","port":0}},"name":"ROOT-16","size":459320832,"path":"ROOT-16","volumeId":19,"vmName":"i-2-16-VM","accountId":2,"format":"OVA","id":19,"hypervisorType":"VMware"},"dataStore":{"com.cloud.agent.api.to.S3TO":{"id":6,"uuid":"4f8c91be-94ce-4e44-a05d-f08584f1d56d","endPoint":"10.147.29.56:8080","bucketName":"imagestore","httpsFlag":false,"created":"Aug
8, 2013 6:25:36
AM","enableRRS":false}},"vmName":"i-2-16-VM","name":"vm1-def_ROOT-16_20130808134707","hypervisorType":"VMware","id":1}},"wait":0}}]
}
2013-08-09 01:53:41,494 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null)
===START=== 10.146.0.20 -- GET
command=queryAsyncJobResult&jobId=8837d16a-bced-4a75-863f-e65b8a1f99a0&response=json&sessionkey=KRUhaR3yBjHqW5ijalRTOluCvJI%3D&_=1376027621535
2013-08-09 01:53:41,520 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:null)
===END=== 10.146.0.20 -- GET
command=queryAsyncJobResult&jobId=8837d16a-bced-4a75-863f-e65b8a1f99a0&response=json&sessionkey=KRUhaR3yBjHqW5ijalRTOluCvJI%3D&_=1376027621535
2013-08-09 01:53:41,730 DEBUG [agent.transport.Request]
(AgentManager-Handler-9:null) Seq 4-629801009: Processing: { Ans: , MgmtId:
6615759585382, via: 4, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.Answer":{"result":true,"details":"Deleted snapshot %s
from bucket imagestore.","wait":0}}] }
2013-08-09 01:53:41,731 DEBUG [agent.transport.Request] (Job-Executor-57:job-56
= [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Seq 4-629801009: Received: { Ans:
, MgmtId: 6615759585382, via: 4, Ver: v1, Flags: 10, { Answer } }
2013-08-09 01:53:41,740 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) copy failed
com.cloud.utils.exception.CloudRuntimeException: Failed to create volume from
vm1-def_ROOT-16_20130808134707 on pool
org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@617e1437
at
org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyVolumeFromSnapshot(AncientDataMotionStrategy.java:258)
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-09 01:53:41,750 WARN [storage.datastore.ObjectInDataStoreManagerImpl]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Unsupported
data object (VOLUME,
org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@617e1437), no need
to delete from object in store ref table
2013-08-09 01:53:41,752 DEBUG [storage.snapshot.SnapshotObject]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Failed to
update state:com.cloud.utils.exception.CloudRuntimeException: can't find
mapping in ObjectInDataStore table for:
org.apache.cloudstack.storage.snapshot.SnapshotObject@63eedc25
2013-08-09 01:53:41,753 WARN [storage.datastore.ObjectInDataStoreManagerImpl]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Snapshot 1
is not found on image store 6, so no need to delete
2013-08-09 01:53:41,754 DEBUG [storage.volume.VolumeServiceImpl]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) create
volume from snapshot failed
2013-08-09 01:53:41,754 DEBUG [storage.volume.VolumeServiceImpl]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) create
volume from snapshot failed
com.cloud.utils.exception.CloudRuntimeException: Failed to update state:
com.cloud.utils.exception.CloudRuntimeException: can't find mapping in
ObjectInDataStore table for:
org.apache.cloudstack.storage.snapshot.SnapshotObject@63eedc25
at
org.apache.cloudstack.storage.snapshot.SnapshotObject.processEvent(SnapshotObject.java:160)
at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromSnapshotCallback(VolumeServiceImpl.java:604)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at
org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.dispatch(AsyncCallbackDispatcher.java:142)
at
org.apache.cloudstack.framework.async.InplaceAsyncCallbackDriver.performCompletionCallback(InplaceAsyncCallbackDriver.java:26)
at
org.apache.cloudstack.framework.async.AsyncCallbackDispatcher.complete(AsyncCallbackDispatcher.java:120)
at
org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:398)
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-09 01:53:41,755 DEBUG [cloud.storage.VolumeManagerImpl]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Failed to
create volume from snapshot:com.cloud.utils.exception.CloudRuntimeException:
Failed to update state: com.cloud.utils.exception.CloudRuntimeException: can't
find mapping in ObjectInDataStore table for:
org.apache.cloudstack.storage.snapshot.SnapshotObject@63eedc25
2013-08-09 01:53:41,755 DEBUG [cloud.storage.VolumeManagerImpl]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Failed to
create volume: 23
com.cloud.utils.exception.CloudRuntimeException: Failed to create volume from
snapshot:com.cloud.utils.exception.CloudRuntimeException: Failed to update
state: com.cloud.utils.exception.CloudRuntimeException: can't find mapping in
ObjectInDataStore table for:
org.apache.cloudstack.storage.snapshot.SnapshotObject@63eedc25
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-09 01:53:41,784 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-57:job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ]) Complete
async job-56 = [ 8837d16a-bced-4a75-863f-e65b8a1f99a0 ], jobStatus: 2,
resultCode: 530, result: Error Code: 530 Error text: Failed to create a volume
> [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
> Assignee: edison su
> Priority: Blocker
> Fix For: 4.2.0
>
> Attachments: cloud.dmp, management-server.rar
>
>
> 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
