[
https://issues.apache.org/jira/browse/CLOUDSTACK-8014?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14244161#comment-14244161
]
Rohit Yadav commented on CLOUDSTACK-8014:
-----------------------------------------
Hi France, the NPE is a corner case that occurs only when you create a volume
since it goes through that code path. IMO, this is not a fatal operation to
undelete the template and test its behaviour, you can also set the removed
field to the original value (make sure to note the original value and take DB
dump in case).
> 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
> Assignee: Rohit Yadav
>
> 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)
