Abhinav Roy created CLOUDSTACK-4002:
---------------------------------------
Summary: [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
Priority: Critical
Fix For: 4.2.0
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
