[ https://issues.apache.org/jira/browse/CLOUDSTACK-8014?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14241094#comment-14241094 ]
France commented on CLOUDSTACK-8014: ------------------------------------ Tnx Rohit for your efforts. I will read your responses with great cate and try to do what you ask of me, then report back on the jira. This is just a private mail to you, so you know I am working on it, the problem is that i have to deal with the customers concurrently on completely different field. :-/ Regards, F. > 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)