You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users-cn@cloudstack.apache.org by 宋冠男 <gu...@uniscom.cn> on 2014/03/25 10:51:22 UTC
CloudStack4.2.0+Xenserver6.0.201:cpvm无法启动，ssvm不断重建
具体日志如下,望各位大侠指导：
2014-03-13 19:17:56,704 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
2014-03-13 19:17:56,704 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Expand console proxy standby capacity for zone zone002
2014-03-13 19:17:56,707 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) Hosts's actual total CPU: 15200 and CPU after applying overprovisioning: 15200
2014-03-13 19:17:56,707 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) We are allocating VM, increasing the used capacity of this host:2
2014-03-13 19:17:56,707 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) Current Used CPU: 0 , Free CPU:15200 ,Requested CPU: 500
2014-03-13 19:17:56,707 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) Current Used RAM: 0 , Free RAM:20340883456 ,Requested RAM: 268435456
2014-03-13 19:17:56,707 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) CPU STATS after allocation: for host: 2, old used: 0, old reserved: 0, actual total: 15200, total with overprovisioning: 15200; new used:500, reserved:0; requested cpu:500,alloc_from_last:false
2014-03-13 19:17:56,707 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) RAM STATS after allocation: for host: 2, old used: 0, old reserved: 0, total: 20340883456; new used: 268435456, reserved: 0; requested mem: 268435456,alloc_from_last:false
2014-03-13 19:17:56,709 INFO [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Found a stopped console proxy, bring it up to running pool. proxy vm id : 2
2014-03-13 19:17:56,712 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) VM is being created in podId: 1
2014-03-13 19:17:56,725 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM state transitted from :Stopped to Starting with event: StartRequestedvm's original host id: null new host id: null host id before state transition: null
2014-03-13 19:17:56,725 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Successfully transitioned to start state for VM[ConsoleProxy|v-2-VM] reservation id = 979b12db-3e66-4119-8a30-9057e6e27a44
2014-03-13 19:17:56,729 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Network id=204 is already implemented
2014-03-13 19:17:56,795 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Trying to deploy VM, vm has dcId: 1 and podId: 1
2014-03-13 19:17:56,795 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2014-03-13 19:17:56,802 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2014-03-13 19:17:56,807 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_347ca090@78bae085
2014-03-13 19:17:56,807 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 1073741824
2014-03-13 19:17:56,807 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Is ROOT volume READY (pool already allocated)?: No
2014-03-13 19:17:56,808 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Searching resources only under specified Pod: 1
2014-03-13 19:17:56,808 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2014-03-13 19:17:56,829 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking resources in Cluster: 1 under Pod: 1
2014-03-13 19:17:56,829 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2014-03-13 19:17:56,837 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 3 hosts to check for allocation: [Host[-3-Routing], Host[-1-Routing], Host[-2-Routing]]
2014-03-13 19:17:56,843 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Asking VirtualRouter to prepare for Nic[284-72-723dbc83-60d8-4202-80c9-6ad19cce3719-192.168.0.32]
2014-03-13 19:17:56,845 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found 3 hosts for allocation after prioritization: [Host[-3-Routing], Host[-1-Routing], Host[-2-Routing]]
2014-03-13 19:17:56,845 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=1024
2014-03-13 19:17:56,849 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Asking SecurityGroupProvider to prepare for Nic[284-72-723dbc83-60d8-4202-80c9-6ad19cce3719-192.168.0.32]
2014-03-13 19:17:56,860 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Checking if host: 3 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
2014-03-13 19:17:56,864 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Network id=202 is already implemented
2014-03-13 19:17:56,864 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 15200 and CPU after applying overprovisioning: 15200
2014-03-13 19:17:56,865 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 15200 , Requested CPU: 500
2014-03-13 19:17:56,865 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 12058574848 , Requested RAM: 1073741824
2014-03-13 19:17:56,865 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-03-13 19:17:56,865 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 3, used: 0, reserved: 0, actual total: 15200, total with overprovisioning: 15200; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-13 19:17:56,865 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 3, used: 0, reserved: 0, total: 12058574848; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-13 19:17:56,865 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host, adding to list: 3
2014-03-13 19:17:56,877 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
2014-03-13 19:17:56,881 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 15200 and CPU after applying overprovisioning: 15200
2014-03-13 19:17:56,882 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 15200 , Requested CPU: 500
2014-03-13 19:17:56,882 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 20340883456 , Requested RAM: 1073741824
2014-03-13 19:17:56,882 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-03-13 19:17:56,882 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 0, reserved: 0, actual total: 15200, total with overprovisioning: 15200; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-13 19:17:56,882 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 0, reserved: 0, total: 20340883456; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-13 19:17:56,882 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
2014-03-13 19:17:56,900 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Checking if host: 2 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
2014-03-13 19:17:56,905 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 15200 and CPU after applying overprovisioning: 15200
2014-03-13 19:17:56,905 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 14700 , Requested CPU: 500
2014-03-13 19:17:56,905 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 20072448000 , Requested RAM: 1073741824
2014-03-13 19:17:56,905 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-03-13 19:17:56,905 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 2, used: 500, reserved: 0, actual total: 15200, total with overprovisioning: 15200; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-13 19:17:56,905 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 2, used: 268435456, reserved: 0, total: 20340883456; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-13 19:17:56,905 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host, adding to list: 2
2014-03-13 19:17:56,905 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning 3 suitable hosts
2014-03-13 19:17:56,908 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking suitable pools for volume (Id, Type): (2,ROOT)
2014-03-13 19:17:56,908 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) We need to allocate new storagepool for this volume
2014-03-13 19:17:56,908 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Calling StoragePoolAllocators to find suitable pools
2014-03-13 19:17:56,909 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2014-03-13 19:17:56,910 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Network id=201 is already implemented
2014-03-13 19:17:56,910 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) ClusterScopeStoragePoolAllocator looking for storage pool
2014-03-13 19:17:56,910 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) Looking for pools in dc: 1 pod:1 cluster:1
2014-03-13 19:17:56,918 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Checking if storage pool is suitable, name: null ,poolId: 1
2014-03-13 19:17:56,925 DEBUG [cloud.storage.StorageManagerImpl] (consoleproxy-1:null) Checking pool 1 for storage, totalSize: 39698563072, usedBytes: 3522035712, usedPct: 0.08871947595715739, disable threshold: 0.85
2014-03-13 19:17:56,941 DEBUG [network.guru.PodBasedNetworkGuru] (secstorage-1:null) Allocated a nic NicProfile[286-72-723dbc83-60d8-4202-80c9-6ad19cce3719-192.168.0.14-null for VM[SecondaryStorageVm|s-72-VM]
2014-03-13 19:17:56,949 DEBUG [cloud.storage.StorageManagerImpl] (consoleproxy-1:null) Checking pool: 1 for volume allocation [Vol[2|vm=2|ROOT]], maxSize : 79397126144, totalAllocatedSize : 0, askingSize : 0, allocated disable threshold: 0.85
2014-03-13 19:17:56,950 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) FirstFitStoragePoolAllocator returning 1 suitable storage pools
2014-03-13 19:17:56,950 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2014-03-13 19:17:56,950 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking if host: 3 can access any suitable storage pool for volume: ROOT
2014-03-13 19:17:56,951 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Host: 3 cannot access pool: 1
2014-03-13 19:17:56,952 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking if host: 1 can access any suitable storage pool for volume: ROOT
2014-03-13 19:17:56,953 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Host: 1 can access pool: 1
2014-03-13 19:17:56,954 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Network id=203 is already implemented
2014-03-13 19:17:56,955 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Found a potential host id: 1 name: xenserver-003-cloud and associated storage pools for this VM
2014-03-13 19:17:56,957 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(2|ROOT-->Pool(1))]
2014-03-13 19:17:56,958 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Deployment found - P0=VM[ConsoleProxy|v-2-VM], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(2|ROOT-->Pool(1))]
2014-03-13 19:17:56,976 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 1 host id before state transition: null
2014-03-13 19:17:56,988 DEBUG [network.guru.PodBasedNetworkGuru] (secstorage-1:null) Allocated a nic NicProfile[287-72-723dbc83-60d8-4202-80c9-6ad19cce3719-192.168.0.16-null for VM[SecondaryStorageVm|s-72-VM]
2014-03-13 19:17:56,991 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) Hosts's actual total CPU: 15200 and CPU after applying overprovisioning: 15200
2014-03-13 19:17:56,991 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) We are allocating VM, increasing the used capacity of this host:1
2014-03-13 19:17:56,991 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) Current Used CPU: 0 , Free CPU:15200 ,Requested CPU: 500
2014-03-13 19:17:56,991 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) Current Used RAM: 0 , Free RAM:20340883456 ,Requested RAM: 1073741824
2014-03-13 19:17:56,991 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) CPU STATS after allocation: for host: 1, old used: 0, old reserved: 0, actual total: 15200, total with overprovisioning: 15200; new used:500, reserved:0; requested cpu:500,alloc_from_last:false
2014-03-13 19:17:56,994 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) RAM STATS after allocation: for host: 1, old used: 0, old reserved: 0, total: 20340883456; new used: 1073741824, reserved: 0; requested mem: 1073741824,alloc_from_last:false
2014-03-13 19:17:56,999 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) VM is being created in podId: 1
2014-03-13 19:17:57,000 DEBUG [cloud.storage.VolumeManagerImpl] (secstorage-1:null) Checking if we need to prepare 1 volumes for VM[SecondaryStorageVm|s-72-VM]
2014-03-13 19:17:57,012 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Network id=204 is already implemented
2014-03-13 19:17:57,014 DEBUG [storage.image.TemplateDataFactoryImpl] (secstorage-1:null) template 1 is already in store:1, type:Image
2014-03-13 19:17:57,020 DEBUG [storage.datastore.PrimaryDataStoreImpl] (secstorage-1:null) Not found (templateId:1poolId:1) in template_spool_ref, persisting it
2014-03-13 19:17:57,030 DEBUG [storage.image.TemplateDataFactoryImpl] (secstorage-1:null) template 1 is already in store:1, type:Primary
2014-03-13 19:17:57,032 DEBUG [storage.volume.VolumeServiceImpl] (secstorage-1:null) Found template routing-1 in storage pool 1 with VMTemplateStoragePool id: 141
2014-03-13 19:17:57,054 DEBUG [storage.volume.VolumeServiceImpl] (secstorage-1:null) Acquire lock on VMTemplateStoragePool 141 with timeout 3600 seconds
2014-03-13 19:17:57,060 INFO [storage.volume.VolumeServiceImpl] (secstorage-1:null) lock is acquired for VMTemplateStoragePool 141
2014-03-13 19:17:57,064 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking VirtualRouter to prepare for Nic[5-2-979b12db-3e66-4119-8a30-9057e6e27a44-192.168.0.31]
2014-03-13 19:17:57,069 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking SecurityGroupProvider to prepare for Nic[5-2-979b12db-3e66-4119-8a30-9057e6e27a44-192.168.0.31]
2014-03-13 19:17:57,077 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Network id=202 is already implemented
2014-03-13 19:17:57,128 DEBUG [storage.motion.AncientDataMotionStrategy] (secstorage-1:null) copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type TEMPLATE
2014-03-13 19:17:57,148 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 2-1262289223: Sending { Cmd , MgmtId: 52238112301, via: 2, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/1/1/","origUrl":"http://download.cloud.com/templates/4.2/systemvmtemplate-2013-07-12-master-xen.vhd.bz2","uuid":"1257316e-aa94-11e3-b701-000c29a2562d","id":1,"format":"VHD","accountId":1,"checksum":"fb1b6e032a160d86f2c28feb5add6d83","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.0.177/export/secondary","_role":"Image"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"http://download.cloud.com/templates/4.2/systemvmtemplate-2013-07-12-master-xen.vhd.bz2","uuid":"1257316e-aa94-11e3-b701-000c29a2562d","id":1,"format":"VHD","accountId":1,"checksum":"fb1b6e032a160d86f2c28feb5add6d83","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"52901ac9-433c-3670-83ba-366a5ca42699","id":1,"poolType":"NetworkFilesystem","host":"192.168.0.177","path":"/export/primary","port":2049}},"name":"routing-1","hypervisorType":"XenServer"}},"executeInSequence":true,"wait":10800}}] }
2014-03-13 19:17:57,150 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 2-1262289223: Executing: { Cmd , MgmtId: 52238112301, via: 2, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/1/1/","origUrl":"http://download.cloud.com/templates/4.2/systemvmtemplate-2013-07-12-master-xen.vhd.bz2","uuid":"1257316e-aa94-11e3-b701-000c29a2562d","id":1,"format":"VHD","accountId":1,"checksum":"fb1b6e032a160d86f2c28feb5add6d83","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.0.177/export/secondary","_role":"Image"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"http://download.cloud.com/templates/4.2/systemvmtemplate-2013-07-12-master-xen.vhd.bz2","uuid":"1257316e-aa94-11e3-b701-000c29a2562d","id":1,"format":"VHD","accountId":1,"checksum":"fb1b6e032a160d86f2c28feb5add6d83","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"52901ac9-433c-3670-83ba-366a5ca42699","id":1,"poolType":"NetworkFilesystem","host":"192.168.0.177","path":"/export/primary","port":2049}},"name":"routing-1","hypervisorType":"XenServer"}},"executeInSequence":true,"wait":10800}}] }
2014-03-13 19:17:57,150 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-463:null) Seq 2-1262289223: Executing request
2014-03-13 19:17:57,153 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Network id=201 is already implemented
2014-03-13 19:17:57,199 DEBUG [network.guru.PodBasedNetworkGuru] (consoleproxy-1:null) Allocated a nic NicProfile[7-2-979b12db-3e66-4119-8a30-9057e6e27a44-192.168.0.12-null for VM[ConsoleProxy|v-2-VM]
2014-03-13 19:17:57,209 DEBUG [cloud.storage.VolumeManagerImpl] (consoleproxy-1:null) Checking if we need to prepare 1 volumes for VM[ConsoleProxy|v-2-VM]
2014-03-13 19:17:57,223 DEBUG [storage.image.TemplateDataFactoryImpl] (consoleproxy-1:null) template 1 is already in store:1, type:Image
2014-03-13 19:17:57,234 DEBUG [storage.image.TemplateDataFactoryImpl] (consoleproxy-1:null) template 1 is already in store:1, type:Primary
2014-03-13 19:17:57,237 DEBUG [storage.volume.VolumeServiceImpl] (consoleproxy-1:null) Found template routing-1 in storage pool 1 with VMTemplateStoragePool id: 141
2014-03-13 19:17:57,251 DEBUG [storage.volume.VolumeServiceImpl] (consoleproxy-1:null) Acquire lock on VMTemplateStoragePool 141 with timeout 3600 seconds
2014-03-13 19:17:59,786 WARN [xen.resource.XenServerStorageProcessor] (DirectAgent-463:null) destoryVDIbyNameLabel failed due to there are 0 VDIs with name cloud-1b1855eb-a7bd-47ab-891c-2b4f9dcf0296
2014-03-13 19:17:59,799 WARN [xen.resource.XenServerStorageProcessor] (DirectAgent-463:null) can't mount 192.168.0.177:/export/secondary/template/tmpl/1/1 to /var/run/cloud_mount/e894384d-14c5-403a-ab7f-e43f96412868
2014-03-13 19:17:59,800 WARN [xen.resource.XenServerStorageProcessor] (DirectAgent-463:null) Catch Exception com.cloud.utils.exception.CloudRuntimeException for template + due to com.cloud.utils.exception.CloudRuntimeException: can't mount 192.168.0.177:/export/secondary/template/tmpl/1/1 to /var/run/cloud_mount/e894384d-14c5-403a-ab7f-e43f96412868
com.cloud.utils.exception.CloudRuntimeException: can't mount 192.168.0.177:/export/secondary/template/tmpl/1/1 to /var/run/cloud_mount/e894384d-14c5-403a-ab7f-e43f96412868
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.copy_vhd_from_secondarystorage(XenServerStorageProcessor.java:792)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.copyTemplateToPrimaryStorage(XenServerStorageProcessor.java:863)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:70)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:621)
at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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:679)
2014-03-13 19:17:59,801 DEBUG [agent.manager.DirectAgentAttache] (Dire
Re: CloudStack4.2.0+Xenserver6.0.201:cpvm无法启动，ssvm不断重建
Posted by "brito.wang@gmail.com" <br...@gmail.com>.
既然你的是xenserver环境，我的建议是从下面四步入手解决问题。
1.检查一下你的二级存储模板是否正确，
192.168.0.177:/export/secondary/template/tmpl/1/1目录下是否有一个vhd文件和一个prperties文件，并且vhd文件大小合适（4.3模板情况下大小为2.5G）
如果模板不正确，则需要重新下载模板，并安装模板到二级存储中。
2.检查一下主机下和二级存储机之间的网络通信，是否通畅，如果不通畅则需要设置解决网络的问题
3.检查一下xenserver主机中是否有一个这样一个脚本
/opt/cloud/bin/copy_vhd_from_secondarystorage.sh
如果没有这个文件，则需要删除主机，重新添加主机
4.在主机上手动执行
mount 192.168.0.177:/export/secondary/template/tmpl/1/1 /var/run/cloud_mount/e894384d-14c5-403a-ab7f-e43f96412868
看看是否成功,如果不成功则检查原因。
brito.wang@gmail.com
发件人： 宋冠男发送时间： 2014-03-25 17:51收件人： users-cn主题： CloudStack4.2.0+Xenserver6.0.201:cpvm无法启动，ssvm不断重建具体日志如下,望各位大侠指导：
2014-03-13 19:17:56,704 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
2014-03-13 19:17:56,704 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Expand console proxy standby capacity for zone zone002
2014-03-13 19:17:56,707 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) Hosts's actual total CPU: 15200 and CPU after applying overprovisioning: 15200
2014-03-13 19:17:56,707 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) We are allocating VM, increasing the used capacity of this host:2
2014-03-13 19:17:56,707 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) Current Used CPU: 0 , Free CPU:15200 ,Requested CPU: 500
2014-03-13 19:17:56,707 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) Current Used RAM: 0 , Free RAM:20340883456 ,Requested RAM: 268435456
2014-03-13 19:17:56,707 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) CPU STATS after allocation: for host: 2, old used: 0, old reserved: 0, actual total: 15200, total with overprovisioning: 15200; new used:500, reserved:0; requested cpu:500,alloc_from_last:false
2014-03-13 19:17:56,707 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) RAM STATS after allocation: for host: 2, old used: 0, old reserved: 0, total: 20340883456; new used: 268435456, reserved: 0; requested mem: 268435456,alloc_from_last:false
2014-03-13 19:17:56,709 INFO [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Found a stopped console proxy, bring it up to running pool. proxy vm id : 2
2014-03-13 19:17:56,712 DEBUG [cloud.vm.VirtualMachineManagerImpl] (secstorage-1:null) VM is being created in podId: 1
2014-03-13 19:17:56,725 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM state transitted from :Stopped to Starting with event: StartRequestedvm's original host id: null new host id: null host id before state transition: null
2014-03-13 19:17:56,725 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Successfully transitioned to start state for VM[ConsoleProxy|v-2-VM] reservation id = 979b12db-3e66-4119-8a30-9057e6e27a44
2014-03-13 19:17:56,729 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Network id=204 is already implemented
2014-03-13 19:17:56,795 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Trying to deploy VM, vm has dcId: 1 and podId: 1
2014-03-13 19:17:56,795 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2014-03-13 19:17:56,802 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2014-03-13 19:17:56,807 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) DeploymentPlanner allocation algorithm: com.cloud.deploy.FirstFitPlanner_EnhancerByCloudStack_347ca090@78bae085
2014-03-13 19:17:56,807 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Trying to allocate a host and storage pools from dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 1073741824
2014-03-13 19:17:56,807 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Is ROOT volume READY (pool already allocated)?: No
2014-03-13 19:17:56,808 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Searching resources only under specified Pod: 1
2014-03-13 19:17:56,808 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Listing clusters in order of aggregate capacity, that have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2014-03-13 19:17:56,829 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking resources in Cluster: 1 under Pod: 1
2014-03-13 19:17:56,829 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1 cluster:1
2014-03-13 19:17:56,837 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 3 hosts to check for allocation: [Host[-3-Routing], Host[-1-Routing], Host[-2-Routing]]
2014-03-13 19:17:56,843 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Asking VirtualRouter to prepare for Nic[284-72-723dbc83-60d8-4202-80c9-6ad19cce3719-192.168.0.32]
2014-03-13 19:17:56,845 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found 3 hosts for allocation after prioritization: [Host[-3-Routing], Host[-1-Routing], Host[-2-Routing]]
2014-03-13 19:17:56,845 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=1024
2014-03-13 19:17:56,849 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Asking SecurityGroupProvider to prepare for Nic[284-72-723dbc83-60d8-4202-80c9-6ad19cce3719-192.168.0.32]
2014-03-13 19:17:56,860 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Checking if host: 3 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
2014-03-13 19:17:56,864 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Network id=202 is already implemented
2014-03-13 19:17:56,864 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 15200 and CPU after applying overprovisioning: 15200
2014-03-13 19:17:56,865 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 15200 , Requested CPU: 500
2014-03-13 19:17:56,865 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 12058574848 , Requested RAM: 1073741824
2014-03-13 19:17:56,865 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-03-13 19:17:56,865 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 3, used: 0, reserved: 0, actual total: 15200, total with overprovisioning: 15200; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-13 19:17:56,865 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 3, used: 0, reserved: 0, total: 12058574848; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-13 19:17:56,865 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host, adding to list: 3
2014-03-13 19:17:56,877 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Checking if host: 1 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
2014-03-13 19:17:56,881 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 15200 and CPU after applying overprovisioning: 15200
2014-03-13 19:17:56,882 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 15200 , Requested CPU: 500
2014-03-13 19:17:56,882 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 20340883456 , Requested RAM: 1073741824
2014-03-13 19:17:56,882 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-03-13 19:17:56,882 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1, used: 0, reserved: 0, actual total: 15200, total with overprovisioning: 15200; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-13 19:17:56,882 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1, used: 0, reserved: 0, total: 20340883456; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-13 19:17:56,882 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host, adding to list: 1
2014-03-13 19:17:56,900 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Checking if host: 2 has enough capacity for requested CPU: 500 and requested RAM: 1073741824 , cpuOverprovisioningFactor: 1.0
2014-03-13 19:17:56,905 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 15200 and CPU after applying overprovisioning: 15200
2014-03-13 19:17:56,905 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 14700 , Requested CPU: 500
2014-03-13 19:17:56,905 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 20072448000 , Requested RAM: 1073741824
2014-03-13 19:17:56,905 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and RAM available
2014-03-13 19:17:56,905 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 2, used: 500, reserved: 0, actual total: 15200, total with overprovisioning: 15200; requested cpu:500,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-13 19:17:56,905 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 2, used: 268435456, reserved: 0, total: 20340883456; requested mem: 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2014-03-13 19:17:56,905 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host, adding to list: 2
2014-03-13 19:17:56,905 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning 3 suitable hosts
2014-03-13 19:17:56,908 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking suitable pools for volume (Id, Type): (2,ROOT)
2014-03-13 19:17:56,908 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) We need to allocate new storagepool for this volume
2014-03-13 19:17:56,908 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Calling StoragePoolAllocators to find suitable pools
2014-03-13 19:17:56,909 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) LocalStoragePoolAllocator trying to find storage pool to fit the vm
2014-03-13 19:17:56,910 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Network id=201 is already implemented
2014-03-13 19:17:56,910 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) ClusterScopeStoragePoolAllocator looking for storage pool
2014-03-13 19:17:56,910 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) Looking for pools in dc: 1 pod:1 cluster:1
2014-03-13 19:17:56,918 DEBUG [storage.allocator.AbstractStoragePoolAllocator] (consoleproxy-1:null) Checking if storage pool is suitable, name: null ,poolId: 1
2014-03-13 19:17:56,925 DEBUG [cloud.storage.StorageManagerImpl] (consoleproxy-1:null) Checking pool 1 for storage, totalSize: 39698563072, usedBytes: 3522035712, usedPct: 0.08871947595715739, disable threshold: 0.85
2014-03-13 19:17:56,941 DEBUG [network.guru.PodBasedNetworkGuru] (secstorage-1:null) Allocated a nic NicProfile[286-72-723dbc83-60d8-4202-80c9-6ad19cce3719-192.168.0.14-null for VM[SecondaryStorageVm|s-72-VM]
2014-03-13 19:17:56,949 DEBUG [cloud.storage.StorageManagerImpl] (consoleproxy-1:null) Checking pool: 1 for volume allocation [Vol[2|vm=2|ROOT]], maxSize : 79397126144, totalAllocatedSize : 0, askingSize : 0, allocated disable threshold: 0.85
2014-03-13 19:17:56,950 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) FirstFitStoragePoolAllocator returning 1 suitable storage pools
2014-03-13 19:17:56,950 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Trying to find a potenial host and associated storage pools from the suitable host/pool lists for this VM
2014-03-13 19:17:56,950 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking if host: 3 can access any suitable storage pool for volume: ROOT
2014-03-13 19:17:56,951 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Host: 3 cannot access pool: 1
2014-03-13 19:17:56,952 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking if host: 1 can access any suitable storage pool for volume: ROOT
2014-03-13 19:17:56,953 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Host: 1 can access pool: 1
2014-03-13 19:17:56,954 DEBUG [cloud.network.NetworkManagerImpl] (secstorage-1:null) Network id=203 is already implemented
2014-03-13 19:17:56,955 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Found a potential host id: 1 name: xenserver-003-cloud and associated storage pools for this VM
2014-03-13 19:17:56,957 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Returning Deployment Destination: Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(2|ROOT-->Pool(1))]
2014-03-13 19:17:56,958 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Deployment found - P0=VM[ConsoleProxy|v-2-VM], P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))] : Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(2|ROOT-->Pool(1))]
2014-03-13 19:17:56,976 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM state transitted from :Starting to Starting with event: OperationRetryvm's original host id: null new host id: 1 host id before state transition: null
2014-03-13 19:17:56,988 DEBUG [network.guru.PodBasedNetworkGuru] (secstorage-1:null) Allocated a nic NicProfile[287-72-723dbc83-60d8-4202-80c9-6ad19cce3719-192.168.0.16-null for VM[SecondaryStorageVm|s-72-VM]
2014-03-13 19:17:56,991 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) Hosts's actual total CPU: 15200 and CPU after applying overprovisioning: 15200
2014-03-13 19:17:56,991 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) We are allocating VM, increasing the used capacity of this host:1
2014-03-13 19:17:56,991 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) Current Used CPU: 0 , Free CPU:15200 ,Requested CPU: 500
2014-03-13 19:17:56,991 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) Current Used RAM: 0 , Free RAM:20340883456 ,Requested RAM: 1073741824
2014-03-13 19:17:56,991 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) CPU STATS after allocation: for host: 1, old used: 0, old reserved: 0, actual total: 15200, total with overprovisioning: 15200; new used:500, reserved:0; requested cpu:500,alloc_from_last:false
2014-03-13 19:17:56,994 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) RAM STATS after allocation: for host: 1, old used: 0, old reserved: 0, total: 20340883456; new used: 1073741824, reserved: 0; requested mem: 1073741824,alloc_from_last:false
2014-03-13 19:17:56,999 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) VM is being created in podId: 1
2014-03-13 19:17:57,000 DEBUG [cloud.storage.VolumeManagerImpl] (secstorage-1:null) Checking if we need to prepare 1 volumes for VM[SecondaryStorageVm|s-72-VM]
2014-03-13 19:17:57,012 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Network id=204 is already implemented
2014-03-13 19:17:57,014 DEBUG [storage.image.TemplateDataFactoryImpl] (secstorage-1:null) template 1 is already in store:1, type:Image
2014-03-13 19:17:57,020 DEBUG [storage.datastore.PrimaryDataStoreImpl] (secstorage-1:null) Not found (templateId:1poolId:1) in template_spool_ref, persisting it
2014-03-13 19:17:57,030 DEBUG [storage.image.TemplateDataFactoryImpl] (secstorage-1:null) template 1 is already in store:1, type:Primary
2014-03-13 19:17:57,032 DEBUG [storage.volume.VolumeServiceImpl] (secstorage-1:null) Found template routing-1 in storage pool 1 with VMTemplateStoragePool id: 141
2014-03-13 19:17:57,054 DEBUG [storage.volume.VolumeServiceImpl] (secstorage-1:null) Acquire lock on VMTemplateStoragePool 141 with timeout 3600 seconds
2014-03-13 19:17:57,060 INFO [storage.volume.VolumeServiceImpl] (secstorage-1:null) lock is acquired for VMTemplateStoragePool 141
2014-03-13 19:17:57,064 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking VirtualRouter to prepare for Nic[5-2-979b12db-3e66-4119-8a30-9057e6e27a44-192.168.0.31]
2014-03-13 19:17:57,069 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Asking SecurityGroupProvider to prepare for Nic[5-2-979b12db-3e66-4119-8a30-9057e6e27a44-192.168.0.31]
2014-03-13 19:17:57,077 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Network id=202 is already implemented
2014-03-13 19:17:57,128 DEBUG [storage.motion.AncientDataMotionStrategy] (secstorage-1:null) copyAsync inspecting src type TEMPLATE copyAsync inspecting dest type TEMPLATE
2014-03-13 19:17:57,148 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 2-1262289223: Sending { Cmd , MgmtId: 52238112301, via: 2, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/1/1/","origUrl":"http://download.cloud.com/templates/4.2/systemvmtemplate-2013-07-12-master-xen.vhd.bz2","uuid":"1257316e-aa94-11e3-b701-000c29a2562d","id":1,"format":"VHD","accountId":1,"checksum":"fb1b6e032a160d86f2c28feb5add6d83","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.0.177/export/secondary","_role":"Image"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"http://download.cloud.com/templates/4.2/systemvmtemplate-2013-07-12-master-xen.vhd.bz2","uuid":"1257316e-aa94-11e3-b701-000c29a2562d","id":1,"format":"VHD","accountId":1,"checksum":"fb1b6e032a160d86f2c28feb5add6d83","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"52901ac9-433c-3670-83ba-366a5ca42699","id":1,"poolType":"NetworkFilesystem","host":"192.168.0.177","path":"/export/primary","port":2049}},"name":"routing-1","hypervisorType":"XenServer"}},"executeInSequence":true,"wait":10800}}] }
2014-03-13 19:17:57,150 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 2-1262289223: Executing: { Cmd , MgmtId: 52238112301, via: 2, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/1/1/","origUrl":"http://download.cloud.com/templates/4.2/systemvmtemplate-2013-07-12-master-xen.vhd.bz2","uuid":"1257316e-aa94-11e3-b701-000c29a2562d","id":1,"format":"VHD","accountId":1,"checksum":"fb1b6e032a160d86f2c28feb5add6d83","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.0.177/export/secondary","_role":"Image"}},"name":"routing-1","hypervisorType":"XenServer"}},"destTO":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"origUrl":"http://download.cloud.com/templates/4.2/systemvmtemplate-2013-07-12-master-xen.vhd.bz2","uuid":"1257316e-aa94-11e3-b701-000c29a2562d","id":1,"format":"VHD","accountId":1,"checksum":"fb1b6e032a160d86f2c28feb5add6d83","hvm":false,"displayText":"SystemVM Template (XenServer)","imageDataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"52901ac9-433c-3670-83ba-366a5ca42699","id":1,"poolType":"NetworkFilesystem","host":"192.168.0.177","path":"/export/primary","port":2049}},"name":"routing-1","hypervisorType":"XenServer"}},"executeInSequence":true,"wait":10800}}] }
2014-03-13 19:17:57,150 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-463:null) Seq 2-1262289223: Executing request
2014-03-13 19:17:57,153 DEBUG [cloud.network.NetworkManagerImpl] (consoleproxy-1:null) Network id=201 is already implemented
2014-03-13 19:17:57,199 DEBUG [network.guru.PodBasedNetworkGuru] (consoleproxy-1:null) Allocated a nic NicProfile[7-2-979b12db-3e66-4119-8a30-9057e6e27a44-192.168.0.12-null for VM[ConsoleProxy|v-2-VM]
2014-03-13 19:17:57,209 DEBUG [cloud.storage.VolumeManagerImpl] (consoleproxy-1:null) Checking if we need to prepare 1 volumes for VM[ConsoleProxy|v-2-VM]
2014-03-13 19:17:57,223 DEBUG [storage.image.TemplateDataFactoryImpl] (consoleproxy-1:null) template 1 is already in store:1, type:Image
2014-03-13 19:17:57,234 DEBUG [storage.image.TemplateDataFactoryImpl] (consoleproxy-1:null) template 1 is already in store:1, type:Primary
2014-03-13 19:17:57,237 DEBUG [storage.volume.VolumeServiceImpl] (consoleproxy-1:null) Found template routing-1 in storage pool 1 with VMTemplateStoragePool id: 141
2014-03-13 19:17:57,251 DEBUG [storage.volume.VolumeServiceImpl] (consoleproxy-1:null) Acquire lock on VMTemplateStoragePool 141 with timeout 3600 seconds
2014-03-13 19:17:59,786 WARN [xen.resource.XenServerStorageProcessor] (DirectAgent-463:null) destoryVDIbyNameLabel failed due to there are 0 VDIs with name cloud-1b1855eb-a7bd-47ab-891c-2b4f9dcf0296
2014-03-13 19:17:59,799 WARN [xen.resource.XenServerStorageProcessor] (DirectAgent-463:null) can't mount 192.168.0.177:/export/secondary/template/tmpl/1/1 to /var/run/cloud_mount/e894384d-14c5-403a-ab7f-e43f96412868
2014-03-13 19:17:59,800 WARN [xen.resource.XenServerStorageProcessor] (DirectAgent-463:null) Catch Exception com.cloud.utils.exception.CloudRuntimeException for template + due to com.cloud.utils.exception.CloudRuntimeException: can't mount 192.168.0.177:/export/secondary/template/tmpl/1/1 to /var/run/cloud_mount/e894384d-14c5-403a-ab7f-e43f96412868
com.cloud.utils.exception.CloudRuntimeException: can't mount 192.168.0.177:/export/secondary/template/tmpl/1/1 to /var/run/cloud_mount/e894384d-14c5-403a-ab7f-e43f96412868
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.copy_vhd_from_secondarystorage(XenServerStorageProcessor.java:792)
at com.cloud.hypervisor.xen.resource.XenServerStorageProcessor.copyTemplateToPrimaryStorage(XenServerStorageProcessor.java:863)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:70)
at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
at com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:621)
at com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73)
at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
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.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
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:679)
2014-03-13 19:17:59,801 DEBUG [agent.manager.DirectAgentAttache] (Dire