[
https://issues.apache.org/jira/browse/CLOUDSTACK-8014?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14235534#comment-14235534
]
France commented on CLOUDSTACK-8014:
------------------------------------
Compute offering which was used to create this root volume has storage tag:
HAiscsi2.
Root disk currently resides on s2iscsi which has storage tag: HAiscsi2.
Snapshot is currently residing on one of the secondary NFS storages, which are
without tags.
Related SQL querry (SELECT id,tag FROM cloud.storage_pool_view;) for storage
IDs and tags returns:
'206','HAiscsi'
'207','HAiscsi'
'208','HAiscsi2'
'209','HAiscsi2'
'210','nonHAnfs'
Those IDs are probably the ones used in the log.
> Failed to create a volume from snapshot - Discrepency in the resource count ?
> -----------------------------------------------------------------------------
>
> Key: CLOUDSTACK-8014
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-8014
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Management Server
> Affects Versions: 4.3.1
> Reporter: France
>
> As sent to mailing list:
> Hi all.
> We are on XS 6.0.2+Hotfixes and CS 4.3.1.
> (All errors we are getting nowadays have come up only after upgrade from
> 4.1.1, 4.1.1 worked perfectly.)
> After successfully creating s snapshot, I want to create a volume from it, so
> it can be downloaded offsite.
> After clicking “Create volume” I get an error Failed to create a volume.
> If i got to list of volumes, there is a volume with name as defined, but
> Status is empty, and only buttons for attach and destroy exist.
> I have taken a look at catalina.out and management-server.log. Here is the
> log detailing a failure.
> Can you see the problem? How should I fix it? Please advise me.
> Should I create a bug report?
> I have also manually checked space on all storages and it seems there is LOTS
> of free space. Resources based on CS Web GUI are:
> Primary Storage Allocated 15%
> Secondary Storage 5%
> 2014-12-03 12:20:42,493 DEBUG [c.c.c.ConsoleProxyManagerImpl]
> (consoleproxy-1:ctx-2d51baa2) Zone 1 is ready to launch console proxy
> 2014-12-03 12:20:42,580 DEBUG [c.c.s.s.SecondaryStorageManagerImpl]
> (secstorage-1:ctx-53354d18) Zone 1 is ready to launch secondary storage VM
> 2014-12-03 12:20:42,894 DEBUG [c.c.a.ApiServlet]
> (http-6443-exec-108:ctx-a228ce49) ===START=== 111.client.ip.111 -- GET
> command=listZones&available=true&response=json&sessionkey=CENSORED%3D&_=1417605814964
> 2014-12-03 12:20:42,909 DEBUG [c.c.a.ApiServlet]
> (http-6443-exec-108:ctx-a228ce49 ctx-74e696ca) ===END=== 111.client.ip.111 --
> GET
> command=listZones&available=true&response=json&sessionkey=CENSORED%3D&_=1417605814964
> 2014-12-03 12:20:46,482 DEBUG [c.c.a.ApiServlet]
> (http-6443-exec-107:ctx-4a28e57c) ===START=== 111.client.ip.111 -- GET
> command=createVolume&response=json&sessionkey=CENSORED%3D&snapshotid=49e4bba9-844d-4b7b-aca2-95a318f17dc4&name=testbrisi567&_=1417605818552
> 2014-12-03 12:20:46,490 DEBUG [c.c.u.AccountManagerImpl]
> (http-6443-exec-107:ctx-4a28e57c ctx-d7a11540) Access to
> Acct[7d6da3bc-0d70-44eb-8a70-422e4eea184e-userName] granted to
> Acct[7d6da3bc-0d70-44eb-8a70-422e4eea184e-userName] by DomainChecker
> 2014-12-03 12:20:46,494 DEBUG [c.c.u.AccountManagerImpl]
> (http-6443-exec-107:ctx-4a28e57c ctx-d7a11540) Access to
> Acct[7d6da3bc-0d70-44eb-8a70-422e4eea184e-userName] granted to
> Acct[7d6da3bc-0d70-44eb-8a70-422e4eea184e-userName] by DomainChecker
> 2014-12-03 12:20:46,507 DEBUG [c.c.u.AccountManagerImpl]
> (http-6443-exec-107:ctx-4a28e57c ctx-d7a11540) Access to
> com.cloud.storage.SnapshotVO$$EnhancerByCGLIB$$3490cea0@60c95391 granted to
> Acct[7d6da3bc-0d70-44eb-8a70-422e4eea184e-userName] by DomainChecker
> 2014-12-03 12:20:46,571 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (Job-Executor-166:ctx-d915e890) Add job-2804 into job monitoring
> 2014-12-03 12:20:46,571 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Job-Executor-166:ctx-d915e890) Executing AsyncJobVO {id:2804, userId: 59,
> accountId: 60, instanceType: Volume, instanceId: 617, cmd:
> org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd, cmdInfo:
> {"id":"617","response":"json","sessionkey":"CENSORED\u003d","cmdEventType":"VOLUME.CREATE","ctxUserId":"59","snapshotid":"49e4bba9-844d-4b7b-aca2-95a318f17dc4","name":"testbrisi567","httpmethod":"GET","_":"1417605818552","ctxAccountId":"60","ctxStartEventId":"62488"},
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
> null, initMsid: 95545481387, completeMsid: null, lastUpdated: null,
> lastPolled: null, created: null}
> 2014-12-03 12:20:46,577 DEBUG [c.c.u.AccountManagerImpl]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) Access to
> Acct[7d6da3bc-0d70-44eb-8a70-422e4eea184e-userName] granted to
> Acct[7d6da3bc-0d70-44eb-8a70-422e4eea184e-userName] by DomainChecker
> 2014-12-03 12:20:46,578 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (http-6443-exec-107:ctx-4a28e57c ctx-d7a11540) submit async job-2804,
> details: AsyncJobVO {id:2804, userId: 59, accountId: 60, instanceType:
> Volume, instanceId: 617, cmd:
> org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd, cmdInfo:
> {"id":"617","response":"json","sessionkey":"CENSORED\u003d","cmdEventType":"VOLUME.CREATE","ctxUserId":"59","snapshotid":"49e4bba9-844d-4b7b-aca2-95a318f17dc4","name":"testbrisi567","httpmethod":"GET","_":"1417605818552","ctxAccountId":"60","ctxStartEventId":"62488"},
> cmdVersion: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result:
> null, initMsid: 95545481387, completeMsid: null, lastUpdated: null,
> lastPolled: null, created: null}
> 2014-12-03 12:20:46,580 DEBUG [c.c.a.ApiServlet]
> (http-6443-exec-107:ctx-4a28e57c ctx-d7a11540) ===END=== 111.client.ip.111 --
> GET
> command=createVolume&response=json&sessionkey=CENSORED%3D&snapshotid=49e4bba9-844d-4b7b-aca2-95a318f17dc4&name=testbrisi567&_=1417605818552
> 2014-12-03 12:20:46,608 DEBUG [o.a.c.s.a.LocalStoragePoolAllocator]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) LocalStoragePoolAllocator trying
> to find storage pool to fit the vm
> 2014-12-03 12:20:46,608 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) ClusterScopeStoragePoolAllocator
> looking for storage pool
> 2014-12-03 12:20:46,608 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) Looking for pools in dc: 1
> pod:1 cluster:null having tags:[HAiscsi2]
> 2014-12-03 12:20:46,610 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) Found pools matching tags:
> [Pool[208|IscsiLUN], Pool[209|IscsiLUN]]
> 2014-12-03 12:20:46,612 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) Adding pool Pool[206|IscsiLUN]
> to avoid set since it did not match tags
> 2014-12-03 12:20:46,612 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) Adding pool Pool[207|IscsiLUN]
> to avoid set since it did not match tags
> 2014-12-03 12:20:46,612 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) Adding pool
> Pool[210|NetworkFilesystem] to avoid set since it did not match tags
> 2014-12-03 12:20:46,612 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) Removing pool Pool[208|IscsiLUN]
> from avoid set, must have been inserted when searching for another disk's tag
> 2014-12-03 12:20:46,612 DEBUG [o.a.c.s.a.ClusterScopeStoragePoolAllocator]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) Removing pool Pool[209|IscsiLUN]
> from avoid set, must have been inserted when searching for another disk's tag
> 2014-12-03 12:20:46,614 DEBUG [o.a.c.s.a.AbstractStoragePoolAllocator]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) Checking if storage pool is
> suitable, name: null ,poolId: 208
> 2014-12-03 12:20:46,617 DEBUG [c.c.s.StorageManagerImpl]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) Checking pool 208 for storage,
> totalSize: 1520242262016, usedBytes: 865985363968, usedPct:
> 0.569636422828828, disable threshold: 0.95
> 2014-12-03 12:20:46,622 DEBUG [c.c.s.VolumeApiServiceImpl]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) Failed to create volume: 617
> java.lang.NullPointerException
> at
> com.cloud.storage.StorageManagerImpl.storagePoolHasEnoughSpace(StorageManagerImpl.java:1570)
> at
> org.apache.cloudstack.storage.allocator.AbstractStoragePoolAllocator.filter(AbstractStoragePoolAllocator.java:199)
> at
> org.apache.cloudstack.storage.allocator.ClusterScopeStoragePoolAllocator.select(ClusterScopeStoragePoolAllocator.java:110)
> at
> org.apache.cloudstack.storage.allocator.AbstractStoragePoolAllocator.allocateToPool(AbstractStoragePoolAllocator.java:109)
> at
> org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.findStoragePool(VolumeOrchestrator.java:256)
> at
> org.apache.cloudstack.engine.orchestration.VolumeOrchestrator.createVolumeFromSnapshot(VolumeOrchestrator.java:339)
> 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:622)
> 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 com.sun.proxy.$Proxy196.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:1146)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:701)
> 2014-12-03 12:20:46,631 DEBUG [c.c.u.AccountManagerImpl]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) Access granted to
> Acct[7d6da3bc-0d70-44eb-8a70-422e4eea184e-userName] to Domain:10/public/ by
> AffinityGroupAccessChecker
> 2014-12-03 12:20:46,635 INFO [c.c.r.ResourceLimitManagerImpl]
> (Job-Executor-166:ctx-d915e890 ctx-d7a11540) Discrepency in the resource
> count (original count=107374182400 correct count = 85899345920) for type
> primary_storage for account ID 60 is fixed during resource count
> recalculation.
> 2014-12-03 12:20:46,651 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Job-Executor-166:ctx-d915e890) Complete async job-2804, jobStatus: FAILED,
> resultCode: 530, result:
> org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Failed
> to create a volume"}
> 2014-12-03 12:20:46,657 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl]
> (Job-Executor-166:ctx-d915e890) Done executing
> org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd for job-2804
> 2014-12-03 12:20:46,660 INFO [o.a.c.f.j.i.AsyncJobMonitor]
> (Job-Executor-166:ctx-d915e890) Remove job-2804 from job monitoring
> 2014-12-03 12:20:49,618 DEBUG [c.c.a.ApiServlet]
> (http-6443-exec-95:ctx-3aa7826a) ===START=== 111.client.ip.111 -- GET
> command=queryAsyncJobResult&jobId=f943cc56-d7a8-4529-9990-1a3ee6e9a13d&response=json&sessionkey=CENSORED%3D&_=1417605821689
> 2014-12-03 12:20:49,689 DEBUG [c.c.a.ApiServlet]
> (http-6443-exec-95:ctx-3aa7826a ctx-d76a1f77) ===END=== 111.client.ip.111 --
> GET
> command=queryAsyncJobResult&jobId=f943cc56-d7a8-4529-9990-1a3ee6e9a13d&response=json&sessionkey=CENSORED%3D&_=1417605821689
> 2014-12-03 12:20:50,015 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-12:null) SeqA 27-839631: Processing Seq 27-839631: {
> Cmd , MgmtId: -1, via: 27, Ver: v1, Flags: 11,
> [{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":473,"_loadInfo":"{\n
> \"connections\": []\n}","wait":0}}] }
> 2014-12-03 12:20:50,144 DEBUG [c.c.a.m.AgentManagerImpl]
> (AgentManager-Handler-12:null) SeqA 27-839631: Sending Seq 27-839631: { Ans:
> , MgmtId: 95545481387, via: 27, Ver: v1, Flags: 100010,
> [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
> BTW there is a typo in the code, Discrepency should be DescrepAncy.
> Regards,
> F.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
