[
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
