You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "prashant kumar mishra (JIRA)" <ji...@apache.org> on 2013/07/23 13:44:49 UTC
[jira] [Created] (CLOUDSTACK-3732) vm deployement fails in vmware
cluster;Mismatch in storage pool Pool[1|NetworkFilesystem] assigned by
deploymentPlanner and the one associated d with volume Vol[16|vm=13|ROOT]
prashant kumar mishra created CLOUDSTACK-3732:
-------------------------------------------------
Summary: vm deployement fails in vmware cluster;Mismatch in storage pool Pool[1|NetworkFilesystem] assigned by deploymentPlanner and the one associated d with volume Vol[16|vm=13|ROOT]
Key: CLOUDSTACK-3732
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-3732
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Management Server
Affects Versions: 4.2.0
Environment: vmware ; branch 4.2
Reporter: prashant kumar mishra
Priority: Critical
Fix For: 4.2.0
Steps to reproduce
------------------------------
1-prepare CS setup ->one cluster (cl1)->one esxi5.1->one primary storage(primary) -->one secondary storage
2-deploy a vm
3-add another cluster say cl2 --> with esxi4.1 host ,vcenter server 5.1-->with one primary storage(primary2)
4-disable cluster 1(cl1)
5-deploy a vm with new network and small SO
expected
--------------
VM should come up successfully
actual
----------
VR is coming up in disabled cluster and user vm deployment failing
My observation
==============
while deployment of VR
------------------------------------
1-primary2 unreachable
013-07-23 10:53:36,839 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Unable to create Vol[17|vm=14|ROOT]:Unable to execute PrimaryStorageDownloadCommand due to exception
2013-07-23 10:53:36,839 INFO [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:2] is unreachable: Unable to create Vol[17|vm=14|ROOT]:Unable to execute PrimaryStorageDownloadCommand due to exception
2-Even cluster one (cl1) is in disable state deployment planner chose cl1 for VR
Checking resources in Cluster: 3 under Pod: 1
2013-07-23 10:53:37,029 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:3
2013-07-23 10:53:37,036 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-6-Routing]]
2013-07-23 10:53:37,043 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-6-Routing]]
2013-07-23 10:53:37,043 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=128
2013-07-23 10:53:37,043 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) Host name: 10.147.40.8, hostId: 6 is in avoid set, skipping this and trying other available hosts
2013-07-23 10:53:37,043 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2013-07-23 10:53:37,043 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) No suitable hosts found
2013-07-23 10:53:37,043 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) No suitable hosts found under this Cluster: 3
2013-07-23 10:53:37,052 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Checking resources in Cluster: 2 under Pod: 1
2013-07-23 10:53:37,052 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:2
2013-07-23 10:53:37,059 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-1-Routing]]
2013-07-23 10:53:37,065 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-1-Routing]]
2013-07-23 10:53:37,065 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=128
3-
2013-07-23 10:53:37,171 DEBUG [cloud.vm.VirtualMachineManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Deployment found - P0=VM[DomainRouter|r-14-VM], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(2)-Host(1)-Storage(Volume(17|ROOT-->Pool(1))]
User VM
--------------
1-
013-07-23 10:57:17,765 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_faaee9c4@aed41bc
2013-07-23 10:57:17,766 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:3, requested cpu: 500, requested ram: 536870912
2013-07-23 10:57:17,766 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Is ROOT volume READY (pool already allocated)?: Yes
2013-07-23 10:57:17,766 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Searching resources only under specified Cluster: 3
2013-07-23 10:57:17,788 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Checking resources in Cluster: 3 under Pod: 1
2013-07-23 10:57:17,789 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:3
2013-07-23 10:57:17,796 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to check for allocation: [Host[-6-Routing]]
2013-07-23 10:57:17,802 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) Found 1 hosts for allocation after prioritization: [Host[-6-Routing]]
2013-07-23 10:57:17,802 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=512
2013-07-23 10:57:17,802 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) Host name: 10.147.40.8, hostId: 6 is in avoid set, skipping this and trying other available hosts
2013-07-23 10:57:17,802 DEBUG [allocator.impl.FirstFitAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ] FirstFitRoutingAllocator) Host Allocator returning 0 suitable hosts
2013-07-23 10:57:17,803 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) No suitable hosts found
2013-07-23 10:57:17,803 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) No suitable hosts found under this Cluster: 3
2013-07-23 10:57:17,809 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Could not find suitable Deployment Destination for this VM under any clusters, returning.
2013-07-23 10:57:17,810 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Searching resources only under specified Cluster: 3
2013-07-23 10:57:17,812 DEBUG [cloud.deploy.FirstFitPlanner] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) The specified cluster is in avoid set, returning.
2013-07-23 10:57:17,835 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Deploy avoids pods: null, clusters: [3], hosts: [6]
2013-07-23 10:57:17,837 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_faaee9c4@aed41bc
2013-07-23 10:57:17,837 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 536870912
2-Asking VirtualRouter to prepare for Nic[30-13-c18b2f60-c507-4da4-827e-78a5ffb8058c-10.1.1.220]
2013-07-23 10:57:18,152 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Lock is acquired for network id 205 as a part of router startup in Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(2)-Host(1)-Storage(Volume(16|ROOT-->Pool(1))]
3-migrate volume initiated because of mismatch and it picked wrong PS(primary2) for copying volume to secondary storage
2013-07-23 10:57:21,572 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Checking if we need to prepare 1 volumes for VM[User|newvm]
2013-07-23 10:57:21,575 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Mismatch in storage pool Pool[1|NetworkFilesystem] assigned by deploymentPlanner and the one associated with volume Vol[16|vm=13|ROOT]
2013-07-23 10:57:21,575 DEBUG [cloud.storage.VolumeManagerImpl] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Shared volume Vol[16|vm=13|ROOT] will be migrated on storage pool Pool[1|NetworkFilesystem] assigned by deploymentPlanner
2013-07-23 10:57:21,643 DEBUG [storage.motion.AncientDataMotionStrategy] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) copyAsync inspecting src type VOLUME copyAsync inspecting dest type VOLUME
2013-07-23 10:57:21,645 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===START=== 10.252.192.53 -- GET command=listRouters&listAll=true&page=1&pagesize=20&response=json&sessionkey=F8Cw9e7dmEvSRFlZRi1DKxUgHPQ%3D&_=1374571988383
2013-07-23 10:57:21,660 DEBUG [cache.allocator.StorageCacheRandomAllocator] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Can't find cache storage in zone: 1
2013-07-23 10:57:21,708 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===END=== 10.252.192.53 -- GET command=listRouters&listAll=true&page=1&pagesize=20&response=json&sessionkey=F8Cw9e7dmEvSRFlZRi1DKxUgHPQ%3D&_=1374571988383
2013-07-23 10:57:21,770 DEBUG [agent.manager.AgentAttache] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Request seq: 1718157356
2013-07-23 10:57:21,771 DEBUG [agent.manager.AgentAttache] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) waiting to send 1718157356
2013-07-23 10:57:21,771 DEBUG [agent.manager.AgentAttache] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) entering synchronize block for sending 1718157356
2013-07-23 10:57:21,773 DEBUG [agent.transport.Request] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Seq 5-1718157356: Sending { Cmd , MgmtId: 7635042566263, via: 5, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"a3ac26fc-92da-476c-8e45-c2421e24e041","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"bd186911-97af-371a-9b26-fac999fc98a4","id":2,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/prashant/primary2","port":2049}},"name":"ROOT-13","size":0,"path":"ROOT-13-16","volumeId":16,"vmName":"i-2-13-VM","accountId":2,"format":"OVA","id":16}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"a3ac26fc-92da-476c-8e45-c2421e24e041","volumeType":"ROOT","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/prashant/secondary.4.2.vmware","_role":"Image"}},"name":"ROOT-13","size":0,"path":"volumes/2/16","volumeId":16,"vmName":"i-2-13-VM","accountId":2,"format":"OVA","id":16}},"executeInSequence":false,"wait":10800}}] }
2013-07-23 10:57:21,792 DEBUG [cloud.api.ApiServlet] (catalina-exec-14:null) ===START=== 10.252.192.53 -- GET command=listRouters&listAll=true&page=1&pagesize=20&projectid=-1&response=json&sessionkey=F8Cw9e7dmEvSRFlZRi1DKxUgHPQ%3D&_=1374571988599
2013-07-23 10:57:21,811 DEBUG [cloud.api.ApiServlet] (catalina-exec-14:null) ===END=== 10.252.192.53 -- GET command=listRouters&listAll=true&page=1&pagesize=20&projectid=-1&response=json&sessionkey=F8Cw9e7dmEvSRFlZRi1DKxUgHPQ%3D&_=1374571988599
2013-07-23 10:57:21,818 DEBUG [agent.transport.Request] (AgentManager-Handler-6:null) Seq 5-1718157356: Processing: { Ans: , MgmtId: 7635042566263, via: 5, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.executeRequest(VmwareSecondaryStorageResourceHandler.java:105)\n\tat com.cloud.storage.resource.PremiumSecondaryStorageResource.executeRequest(PremiumSecondaryStorageResource.java:56)\n\tat com.cloud.agent.Agent.processRequest(Agent.java:525)\n\tat com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)\n\tat com.cloud.utils.nio.Task.run(Task.java:83)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)\n\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat java.lang.Thread.run(Thread.java:679)\n","wait":0}}] }
2013-07-23 10:57:21,819 DEBUG [agent.transport.Request] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) Seq 5-1718157356: Received: { Ans: , MgmtId: 7635042566263, via: 5, Ver: v1, Flags: 10, { Answer } }
2013-07-23 10:57:21,819 DEBUG [storage.motion.AncientDataMotionStrategy] (Job-Executor-10:job-43 = [ 05569d7e-8630-4481-a7cf-2d4831ba38fe ]) copy to image store failed: java.lang.NullPointerException
DB
=========
mysql> select * from storage_pool\G;
*************************** 1. row ***************************
id: 1
name: primary
uuid: 8db52c2d-88f9-3b9d-9b81-f72fcb8097c2
pool_type: NetworkFilesystem
port: 2049
data_center_id: 1
pod_id: 1
cluster_id: 2
used_bytes: 2074777964544
capacity_bytes: 5902284800000
host_address: 10.147.28.7
user_info: NULL
path: /export/home/prashant/primary
created: 2013-07-22 15:57:53
removed: NULL
update_time: NULL
status: Up
storage_provider_name: DefaultPrimary
scope: CLUSTER
hypervisor: NULL
managed: 0
capacity_iops: NULL
*************************** 2. row ***************************
id: 2
name: primary2
uuid: bd186911-97af-371a-9b26-fac999fc98a4
pool_type: NetworkFilesystem
port: 2049
data_center_id: 1
pod_id: 1
cluster_id: 3
used_bytes: 2064452661248
capacity_bytes: 5902284800000
host_address: 10.147.28.7
user_info: NULL
path: /export/home/prashant/primary2
created: 2013-07-23 14:02:59
removed: NULL
update_time: NULL
status: Up
storage_provider_name: DefaultPrimary
scope: CLUSTER
hypervisor: NULL
managed: 0
capacity_iops: NULL
2-
mysql> select * from volumes where id = 18\G;
*************************** 1. row ***************************
id: 18
account_id: 2
domain_id: 1
pool_id: 1
last_pool_id: 2
instance_id: 13
device_id: 0
name: ROOT-13
uuid: 881d0e45-0986-4ba1-b1d9-b286df54930f
size: 0
folder: /export/home/prashant/primary
path: ROOT-13-16
pod_id: 1
data_center_id: 1
iscsi_name: NULL
host_ip: NULL
volume_type: ROOT
pool_type: NULL
disk_offering_id: 1
template_id: 7
first_snapshot_backup_uuid: NULL
recreatable: 0
created: 2013-07-23 14:57:21
attached: NULL
updated: 2013-07-23 14:57:27
removed: 2013-07-23 14:57:27
state: Expunged
chain_info: NULL
update_count: 6
disk_type: NULL
display_volume: 0
format: NULL
min_iops: NULL
max_iops: NULL
1 row in set (0.00 sec)
ERROR:
No query specified
--
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