You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Min Chen (JIRA)" <ji...@apache.org> on 2014/02/07 00:57:21 UTC
[jira] [Resolved] (CLOUDSTACK-6046) CreateVolume from snapshot is
failing with S3 as secondary storage and zone-wide primary storage.
[ https://issues.apache.org/jira/browse/CLOUDSTACK-6046?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Min Chen resolved CLOUDSTACK-6046.
----------------------------------
Resolution: Fixed
> CreateVolume from snapshot is failing with S3 as secondary storage and zone-wide primary storage.
> -------------------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-6046
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-6046
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: Storage Controller
> Affects Versions: 4.2.1
> Reporter: Min Chen
> Assignee: Min Chen
> Priority: Critical
> Fix For: 4.3.0
>
>
> 1. Have CS with KVM HV, S3 as secondary storage, zone-wide primary storage.
> 2. Create a VM and create snapshot of root volume.
> 3. Now creatVolume from snapshot taken in stpe2.
> Observation:
> Observed the follwoing exception in MS logs and create volume from snapshot failed:
> 2014-02-03 20:33:07,109 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (catalina-exec-22:ctx-58f7b84e ctx-d6b53517) submit async job-96, details: AsyncJobVO {id:96, userId: 2, accountId: 2, instanceType: Volume, instanceId: 21, cmd: org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd, cmdInfo:
> {"id":"21","response":"json","sessionkey":"48nz1Dz96CYsK87tCQeRSeGmZ2E\u003d","cmdEventType":"VOLUME.CREATE","ctxUserId":"2","snapshotid":"388aeb8c-b9ea-4117-9c20-a8453c546ccc","name":"volsanp","httpmethod":"GET","_":"1391420610122","ctxAccountId":"2","ctxStartEventId":"203"}
> , cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 7494415941730, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-02-03 20:33:07,111 DEBUG [c.c.a.ApiServlet] (catalina-exec-22:ctx-58f7b84e ctx-d6b53517) ===END=== 10.252.192.33 – GET command=createVolume&response=json&sessionkey=48nz1Dz96CYsK87tCQeRSeGmZ2E%3D&snapshotid=388aeb8c-b9ea-4117-9c20-a8453c546ccc&name=volsanp&_=1391420610122
> 2014-02-03 20:33:07,115 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-89:ctx-7e16453b) Add job-96 into job monitoring
> 2014-02-03 20:33:07,116 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-89:ctx-7e16453b) Executing AsyncJobVO {id:96, userId: 2, accountId: 2, instanceType: Volume, instanceId: 21, cmd: org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd, cmdInfo:
> {"id":"21","response":"json","sessionkey":"48nz1Dz96CYsK87tCQeRSeGmZ2E\u003d","cmdEventType":"VOLUME.CREATE","ctxUserId":"2","snapshotid":"388aeb8c-b9ea-4117-9c20-a8453c546ccc","name":"volsanp","httpmethod":"GET","_":"1391420610122","ctxAccountId":"2","ctxStartEventId":"203"}
> , cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, initMsid: 7494415941730, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2014-02-03 20:33:07,156 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) LocalStoragePoolAllocator trying to find storage pool to fit the vm
> 2014-02-03 20:33:07,156 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) ClusterScopeStoragePoolAllocator looking for storage pool
> 2014-02-03 20:33:07,157 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) Looking for pools in dc: 1 pod:1 cluster:null
> 2014-02-03 20:33:07,159 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) Found pools matching tags: []
> 2014-02-03 20:33:07,161 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) No storage pools available for shared volume allocation, returning
> 2014-02-03 20:33:07,161 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) ZoneWideStoragePoolAllocator to find storage pool
> 2014-02-03 20:33:07,170 DEBUG [o.a.c.s.a.ZoneWideStoragePoolAllocator] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) Removing pool Pool[1|NetworkFilesystem] from avoid set, must have been inserted when searching for another disk's tag
> 2014-02-03 20:33:07,177 DEBUG [c.c.s.StorageManagerImpl] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) Checking pool 1 for storage, totalSize: 5902284816384, usedBytes: 3731833782272, usedPct: 0.6322693496445476, disable threshold: 0.85
> 2014-02-03 20:33:07,187 DEBUG [c.c.s.StorageManagerImpl] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) Checking pool: 1 for volume allocation [Vol[21|vm=null|DATADISK]], maxSize : 11804569632768, totalAllocatedSize : 63747532288, askingSize : 8589934592, allocated disable threshold: 0.85
> 2014-02-03 20:33:07,189 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) Found a suitable pool for create volume: 1
> 2014-02-03 20:33:07,197 DEBUG [o.a.c.s.s.SnapshotServiceImpl] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) sync snapshot 3 from cache to object store...
> 2014-02-03 20:33:07,201 DEBUG [o.a.c.s.s.SnapshotServiceImpl] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) sync snapshot 5 from cache to object store...
> 2014-02-03 20:33:07,204 DEBUG [c.c.a.ApiServlet] (catalina-exec-17:ctx-5ad5187e) ===START=== 10.252.192.33 – GET command=queryAsyncJobResult&jobId=11a6136c-aa09-44f9-9a39-1f143a85ab77&response=json&sessionkey=48nz1Dz96CYsK87tCQeRSeGmZ2E%3D&_=1391420610412
> 2014-02-03 20:33:07,210 DEBUG [o.a.c.s.s.SnapshotServiceImpl] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) sync snapshot 7 from cache to object store...
> 2014-02-03 20:33:07,254 DEBUG [c.c.a.ApiServlet] (catalina-exec-17:ctx-5ad5187e ctx-86c17a91) ===END=== 10.252.192.33 – GET command=queryAsyncJobResult&jobId=11a6136c-aa09-44f9-9a39-1f143a85ab77&response=json&sessionkey=48nz1Dz96CYsK87tCQeRSeGmZ2E%3D&_=1391420610412
> 2014-02-03 20:33:07,277 DEBUG [o.a.c.s.m.AncientDataMotionStrategy] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) copyAsync inspecting src type SNAPSHOT copyAsync inspecting dest type VOLUME
> 2014-02-03 20:33:07,292 DEBUG [o.a.c.s.c.m.StorageCacheManagerImpl] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) there is already one in the cache store
> 2014-02-03 20:33:07,323 ERROR [o.a.c.s.m.AncientDataMotionStrategy] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) No remote endpoint to send command, check if host or ssvm is down?
> 2014-02-03 20:33:07,345 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@3cb15a22), no need to delete from object in store ref table
> 2014-02-03 20:33:07,358 WARN [o.a.c.s.d.ObjectInDataStoreManagerImpl] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) Snapshot 3 is not found on image store 3, so no need to delete
> 2014-02-03 20:33:07,358 DEBUG [o.a.c.e.o.VolumeOrchestrator] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) Failed to create volume from snapshot:No remote endpoint to send command, check if host or ssvm is down?
> 2014-02-03 20:33:07,358 DEBUG [c.c.s.VolumeApiServiceImpl] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) Failed to create volume: 21
> com.cloud.utils.exception.CloudRuntimeException: Failed to create volume from snapshot:No remote endpoint to send command, check if host or ssvm is down?
> at org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.createVolumeFromSnapshot(VolumeOrchestrator.java:374)
> at com.cloud.storage.VolumeApiServiceImpl.createVolumeFromSnapshot(VolumeApiServiceImpl.java:785)
> at com.cloud.storage.VolumeApiServiceImpl.createVolume(VolumeApiServiceImpl.java:735)
> at com.cloud.storage.VolumeApiServiceImpl.createVolume(VolumeApiServiceImpl.java:177)
> 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.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
> at com.cloud.event.ActionEventInterceptor.invoke(ActionEventInterceptor.java:50)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
> at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
> at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
> at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
> at $Proxy213.createVolume(Unknown Source)
> at org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd.execute(CreateVolumeCmd.java:196)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:161)
> at com.cloud.api.ApiAsyncJobDispatcher.runJobInContext(ApiAsyncJobDispatcher.java:109)
> at com.cloud.api.ApiAsyncJobDispatcher$1.run(ApiAsyncJobDispatcher.java:66)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:63)
> at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:509)
> at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
> at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
> at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
> 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)
> 2014-02-03 20:33:07,372 DEBUG [c.c.u.AccountManagerImpl] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) Access granted to Acct[4b600840-8cc2-11e3-bb5b-06d0ee000062-admin] to Domain:1/ by AffinityGroupAccessChecker
> 2014-02-03 20:33:07,378 INFO [c.c.r.ResourceLimitManagerImpl] (Job-Executor-89:ctx-7e16453b ctx-d6b53517) Discrepency in the resource count (original count=70869057536 correct count = 62279122944) for type primary_storage for account ID 2 is fixed during resource count recalculation.
> 2014-02-03 20:33:07,405 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-89:ctx-7e16453b) Complete async job-96, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/
> {"uuidList":[],"errorcode":530,"errortext":"Failed to create a volume"}
> 2014-02-03 20:33:07,430 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Executor-89:ctx-7e16453b) Done executing org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd for job-96
--
This message was sent by Atlassian JIRA
(v6.1.5#6160)