[
https://issues.apache.org/jira/browse/CLOUDSTACK-8014?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14241090#comment-14241090
]
Abhinandan Prateek commented on CLOUDSTACK-8014:
------------------------------------------------
If you try to delete the template twice, (maybe due to some race condition it
pops up in the UI while it is being deleted), then you get the resource count
issue:
..
INFO [c.c.t.HypervisorTemplateAdapter] (Job-Executor-5:ctx-07a5e482
ctx-e4966196) Delete template from image store: secone
INFO [c.c.t.HypervisorTemplateAdapter] (Job-Executor-5:ctx-07a5e482
ctx-e4966196) Delete template from image store: sectwo
..
INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-6:ctx-fdf72fb9) Add job-189
into job monitoring
INFO [c.c.t.HypervisorTemplateAdapter] (Job-Executor-6:ctx-fdf72fb9
ctx-1e235c0f) Unable to find image store still having template: centos, so just
mark the template removed
INFO [c.c.r.ResourceLimitManagerImpl] (Job-Executor-6:ctx-fdf72fb9
ctx-1e235c0f) Discrepency in the resource count (original count=46513518080
correct count = 3563845120) for type secondary_storage for account ID 2 is
fixed during resource count recalculation.
INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor-6:ctx-fdf72fb9) Remove
job-189 from job monitoring
...
This is just a info message and not a bug.
> 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)
