cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "prashant kumar mishra (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (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]
Date Tue, 23 Jul 2013 11:46:48 GMT

     [ https://issues.apache.org/jira/browse/CLOUDSTACK-3732?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

prashant kumar mishra updated CLOUDSTACK-3732:
----------------------------------------------

    Attachment: Logs_DB.rar
    
> 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
>
>         Attachments: Logs_DB.rar
>
>
> 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

Mime
View raw message