[ https://issues.apache.org/jira/browse/CLOUDSTACK-4002?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13729963#comment-13729963 ]
Min Chen commented on CLOUDSTACK-4002: -------------------------------------- That NullPointerException is because all your hosts are in Disconnected state, so when we need to send a CopyCommand to a hypervisor host to copy a snapshot from secondary storage to primary, we could not find a Up host to send command to, and thus failed in create volume. You need to make sure that hosts are up before invoking creating volume command. > [Upgrade][2.2.16 to 4.2] After upgrade creation of volume from a snapshot > which was existing before upgrade, fails with NPE > --------------------------------------------------------------------------------------------------------------------------- > > Key: CLOUDSTACK-4002 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4002 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the > default.) > Components: Snapshot, Storage Controller, Upgrade > Affects Versions: 4.2.0 > Environment: upgraded environment from 2.2.16 to 4.2 > Hypervisor : XEN 6.0.2 > Reporter: Abhinav Roy > Assignee: Min Chen > Priority: Critical > Fix For: 4.2.0 > > Attachments: apilog.log, Bforeupgraedecloud-backup.dmp, > DB_DUMP_2216_cloud-31jul.sql, DB_DUMP_420_cloud-1Aug.sql, > management-server.log, postupgradecloud-backup.dmp > > > Steps : > ==================== > 1. Deploy CS advanced zone setup with Xen 6.0.2 hypervisor > 2. Create VMs. v1, v2 > 3. Create snapshots on the ROOT volumes of the VMs created in step2 , s1,s2 > 4. Upgrade CS to 4.2 > 5. Now try to create volumes from snapshots s1/s2 > Expected behaviour : > =================== > Creation of volumes should be successful. > Observed behaviour : > =================== > 1. The volume creation fails with NPE and gets stuck in "creating" in the DB > 2013-08-01 13:25:18,846 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) > ===START=== 10.144.7.7 -- GET > command=createVolume&response=json&sessionkey=e6y2vkO969W8moD6GKiQkvMwjA8%3D&sna > pshotid=2&name=vol-root5+au+from+snapshot&_=1375343509092 > 2013-08-01 13:25:18,967 DEBUG [cloud.async.AsyncJobManagerImpl] > (catalina-exec-22:null) submit async job-39 = [ > 31f14989-012d-414d-a0dd-a15232ef0823 ], details: AsyncJobVO {id:39, userId: > 2, accountId: 2, sessionKey: null, instanceType: Volume, instanceId: 18, cmd: > org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd, cmdOriginator: > null, cmdInfo: > {"id":"18","response":"json","sessionkey":"e6y2vkO969W8moD6GKiQkvMwjA8\u003d","cmdEventType":"VOLUME.CREATE","ctxUserId":"2","snapshotid":"2","name":"vol-root5 > au from > snapshot","httpmethod":"GET","_":"1375343509092","ctxAccountId":"2","ctxStartEventId":"157"}, > cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, > processStatus: 0, resultCode: 0, result: null, initMsid: 226870599129537, > completeMsid: null, lastUpdated: null, lastPolled: null, created: > null}2013-08-01 13:25:18,969 DEBUG [cloud.api.ApiServlet] > (catalina-exec-22:null) ===END=== 10.144.7.7 -- GET > command=createVolume&response=json&sessionkey=e6y2vkO969W8moD6GKiQkvMwjA8%3D&snaps > hotid=2&name=vol-root5+au+from+snapshot&_=1375343509092 > 2013-08-01 13:25:18,971 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-14:job-39 = [ 31f14989-012d-414d-a0dd-a15232ef0823 ]) Executing > org.apache.cloudstack.api.command.user.volume.C > reateVolumeCmd for job-39 = [ 31f14989-012d-414d-a0dd-a15232ef0823 ] > 2013-08-01 13:25:18,990 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-13:null) SeqA 4-10114: Processing Seq 4-10114: { Cmd , > MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.c > loud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n > \"connections\": []\n}","wait":0}}] } > 2013-08-01 13:25:19,001 DEBUG [agent.manager.AgentManagerImpl] > (AgentManager-Handler-13:null) SeqA 4-10114: Sending Seq 4-10114: { Ans: , > MgmtId: 226870599129537, via: 4, Ver: v1, Flags: 1 > 00010, [{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] } > 2013-08-01 13:25:19,019 DEBUG [storage.allocator.LocalStoragePoolAllocator] > (Job-Executor-14:job-39 = [ 31f14989-012d-414d-a0dd-a15232ef0823 ]) > LocalStoragePoolAllocator trying to find stor > age pool to fit the vm > 2013-08-01 13:25:19,019 DEBUG > [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-14:job-39 > = [ 31f14989-012d-414d-a0dd-a15232ef0823 ]) ClusterScopeStoragePoolAllocator > looki > ng for storage pool > 2013-08-01 13:25:19,020 DEBUG > [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-14:job-39 > = [ 31f14989-012d-414d-a0dd-a15232ef0823 ]) Looking for pools in dc: 1 pod:1 > clu > ster:null > 2013-08-01 13:25:19,024 DEBUG > [storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-14:job-39 = [ > 31f14989-012d-414d-a0dd-a15232ef0823 ]) Checking if storage pool is suitable, > name > : null ,poolId: 200 > 2013-08-01 13:25:19,029 DEBUG [cloud.storage.StorageManagerImpl] > (Job-Executor-14:job-39 = [ 31f14989-012d-414d-a0dd-a15232ef0823 ]) Checking > pool 200 for storage, totalSize: 879609315328, > usedBytes: 651471093760, usedPct: 0.7406368741298187, disable threshold: 0.85 > 2013-08-01 13:25:19,055 DEBUG [cloud.storage.StorageManagerImpl] > (Job-Executor-14:job-39 = [ 31f14989-012d-414d-a0dd-a15232ef0823 ]) Checking > pool: 200 for volume allocation [Vol[18|vm=null > |DATADISK]], maxSize : 1759218630656, totalAllocatedSize : 128773780480, > askingSize : 8589934592, allocated disable threshold: 0.85 > 2013-08-01 13:25:19,055 DEBUG > [storage.allocator.ClusterScopeStoragePoolAllocator] (Job-Executor-14:job-39 > = [ 31f14989-012d-414d-a0dd-a15232ef0823 ]) FirstFitStoragePoolAllocator > returning > 1 suitable storage pools > 2013-08-01 13:25:19,058 DEBUG [allocator.impl.UserConcentratedAllocator] > (Job-Executor-14:job-39 = [ 31f14989-012d-414d-a0dd-a15232ef0823 ]) There are > no pods with enough memory/CPU capacit > y in zone zone-1 > 2013-08-01 13:25:19,080 DEBUG [storage.volume.VolumeServiceImpl] > (Job-Executor-14:job-39 = [ 31f14989-012d-414d-a0dd-a15232ef0823 ]) create > volume from snapshot failed > java.lang.NullPointerException > at > org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromSnapshot(VolumeServiceImpl.java:567) > at > com.cloud.storage.VolumeManagerImpl.createVolumeFromSnapshot(VolumeManagerImpl.java:552) > at > com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) > at > com.cloud.storage.VolumeManagerImpl.createVolumeFromSnapshot(VolumeManagerImpl.java:602) > at > com.cloud.storage.VolumeManagerImpl.createVolume(VolumeManagerImpl.java:1046) > at > com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) > at > com.cloud.storage.VolumeManagerImpl.createVolume(VolumeManagerImpl.java:180) > at > org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd.execute(CreateVolumeCmd.java:189) > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158) > at > com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531) > 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:636) > 2013-08-01 13:25:19,080 DEBUG [cloud.storage.VolumeManagerImpl] > (Job-Executor-14:job-39 = [ 31f14989-012d-414d-a0dd-a15232ef0823 ]) > Failed to create volume from > snapshot:java.lang.NullPointerException2013-08-01 > 13:25:19,080 DEBUG [cloud.storage.VolumeManagerImpl] > (Job-Executor-14:job-39 = [ 31f14989-012d-414d-a0dd-a15232ef0823 ]) > Failed to create volume: 18 > com.cloud.utils.exception.CloudRuntimeException: Failed to create volume from > snapshot:java.lang.NullPointerException > at > com.cloud.storage.VolumeManagerImpl.createVolumeFromSnapshot(VolumeManagerImpl.java:557) > > at > com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) > > at > com.cloud.storage.VolumeManagerImpl.createVolumeFromSnapshot(VolumeManagerImpl.java:602) > > at > com.cloud.storage.VolumeManagerImpl.createVolume(VolumeManagerImpl.java:1046) > > at > com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125) > > at > com.cloud.storage.VolumeManagerImpl.createVolume(VolumeManagerImpl.java:180) > > at > org.apache.cloudstack.api.command.user.volume.CreateVolumeCmd.execute(CreateVolumeCmd.java:189) > > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158) > > at > com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531) > > 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:636)2013-08-01 13:25:19,113 > DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-14:job-39 = [ > 31f14989-012d-414d-a0dd-a15232ef0823 ]) Complete async job-39 = [ > 31f14989-012d-414d-a0dd-a15232ef0823 ], jobStatus: 2, resultCode: 530, > result: Error Code: 530 Error text: Failed to create a volume2013-08-01 > 13:25:22,005 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===START=== > 10.144.7.7 -- GET > command=queryAsyncJobResult&jobId=31f14989-012d-414d-a0dd-a15232ef0823&response=json&sessionkey=e6y2vkO969W8moD6GKiQkvMwjA8%3D&_=13753435122972013-08-01 > 13:25:22,017 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-1:null) > Async job-39 = [ 31f14989-012d-414d-a0dd-a15232ef0823 ] completed > mysql> select * from volumes where id=18; > +----+------------+-----------+---------+-------------+-----------+----------------------------+------------+--------+------+--------+----------------+------------+---------+-------------+-----------+------------------+-------------+--------+----------------------------+-------------+---------------------+----------+---------------------+---------+----------+------------+--------------------------------------+--------------+--------------+-----------+----------------+--------+----------+----------+------------------------+ > | id | account_id | domain_id | pool_id | instance_id | device_id | name > | size | folder | path | pod_id | data_center_id | > iscsi_name | host_ip | volume_type | pool_type | disk_offering_id | > template_id | iso_id | first_snapshot_backup_uuid | recreatable | created > | attached | updated | removed | state | chain_info | > uuid | last_pool_id | update_count | > disk_type | display_volume | format | min_iops | max_iops | > vm_snapshot_chain_size | > +----+------------+-----------+---------+-------------+-----------+----------------------------+------------+--------+------+--------+----------------+------------+---------+-------------+-----------+------------------+-------------+--------+----------------------------+-------------+---------------------+----------+---------------------+---------+----------+------------+--------------------------------------+--------------+--------------+-----------+----------------+--------+----------+----------+------------------------+ > | 18 | 2 | 1 | NULL | NULL | NULL | vol-root5 > au from snapshot | 8589934592 | NULL | NULL | NULL | 1 | > NULL | NULL | DATADISK | NULL | 1 | > 2 | NULL | NULL | 0 | 2013-08-01 07:55:18 | > NULL | 2013-08-01 07:55:19 | NULL | Creating | NULL | > a2330e3b-b6b8-44cc-babd-aa28ef1baa95 | NULL | 1 | NULL > | 1 | NULL | NULL | NULL | NULL | > +----+------------+-----------+---------+-------------+-----------+----------------------------+------------+--------+------+--------+----------------+------------+---------+-------------+-----------+------------------+-------------+--------+----------------------------+-------------+---------------------+----------+---------------------+---------+----------+------------+--------------------------------------+--------------+--------------+-----------+----------------+--------+----------+----------+------------------------+ > 1 row in set (0.00 sec) > 2. If for the same Root volume I create another snapshot after upgrade , and > then create a volume from that snapshot then it succeeds. > mysql> select * from volumes where id=22; > +----+------------+-----------+---------+-------------+-----------+----------------------+------------+--------+--------------------------------------+--------+----------------+------------+---------+-------------+-----------+------------------+-------------+--------+----------------------------+-------------+---------------------+----------+---------------------+---------+-------+------------+--------------------------------------+--------------+--------------+-----------+----------------+--------+----------+----------+------------------------+ > | id | account_id | domain_id | pool_id | instance_id | device_id | name > | size | folder | path | > pod_id | data_center_id | iscsi_name | host_ip | volume_type | pool_type | > disk_offering_id | template_id | iso_id | first_snapshot_backup_uuid | > recreatable | created | attached | updated | removed > | state | chain_info | uuid | last_pool_id | > update_count | disk_type | display_volume | format | min_iops | max_iops | > vm_snapshot_chain_size | > +----+------------+-----------+---------+-------------+-----------+----------------------+------------+--------+--------------------------------------+--------+----------------+------------+---------+-------------+-----------+------------------+-------------+--------+----------------------------+-------------+---------------------+----------+---------------------+---------+-------+------------+--------------------------------------+--------------+--------------+-----------+----------------+--------+----------+----------+------------------------+ > | 22 | 2 | 1 | 200 | NULL | NULL | vol from > snap root-5 | 8589934592 | NULL | a1eaaabd-19a9-48d8-9624-c9ee81ca01c9 | > NULL | 1 | NULL | NULL | DATADISK | NULL | > 1 | 2 | NULL | NULL | 0 > | 2013-08-01 08:10:53 | NULL | 2013-08-01 08:11:26 | NULL | Ready | > NULL | 840077f9-0840-41b2-a4e0-de35a06ada37 | NULL | > 2 | NULL | 1 | NULL | NULL | NULL | > NULL | > +----+------------+-----------+---------+-------------+-----------+----------------------+------------+--------+--------------------------------------+--------+----------------+------------+---------+-------------+-----------+------------------+-------------+--------+----------------------------+-------------+---------------------+----------+---------------------+---------+-------+------------+--------------------------------------+--------------+--------------+-----------+----------------+--------+----------+----------+------------------------+ > 1 row in set (0.00 sec) -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators For more information on JIRA, see: http://www.atlassian.com/software/jira