[cloudstack-users:0412] Re: 【質問】システムVM2台の作成、起動について（CentOS6.6+KVM+ver4.1.1）

[永喜多]

こんにちは。永喜多です。


 ご指摘いただいた箇所などを修正しつつ、セットアップを

やりなおした結果、システムVMが2台および、仮想ルーターが起動しました。

ありがとうございます。


 localに指定したコンピュートオファリングを作成し、セキュリティグループで

さしあたり0.0.0.0/0で特定ポート郡の開放をしました。


 その後、テンプレートにあるCentOS5.5を起動しようと

したところ、Errorで停止しました。


 デプロイ時のログは以下のようになります。

agent.logは流れがなく、/var/log/libvirt/qemu/ にはVMの名前がありませんでした。


 [root ＠ cloud ~]# tail -f
/var/log/cloudstack/management/management-server.log

2015-01-10 13:32:48,751 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:32:50,237 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:32:50,238 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:32:50,238 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:32:51,737 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:32:51,738 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:32:51,738 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:32:53,251 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:32:53,251 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:32:53,252 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:32:54,751 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:32:54,751 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:32:54,752 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:32:54,935 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-5:null) SeqA 3-409: Processing Seq 3-409: { Cmd ,
MgmtId: -1, via: 3, Ver: v1, Flags: 11,
[{"ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }

2015-01-10 13:32:54,950 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-5:null) SeqA 3-409: Sending Seq 3-409: { Ans: ,
MgmtId: 129899290224676, via: 3, Ver: v1, Flags: 100010,
[{"AgentControlAnswer":{"result":true,"wait":0}}] }

2015-01-10 13:32:56,237 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:32:56,237 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:32:56,238 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:32:56,359 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null)
===START=== 192.168.0.2 -- GET
command=deployVirtualMachine&zoneId=fd74d286-9aab-4489-8c12-01a1e2ff3e91&templateId=1d4916ba-9836-11e4-88cc-001999b8c751&hypervisor=KVM&serviceOfferingId=48d211bc-7dc8-4012-b68d-7071ce52c62e&diskOfferingId=6b1bc6f6-3e68-4f35-a905-ca91bde106fa&securitygroupids=ccc2d973-05e8-40c5-8fdd-48d42479d5e3&response=json&sessionkey=s8ySfW8NWUOdK%2B%2BsZ1xdIh1ZkyM%3D&_=1420864377008


2015-01-10 13:32:56,376 DEBUG [cloud.api.ApiDispatcher]
(catalina-exec-6:null) InfrastructureEntity name
is:com.cloud.offering.ServiceOffering

2015-01-10 13:32:56,381 DEBUG [cloud.api.ApiDispatcher]
(catalina-exec-6:null) ControlledEntity name
is:com.cloud.template.VirtualMachineTemplate

2015-01-10 13:32:56,388 DEBUG [cloud.api.ApiDispatcher]
(catalina-exec-6:null) InfrastructureEntity name
is:com.cloud.offering.DiskOffering

2015-01-10 13:32:56,394 DEBUG [cloud.api.ApiDispatcher]
(catalina-exec-6:null) ControlledEntity name
is:com.cloud.network.security.SecurityGroup

2015-01-10 13:32:56,423 DEBUG
[cloud.configuration.ConfigurationManagerImpl] (catalina-exec-6:null)
Access granted to Acct[2-admin] to zone:1 by
DomainChecker_EnhancerByCloudStack_cfaf3ad0

2015-01-10 13:32:56,423 DEBUG
[cloud.configuration.ConfigurationManagerImpl] (catalina-exec-6:null)
Access granted to Acct[2-admin] to zone:1 by
DomainChecker_EnhancerByCloudStack_cfaf3ad0

2015-01-10 13:32:56,462 DEBUG [cloud.vm.UserVmManagerImpl]
(catalina-exec-6:null) Allocating in the DB for vm

2015-01-10 13:32:56,482 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(catalina-exec-6:null) Allocating entries for VM:
VM[User|af5e1fbb-bd95-4c3c-9aeb-aaed09115ecb]

2015-01-10 13:32:56,483 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(catalina-exec-6:null) Allocating nics for
VM[User|af5e1fbb-bd95-4c3c-9aeb-aaed09115ecb]

2015-01-10 13:32:56,485 DEBUG [cloud.network.NetworkManagerImpl]
(catalina-exec-6:null) Allocating nic for vm
VM[User|af5e1fbb-bd95-4c3c-9aeb-aaed09115ecb] in network Ntwk[204|Guest|6]
with requested profile NicProfile[0-0-null-null-null

2015-01-10 13:32:56,506 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(catalina-exec-6:null) Allocaing disks for
VM[User|af5e1fbb-bd95-4c3c-9aeb-aaed09115ecb]

2015-01-10 13:32:56,543 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(catalina-exec-6:null) Allocation completed for VM:
VM[User|af5e1fbb-bd95-4c3c-9aeb-aaed09115ecb]

2015-01-10 13:32:56,544 DEBUG [cloud.vm.UserVmManagerImpl]
(catalina-exec-6:null) Successfully allocated DB entry for
VM[User|af5e1fbb-bd95-4c3c-9aeb-aaed09115ecb]

2015-01-10 13:32:56,694 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-6:null) submit async job-33, details: AsyncJobVO {id:33,
userId: 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine,
instanceId: 25, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd,
cmdOriginator: null, cmdInfo:
{"id":"25","response":"json","templateId":"1d4916ba-9836-11e4-88cc-001999b8c751","sessionkey":"s8ySfW8NWUOdK++sZ1xdIh1ZkyM\u003d","ctxUserId":"2","hypervisor":"KVM","diskOfferingId":"6b1bc6f6-3e68-4f35-a905-ca91bde106fa","serviceOfferingId":"48d211bc-7dc8-4012-b68d-7071ce52c62e","_":"1420864377008","securitygroupids":"ccc2d973-05e8-40c5-8fdd-48d42479d5e3","ctxAccountId":"2","ctxStartEventId":"125","zoneId":"fd74d286-9aab-4489-8c12-01a1e2ff3e91"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
processStatus: 0, resultCode: 0, result: null, initMsid: 129899290224676,
completeMsid: null, lastUpdated: null, lastPolled: null, created: null}

2015-01-10 13:32:56,695 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-3:job-33) Executing
org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-33

2015-01-10 13:32:56,699 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null)
===END=== 192.168.0.2 -- GET
command=deployVirtualMachine&zoneId=fd74d286-9aab-4489-8c12-01a1e2ff3e91&templateId=1d4916ba-9836-11e4-88cc-001999b8c751&hypervisor=KVM&serviceOfferingId=48d211bc-7dc8-4012-b68d-7071ce52c62e&diskOfferingId=6b1bc6f6-3e68-4f35-a905-ca91bde106fa&securitygroupids=ccc2d973-05e8-40c5-8fdd-48d42479d5e3&response=json&sessionkey=s8ySfW8NWUOdK%2B%2BsZ1xdIh1ZkyM%3D&_=1420864377008


2015-01-10 13:32:56,709 DEBUG [cloud.api.ApiDispatcher]
(Job-Executor-3:job-33) InfrastructureEntity name
is:com.cloud.offering.ServiceOffering

2015-01-10 13:32:56,713 DEBUG [cloud.api.ApiDispatcher]
(Job-Executor-3:job-33) ControlledEntity name
is:com.cloud.template.VirtualMachineTemplate

2015-01-10 13:32:56,717 DEBUG [cloud.api.ApiDispatcher]
(Job-Executor-3:job-33) InfrastructureEntity name
is:com.cloud.offering.DiskOffering

2015-01-10 13:32:56,723 DEBUG [cloud.api.ApiDispatcher]
(Job-Executor-3:job-33) ControlledEntity name
is:com.cloud.network.security.SecurityGroup

2015-01-10 13:32:56,753 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is ready to launch secondary storage VM

2015-01-10 13:32:56,834 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) DeploymentPlanner allocation algorithm: random

2015-01-10 13:32:56,834 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) Trying to allocate a host and storage pools from
dc:1, pod:null,cluster:null, requested cpu: 1000, requested ram: 1073741824

2015-01-10 13:32:56,834 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) Is ROOT volume READY (pool already allocated)?: No

2015-01-10 13:32:56,834 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) Searching all possible resources under this Zone: 1

2015-01-10 13:32:56,838 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) Listing clusters in order of aggregate capacity,
that have (atleast one host with) enough CPU and RAM capacity under this
Zone: 1

2015-01-10 13:32:56,840 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) CPUOverprovisioningFactor considered: 1.0

2015-01-10 13:32:56,862 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) Checking resources in Cluster: 1 under Pod: 1

2015-01-10 13:32:56,867 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-3:job-33 FirstFitRoutingAllocator) Looking for hosts in dc: 1
pod:1 cluster:1

2015-01-10 13:32:56,872 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-3:job-33 FirstFitRoutingAllocator) FirstFitAllocator has 1
hosts to check for allocation: [Host[-1-Routing]]

2015-01-10 13:32:56,879 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-3:job-33 FirstFitRoutingAllocator) Found 1 hosts for
allocation after prioritization: [Host[-1-Routing]]

2015-01-10 13:32:56,880 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-3:job-33 FirstFitRoutingAllocator) Looking for speed=1000Mhz,
Ram=1024

2015-01-10 13:32:56,885 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-3:job-33 FirstFitRoutingAllocator) Checking if host: 1 has
enough capacity for requested CPU: 1000 and requested RAM: 1073741824 ,
cpuOverprovisioningFactor: 1.0

2015-01-10 13:32:56,893 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-3:job-33 FirstFitRoutingAllocator) Hosts's actual total CPU:
19200 and CPU after applying overprovisioning: 19200

2015-01-10 13:32:56,893 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-3:job-33 FirstFitRoutingAllocator) Free CPU: 12100 ,
Requested CPU: 1000

2015-01-10 13:32:56,893 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-3:job-33 FirstFitRoutingAllocator) Free RAM: 6354173952 ,
Requested RAM: 1073741824

2015-01-10 13:32:56,893 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-3:job-33 FirstFitRoutingAllocator) Host has enough CPU and
RAM available

2015-01-10 13:32:56,894 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-3:job-33 FirstFitRoutingAllocator) STATS: Can alloc CPU from
host: 1, used: 1500, reserved: 5600, actual total: 19200, total with
overprovisioning: 19200; requested cpu:1000,alloc_from_last_host?:false
,considerReservedCapacity?: true

2015-01-10 13:32:56,894 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-3:job-33 FirstFitRoutingAllocator) STATS: Can alloc MEM from
host: 1, used: 1476395008, reserved: 8589934592, total: 16420503552;
requested mem: 1073741824,alloc_from_last_host?:false
,considerReservedCapacity?: true

2015-01-10 13:32:56,894 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-3:job-33 FirstFitRoutingAllocator) Found a suitable host,
adding to list: 1

2015-01-10 13:32:56,894 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-3:job-33 FirstFitRoutingAllocator) Host Allocator returning 1
suitable hosts

2015-01-10 13:32:56,900 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) Checking suitable pools for volume (Id, Type):
(28,ROOT)

2015-01-10 13:32:56,901 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) We need to allocate new storagepool for this volume

2015-01-10 13:32:56,904 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) Calling StoragePoolAllocators to find suitable
pools

2015-01-10 13:32:56,907 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-3:job-33)
Looking for pools in dc: 1 pod:1 cluster:1

2015-01-10 13:32:56,912 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-3:job-33)
FirstFitStoragePoolAllocator has 1 pools to check for allocation

2015-01-10 13:32:56,912 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-3:job-33)
Checking if storage pool is suitable, name: cloud.priv ,poolId: 200

2015-01-10 13:32:56,912 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-3:job-33) Is
localStorageAllocationNeeded? false

2015-01-10 13:32:56,912 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-3:job-33) Is
storage pool shared? false

2015-01-10 13:32:56,912 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-3:job-33)
StoragePool is not of correct type, skipping this pool

2015-01-10 13:32:56,913 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-3:job-33)
FirstFitStoragePoolAllocator returning 0 suitable storage pools

2015-01-10 13:32:56,913 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) No suitable pools found for volume:
Vol[28|vm=25|ROOT] under cluster: 1

2015-01-10 13:32:56,913 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) No suitable pools found

2015-01-10 13:32:56,913 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) No suitable storagePools found under this Cluster:
1

2015-01-10 13:32:56,913 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-3:job-33) Could not find suitable Deployment Destination for
this VM under any clusters, returning.

2015-01-10 13:32:56,918 DEBUG [cloud.vm.UserVmManagerImpl]
(Job-Executor-3:job-33) Destroying vm
VM[User|af5e1fbb-bd95-4c3c-9aeb-aaed09115ecb] as it failed to create on
Host with Id:null

2015-01-10 13:32:56,947 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-3:job-33) VM state transitted from :Stopped to Error with
event: OperationFailedToErrorvm's original host id: null new host id: null
host id before state transition: null

2015-01-10 13:32:57,147 INFO [user.vm.DeployVMCmd] (Job-Executor-3:job-33)
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|af5e1fbb-bd95-4c3c-9aeb-aaed09115ecb]Scope=interface
com.cloud.dc.DataCenter; id=1

2015-01-10 13:32:57,148 INFO [user.vm.DeployVMCmd] (Job-Executor-3:job-33)
Unable to create a deployment for
VM[User|af5e1fbb-bd95-4c3c-9aeb-aaed09115ecb]

com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|af5e1fbb-bd95-4c3c-9aeb-aaed09115ecb]Scope=interface
com.cloud.dc.DataCenter; id=1

at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:186)


at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:198)


at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3870)


at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3464)


at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3450)


at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)


at
org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:379)


at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:162)

at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437)

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)

at java.util.concurrent.FutureTask.run(FutureTask.java:262)

at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)


at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)


at java.lang.Thread.run(Thread.java:745)

2015-01-10 13:32:57,149 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-3:job-33) Complete async job-33, jobStatus: 2, resultCode:
530, result: Error Code: 533 Error text: Unable to create a deployment for
VM[User|af5e1fbb-bd95-4c3c-9aeb-aaed09115ecb]

2015-01-10 13:32:57,374 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is ready to launch console proxy

2015-01-10 13:32:57,738 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:32:57,738 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:32:57,739 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:32:57,793 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers to update status.

2015-01-10 13:32:57,796 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.

2015-01-10 13:32:57,829 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers to update status.

2015-01-10 13:32:57,831 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.

2015-01-10 13:32:59,248 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:32:59,248 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:32:59,248 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:32:59,728 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null)
===START=== 192.168.0.2 -- GET
command=queryAsyncJobResult&jobId=cd99c6e7-dc9b-41da-8276-4e30b5b7888e&response=json&sessionkey=s8ySfW8NWUOdK%2B%2BsZ1xdIh1ZkyM%3D&_=1420864380375


2015-01-10 13:32:59,757 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-8:null) Async job-33 completed

2015-01-10 13:32:59,771 DEBUG [cloud.api.ApiServlet] (catalina-exec-8:null)
===END=== 192.168.0.2 -- GET
command=queryAsyncJobResult&jobId=cd99c6e7-dc9b-41da-8276-4e30b5b7888e&response=json&sessionkey=s8ySfW8NWUOdK%2B%2BsZ1xdIh1ZkyM%3D&_=1420864380375


2015-01-10 13:32:59,779 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null)
===START=== 192.168.0.2 -- GET
command=listVirtualMachines&id=af5e1fbb-bd95-4c3c-9aeb-aaed09115ecb&response=json&sessionkey=s8ySfW8NWUOdK%2B%2BsZ1xdIh1ZkyM%3D&_=1420864380429


2015-01-10 13:32:59,828 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null)
===END=== 192.168.0.2 -- GET
command=listVirtualMachines&id=af5e1fbb-bd95-4c3c-9aeb-aaed09115ecb&response=json&sessionkey=s8ySfW8NWUOdK%2B%2BsZ1xdIh1ZkyM%3D&_=1420864380429


2015-01-10 13:32:59,936 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-3:null) SeqA 3-410: Processing Seq 3-410: { Cmd ,
MgmtId: -1, via: 3, Ver: v1, Flags: 11,
[{"ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }

2015-01-10 13:32:59,951 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-3:null) SeqA 3-410: Sending Seq 3-410: { Ans: ,
MgmtId: 129899290224676, via: 3, Ver: v1, Flags: 100010,
[{"AgentControlAnswer":{"result":true,"wait":0}}] }

2015-01-10 13:33:00,750 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:33:00,750 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:33:00,751 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:33:02,237 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:33:02,238 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:33:02,238 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:33:03,341 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-6:null) Ping from 1

^C

[root ＠ cloud ~]#




 上記から、リソースは空いていそうでしたが、リソースの空きがないのかと、Runningの

CentOS7を入れたVMを、グローバル設定から修正を入れて即時削除しています。

※KVMなのでqcow2のところが、ISOでしたが


 ▽変更したパラメータ

expunge.interval

expunge.delay


 その後、以下にてあらためてテンプレートのVMを起動しました。



 [root ＠ cloud ~]# tail -f
/var/log/cloudstack/management/management-server.log

2015-01-10 13:45:14,250 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:45:14,251 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:45:15,032 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-8:null) SeqA 3-516: Processing Seq 3-516: { Cmd ,
MgmtId: -1, via: 3, Ver: v1, Flags: 11,
[{"ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }

2015-01-10 13:45:15,059 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-8:null) SeqA 3-516: Sending Seq 3-516: { Ans: ,
MgmtId: 129899290224676, via: 3, Ver: v1, Flags: 100010,
[{"AgentControlAnswer":{"result":true,"wait":0}}] }

2015-01-10 13:45:15,737 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:45:15,737 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:45:15,738 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:45:17,237 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:45:17,237 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:45:17,238 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:45:18,750 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:45:18,751 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:45:18,751 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:45:20,250 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:45:20,250 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:45:20,251 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:45:21,737 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:45:21,738 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:45:21,738 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:45:22,088 DEBUG [cloud.api.ApiServlet]
(catalina-exec-19:null) ===START=== 192.168.0.2 -- GET
command=deployVirtualMachine&zoneId=fd74d286-9aab-4489-8c12-01a1e2ff3e91&templateId=1d4916ba-9836-11e4-88cc-001999b8c751&hypervisor=KVM&serviceOfferingId=b37dda89-0f61-404d-90ac-b18bbfe3e7e7&diskOfferingId=6b1bc6f6-3e68-4f35-a905-ca91bde106fa&securitygroupids=ccc2d973-05e8-40c5-8fdd-48d42479d5e3&response=json&sessionkey=s8ySfW8NWUOdK%2B%2BsZ1xdIh1ZkyM%3D&_=1420865122737


2015-01-10 13:45:22,104 DEBUG [cloud.api.ApiDispatcher]
(catalina-exec-19:null) InfrastructureEntity name
is:com.cloud.offering.ServiceOffering

2015-01-10 13:45:22,108 DEBUG [cloud.api.ApiDispatcher]
(catalina-exec-19:null) ControlledEntity name
is:com.cloud.template.VirtualMachineTemplate

2015-01-10 13:45:22,112 DEBUG [cloud.api.ApiDispatcher]
(catalina-exec-19:null) InfrastructureEntity name
is:com.cloud.offering.DiskOffering

2015-01-10 13:45:22,117 DEBUG [cloud.api.ApiDispatcher]
(catalina-exec-19:null) ControlledEntity name
is:com.cloud.network.security.SecurityGroup

2015-01-10 13:45:22,142 DEBUG
[cloud.configuration.ConfigurationManagerImpl] (catalina-exec-19:null)
Access granted to Acct[2-admin] to zone:1 by
DomainChecker_EnhancerByCloudStack_cfaf3ad0

2015-01-10 13:45:22,142 DEBUG
[cloud.configuration.ConfigurationManagerImpl] (catalina-exec-19:null)
Access granted to Acct[2-admin] to zone:1 by
DomainChecker_EnhancerByCloudStack_cfaf3ad0

2015-01-10 13:45:22,178 DEBUG [cloud.vm.UserVmManagerImpl]
(catalina-exec-19:null) Allocating in the DB for vm

2015-01-10 13:45:22,202 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(catalina-exec-19:null) Allocating entries for VM:
VM[User|edc76e44-7263-4a55-8c7d-d9dfcc3f5b65]

2015-01-10 13:45:22,203 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(catalina-exec-19:null) Allocating nics for
VM[User|edc76e44-7263-4a55-8c7d-d9dfcc3f5b65]

2015-01-10 13:45:22,205 DEBUG [cloud.network.NetworkManagerImpl]
(catalina-exec-19:null) Allocating nic for vm
VM[User|edc76e44-7263-4a55-8c7d-d9dfcc3f5b65] in network Ntwk[204|Guest|6]
with requested profile NicProfile[0-0-null-null-null

2015-01-10 13:45:22,227 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(catalina-exec-19:null) Allocaing disks for
VM[User|edc76e44-7263-4a55-8c7d-d9dfcc3f5b65]

2015-01-10 13:45:22,259 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(catalina-exec-19:null) Allocation completed for VM:
VM[User|edc76e44-7263-4a55-8c7d-d9dfcc3f5b65]

2015-01-10 13:45:22,259 DEBUG [cloud.vm.UserVmManagerImpl]
(catalina-exec-19:null) Successfully allocated DB entry for
VM[User|edc76e44-7263-4a55-8c7d-d9dfcc3f5b65]

2015-01-10 13:45:22,403 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-19:null) submit async job-38, details: AsyncJobVO {id:38,
userId: 2, accountId: 2, sessionKey: null, instanceType: VirtualMachine,
instanceId: 28, cmd: org.apache.cloudstack.api.command.user.vm.DeployVMCmd,
cmdOriginator: null, cmdInfo:
{"id":"28","response":"json","templateId":"1d4916ba-9836-11e4-88cc-001999b8c751","sessionkey":"s8ySfW8NWUOdK++sZ1xdIh1ZkyM\u003d","ctxUserId":"2","hypervisor":"KVM","diskOfferingId":"6b1bc6f6-3e68-4f35-a905-ca91bde106fa","serviceOfferingId":"b37dda89-0f61-404d-90ac-b18bbfe3e7e7","_":"1420865122737","securitygroupids":"ccc2d973-05e8-40c5-8fdd-48d42479d5e3","ctxAccountId":"2","ctxStartEventId":"143","zoneId":"fd74d286-9aab-4489-8c12-01a1e2ff3e91"},
cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0,
processStatus: 0, resultCode: 0, result: null, initMsid: 129899290224676,
completeMsid: null, lastUpdated: null, lastPolled: null, created: null}

2015-01-10 13:45:22,405 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-8:job-38) Executing
org.apache.cloudstack.api.command.user.vm.DeployVMCmd for job-38

2015-01-10 13:45:22,409 DEBUG [cloud.api.ApiServlet]
(catalina-exec-19:null) ===END=== 192.168.0.2 -- GET
command=deployVirtualMachine&zoneId=fd74d286-9aab-4489-8c12-01a1e2ff3e91&templateId=1d4916ba-9836-11e4-88cc-001999b8c751&hypervisor=KVM&serviceOfferingId=b37dda89-0f61-404d-90ac-b18bbfe3e7e7&diskOfferingId=6b1bc6f6-3e68-4f35-a905-ca91bde106fa&securitygroupids=ccc2d973-05e8-40c5-8fdd-48d42479d5e3&response=json&sessionkey=s8ySfW8NWUOdK%2B%2BsZ1xdIh1ZkyM%3D&_=1420865122737


2015-01-10 13:45:22,417 DEBUG [cloud.api.ApiDispatcher]
(Job-Executor-8:job-38) InfrastructureEntity name
is:com.cloud.offering.ServiceOffering

2015-01-10 13:45:22,421 DEBUG [cloud.api.ApiDispatcher]
(Job-Executor-8:job-38) ControlledEntity name
is:com.cloud.template.VirtualMachineTemplate

2015-01-10 13:45:22,425 DEBUG [cloud.api.ApiDispatcher]
(Job-Executor-8:job-38) InfrastructureEntity name
is:com.cloud.offering.DiskOffering

2015-01-10 13:45:22,431 DEBUG [cloud.api.ApiDispatcher]
(Job-Executor-8:job-38) ControlledEntity name
is:com.cloud.network.security.SecurityGroup

2015-01-10 13:45:22,542 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) DeploymentPlanner allocation algorithm: random

2015-01-10 13:45:22,542 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) Trying to allocate a host and storage pools from
dc:1, pod:null,cluster:null, requested cpu: 5600, requested ram: 8589934592

2015-01-10 13:45:22,542 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) Is ROOT volume READY (pool already allocated)?: No

2015-01-10 13:45:22,542 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) Searching all possible resources under this Zone: 1

2015-01-10 13:45:22,547 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) Listing clusters in order of aggregate capacity,
that have (atleast one host with) enough CPU and RAM capacity under this
Zone: 1

2015-01-10 13:45:22,549 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) CPUOverprovisioningFactor considered: 1.0

2015-01-10 13:45:22,572 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) Checking resources in Cluster: 1 under Pod: 1

2015-01-10 13:45:22,578 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-8:job-38 FirstFitRoutingAllocator) Looking for hosts in dc: 1
pod:1 cluster:1

2015-01-10 13:45:22,582 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-8:job-38 FirstFitRoutingAllocator) FirstFitAllocator has 1
hosts to check for allocation: [Host[-1-Routing]]

2015-01-10 13:45:22,588 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-8:job-38 FirstFitRoutingAllocator) Found 1 hosts for
allocation after prioritization: [Host[-1-Routing]]

2015-01-10 13:45:22,588 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-8:job-38 FirstFitRoutingAllocator) Looking for speed=5600Mhz,
Ram=8192

2015-01-10 13:45:22,593 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-8:job-38 FirstFitRoutingAllocator) Checking if host: 1 has
enough capacity for requested CPU: 5600 and requested RAM: 8589934592 ,
cpuOverprovisioningFactor: 1.0

2015-01-10 13:45:22,600 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-8:job-38 FirstFitRoutingAllocator) Hosts's actual total CPU:
19200 and CPU after applying overprovisioning: 19200

2015-01-10 13:45:22,600 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-8:job-38 FirstFitRoutingAllocator) Free CPU: 17700 ,
Requested CPU: 5600

2015-01-10 13:45:22,600 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-8:job-38 FirstFitRoutingAllocator) Free RAM: 14944108544 ,
Requested RAM: 8589934592

2015-01-10 13:45:22,600 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-8:job-38 FirstFitRoutingAllocator) Host has enough CPU and
RAM available

2015-01-10 13:45:22,601 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-8:job-38 FirstFitRoutingAllocator) STATS: Can alloc CPU from
host: 1, used: 1500, reserved: 0, actual total: 19200, total with
overprovisioning: 19200; requested cpu:5600,alloc_from_last_host?:false
,considerReservedCapacity?: true

2015-01-10 13:45:22,601 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-8:job-38 FirstFitRoutingAllocator) STATS: Can alloc MEM from
host: 1, used: 1476395008, reserved: 0, total: 16420503552; requested mem:
8589934592,alloc_from_last_host?:false ,considerReservedCapacity?: true

2015-01-10 13:45:22,601 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-8:job-38 FirstFitRoutingAllocator) Found a suitable host,
adding to list: 1

2015-01-10 13:45:22,601 DEBUG [allocator.impl.FirstFitAllocator]
(Job-Executor-8:job-38 FirstFitRoutingAllocator) Host Allocator returning 1
suitable hosts

2015-01-10 13:45:22,606 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) Checking suitable pools for volume (Id, Type):
(33,ROOT)

2015-01-10 13:45:22,607 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) We need to allocate new storagepool for this volume

2015-01-10 13:45:22,609 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) Calling StoragePoolAllocators to find suitable
pools

2015-01-10 13:45:22,610 DEBUG [storage.allocator.LocalStoragePoolAllocator]
(Job-Executor-8:job-38) LocalStoragePoolAllocator trying to find storage
pool to fit the vm

2015-01-10 13:45:22,610 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-8:job-38)
Looking for pools in dc: 1 pod:1 cluster:1

2015-01-10 13:45:22,614 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-8:job-38)
FirstFitStoragePoolAllocator has 1 pools to check for allocation

2015-01-10 13:45:22,614 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-8:job-38)
Checking if storage pool is suitable, name: cloud.priv ,poolId: 200

2015-01-10 13:45:22,614 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-8:job-38) Is
localStorageAllocationNeeded? true

2015-01-10 13:45:22,614 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-8:job-38) Is
storage pool shared? false

2015-01-10 13:45:22,620 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-8:job-38) Checking pool 200 for storage, totalSize:
1048881356800, usedBytes: 1165926400, usedPct: 0.0011115903552305375,
disable threshold: 0.85

2015-01-10 13:45:22,642 DEBUG [cloud.storage.StorageManagerImpl]
(Job-Executor-8:job-38) Checking pool: 200 for volume allocation
[Vol[33|vm=28|ROOT]], maxSize : 1048881356800, totalAllocatedSize :
2495488000, askingSize : 8589934592, allocated disable threshold: 0.85

2015-01-10 13:45:22,642 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-8:job-38)
FirstFitStoragePoolAllocator returning 1 suitable storage pools

2015-01-10 13:45:22,645 DEBUG [storage.allocator.LocalStoragePoolAllocator]
(Job-Executor-8:job-38) Found suitable local storage pool 200, adding to
list

2015-01-10 13:45:22,645 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-8:job-38)
Looking for pools in dc: 1 pod:1 cluster:1

2015-01-10 13:45:22,649 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-8:job-38)
FirstFitStoragePoolAllocator has 1 pools to check for allocation

2015-01-10 13:45:22,649 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-8:job-38)
Checking if storage pool is suitable, name: cloud.priv ,poolId: 200

2015-01-10 13:45:22,649 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-8:job-38)
StoragePool is in avoid set, skipping this pool

2015-01-10 13:45:22,649 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-8:job-38)
FirstFitStoragePoolAllocator returning 0 suitable storage pools

2015-01-10 13:45:22,649 DEBUG [storage.allocator.LocalStoragePoolAllocator]
(Job-Executor-8:job-38) LocalStoragePoolAllocator returning 1 suitable
storage pools

2015-01-10 13:45:22,649 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) Checking suitable pools for volume (Id, Type):
(34,DATADISK)

2015-01-10 13:45:22,649 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) We need to allocate new storagepool for this volume

2015-01-10 13:45:22,652 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) Calling StoragePoolAllocators to find suitable
pools

2015-01-10 13:45:22,652 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-8:job-38)
Looking for pools in dc: 1 pod:1 cluster:1

2015-01-10 13:45:22,656 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-8:job-38)
FirstFitStoragePoolAllocator has 1 pools to check for allocation

2015-01-10 13:45:22,656 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-8:job-38)
Checking if storage pool is suitable, name: cloud.priv ,poolId: 200

2015-01-10 13:45:22,656 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-8:job-38) Is
localStorageAllocationNeeded? false

2015-01-10 13:45:22,656 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-8:job-38) Is
storage pool shared? false

2015-01-10 13:45:22,656 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (Job-Executor-8:job-38)
StoragePool is not of correct type, skipping this pool

2015-01-10 13:45:22,656 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (Job-Executor-8:job-38)
FirstFitStoragePoolAllocator returning 0 suitable storage pools

2015-01-10 13:45:22,656 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) No suitable pools found for volume:
Vol[34|vm=28|DATADISK] under cluster: 1

2015-01-10 13:45:22,657 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) No suitable pools found

2015-01-10 13:45:22,657 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) No suitable storagePools found under this Cluster:
1

2015-01-10 13:45:22,657 DEBUG [cloud.deploy.FirstFitPlanner]
(Job-Executor-8:job-38) Could not find suitable Deployment Destination for
this VM under any clusters, returning.

2015-01-10 13:45:22,661 DEBUG [cloud.vm.UserVmManagerImpl]
(Job-Executor-8:job-38) Destroying vm
VM[User|edc76e44-7263-4a55-8c7d-d9dfcc3f5b65] as it failed to create on
Host with Id:null

2015-01-10 13:45:22,689 DEBUG [cloud.capacity.CapacityManagerImpl]
(Job-Executor-8:job-38) VM state transitted from :Stopped to Error with
event: OperationFailedToErrorvm's original host id: null new host id: null
host id before state transition: null

2015-01-10 13:45:22,885 INFO [user.vm.DeployVMCmd] (Job-Executor-8:job-38)
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|edc76e44-7263-4a55-8c7d-d9dfcc3f5b65]Scope=interface
com.cloud.dc.DataCenter; id=1

2015-01-10 13:45:22,885 INFO [user.vm.DeployVMCmd] (Job-Executor-8:job-38)
Unable to create a deployment for
VM[User|edc76e44-7263-4a55-8c7d-d9dfcc3f5b65]

com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[User|edc76e44-7263-4a55-8c7d-d9dfcc3f5b65]Scope=interface
com.cloud.dc.DataCenter; id=1

at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:186)


at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:198)


at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3870)


at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3464)


at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3450)


at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)


at
org.apache.cloudstack.api.command.user.vm.DeployVMCmd.execute(DeployVMCmd.java:379)


at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:162)

at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:437)

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)

at java.util.concurrent.FutureTask.run(FutureTask.java:262)

at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)


at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)


at java.lang.Thread.run(Thread.java:745)

2015-01-10 13:45:22,886 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-8:job-38) Complete async job-38, jobStatus: 2, resultCode:
530, result: Error Code: 533 Error text: Unable to create a deployment for
VM[User|edc76e44-7263-4a55-8c7d-d9dfcc3f5b65]

2015-01-10 13:45:23,237 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:45:23,238 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:45:23,238 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:45:24,750 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:45:24,750 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:45:24,751 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:45:25,033 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-9:null) SeqA 3-517: Processing Seq 3-517: { Cmd ,
MgmtId: -1, via: 3, Ver: v1, Flags: 11,
[{"ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }

2015-01-10 13:45:25,047 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-9:null) SeqA 3-517: Sending Seq 3-517: { Ans: ,
MgmtId: 129899290224676, via: 3, Ver: v1, Flags: 100010,
[{"AgentControlAnswer":{"result":true,"wait":0}}] }

2015-01-10 13:45:25,435 DEBUG [cloud.api.ApiServlet]
(catalina-exec-15:null) ===START=== 192.168.0.2 -- GET
command=queryAsyncJobResult&jobId=732ab86a-35a2-4c42-ad2b-dcfac61b38a4&response=json&sessionkey=s8ySfW8NWUOdK%2B%2BsZ1xdIh1ZkyM%3D&_=1420865126085


2015-01-10 13:45:25,463 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-15:null) Async job-38 completed

2015-01-10 13:45:25,476 DEBUG [cloud.api.ApiServlet]
(catalina-exec-15:null) ===END=== 192.168.0.2 -- GET
command=queryAsyncJobResult&jobId=732ab86a-35a2-4c42-ad2b-dcfac61b38a4&response=json&sessionkey=s8ySfW8NWUOdK%2B%2BsZ1xdIh1ZkyM%3D&_=1420865126085


2015-01-10 13:45:25,483 DEBUG [cloud.api.ApiServlet]
(catalina-exec-21:null) ===START=== 192.168.0.2 -- GET
command=listVirtualMachines&id=edc76e44-7263-4a55-8c7d-d9dfcc3f5b65&response=json&sessionkey=s8ySfW8NWUOdK%2B%2BsZ1xdIh1ZkyM%3D&_=1420865126133


2015-01-10 13:45:25,529 DEBUG [cloud.api.ApiServlet]
(catalina-exec-21:null) ===END=== 192.168.0.2 -- GET
command=listVirtualMachines&id=edc76e44-7263-4a55-8c7d-d9dfcc3f5b65&response=json&sessionkey=s8ySfW8NWUOdK%2B%2BsZ1xdIh1ZkyM%3D&_=1420865126133


2015-01-10 13:45:25,848 DEBUG [cloud.server.StatsCollector]
(StatsCollector-3:null) StorageCollector is running...

2015-01-10 13:45:25,922 DEBUG [agent.transport.Request]
(StatsCollector-3:null) Seq 4-1496383559: Received: { Ans: , MgmtId:
129899290224676, via: 4, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }

2015-01-10 13:45:26,001 DEBUG [agent.transport.Request]
(StatsCollector-3:null) Seq 1-1362886802: Received: { Ans: , MgmtId:
129899290224676, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }

2015-01-10 13:45:26,250 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:45:26,251 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:45:26,251 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:45:26,752 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is ready to launch secondary storage VM

2015-01-10 13:45:27,374 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is ready to launch console proxy

2015-01-10 13:45:27,738 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:45:27,738 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:45:27,738 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:45:27,793 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers to update status.

2015-01-10 13:45:27,796 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.

2015-01-10 13:45:27,829 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers to update status.

2015-01-10 13:45:27,832 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.

2015-01-10 13:45:27,922 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Running Capacity Checker ...

2015-01-10 13:45:27,923 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) recalculating system capacity

2015-01-10 13:45:27,923 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Executing cpu/ram capacity update

2015-01-10 13:45:27,943 DEBUG [cloud.capacity.CapacityManagerImpl]
(CapacityChecker:null) Found 3 VMs on host 1

2015-01-10 13:45:27,944 DEBUG [cloud.capacity.CapacityManagerImpl]
(CapacityChecker:null) Found 0 VM, not running on host 1

2015-01-10 13:45:27,948 DEBUG [cloud.capacity.CapacityManagerImpl]
(CapacityChecker:null) No need to calibrate cpu capacity, host:1 usedCpu:
1500 reservedCpu: 0

2015-01-10 13:45:27,948 DEBUG [cloud.capacity.CapacityManagerImpl]
(CapacityChecker:null) No need to calibrate memory capacity, host:1
usedMem: 1476395008 reservedMem: 0

2015-01-10 13:45:27,948 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Done executing cpu/ram capacity update

2015-01-10 13:45:27,948 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Executing storage capacity update

2015-01-10 13:45:27,966 DEBUG [cloud.storage.StorageManagerImpl]
(CapacityChecker:null) Successfully set Capacity - 1048881356800 for
capacity type - 9 , DataCenterId - 1, HostOrPoolId - 200, PodId 1

2015-01-10 13:45:27,966 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Done executing storage capacity update

2015-01-10 13:45:27,966 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Executing capacity updates for public ip and Vlans

2015-01-10 13:45:27,996 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Done capacity updates for public ip and Vlans

2015-01-10 13:45:27,997 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Executing capacity updates for private ip

2015-01-10 13:45:28,014 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Done executing capacity updates for private ip

2015-01-10 13:45:28,014 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Done recalculating system capacity

2015-01-10 13:45:28,058 DEBUG [cloud.alert.AlertManagerImpl]
(CapacityChecker:null) Done running Capacity Checker ...

2015-01-10 13:45:28,298 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-12:null) Ping from 3

2015-01-10 13:45:29,238 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:45:29,238 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:45:29,238 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:45:30,751 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:45:30,751 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:45:30,752 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

2015-01-10 13:45:32,251 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:2,
nodeIP:192.168.0.10

2015-01-10 13:45:32,251 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10

2015-01-10 13:45:32,252 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 2 is detected inactive by
timestamp but is pingable

^C

[root ＠ cloud ~]#



 VMを削除したことで使える容量は増えたようですが、

テンプレートからCentOS5.5をデプロイしようとすると、

継続してErrorが出る状態となっております。


 なお、過去のMLに、仮想化の有効化について記載がありましたので、

BIOS上であらためて確認したところenabledでした。


 また、カーネルモジュールも表示されておりました。


 [root ＠ cloud ~]# lsmod | grep kvm

kvm_amd 40735 9

kvm 337772 1 kvm_amd


ここで詰まっている状況となります。

2015-01-09 11:48 GMT+09:00 永喜多 <n ＠ gakita.me>:

> 中谷さん
>
>
> 検証までして頂き、ありがとうございます。
>
> 永喜多です。
>
>
> 再度OS再インストールからセットアップをしなおました。
>
> また、ご指摘の箇所について、確認の上設定致しました。
>
>
>  (1)ローカルストレージ利用時の注意点
>
> 「CloudStackを使用したことがあるので、このガイドをスキップする。」
>
> ↓
>
> Local Storage Enabled
>
> こちら、チェックをしていなかったため、チェックをして実行いたしました。
>
> すると、WebUI上のインストーラの動きでは、問題なく終了しております。
>
> ※プライマリ、セカンダリストレージ共にNFSとなります
>
> グローバル設定の、system.vm.use.local.storageはtrueにし、サーバ毎再起動しております。
>
>
>  (2)management-serverのIPアドレス設定の確認
>
> propertiesの設定状況は、特に問題が見受けられない印象がありました。
>
> [root ＠ localhost ~]# cat /etc/cloudstack/management/db.properties | grep
> cluster.node.IP=
>
> cluster.node.IP=192.168.0.10
>
> [root ＠ localhost ~]# cat /etc/cloudstack/management/db.properties | grep
> cloud.host
>
> db.cloud.host=localhost
>
>
>
>  (3)仮想スイッチ名の確認
>
> 確認したところ、デフォルトゲートウェイになっておりましたので、変更致しました。
>
>
>  WebUIログイン後、【インフラストラクチャ】>【該当のゾーン】>【Physical Network】タブ>
>
> 【Physical Network 1】を押下>ゲスト&管理の、【構成】>【詳細】から、【KVMトラフィックのラベル】
>
> を「デフォルトゲートウェイを使用」から、cloudbr0に変更致しました。
>
>
>  (4)その他
>
> secstorage.allowed.internal.sitesに設定はしておりませんでしたので、10.0.0.0/24を設定致しました。
>
>
>
> ほか、ifconfigで、自分では用途がわからないcloud0が見えております。
>
> [root ＠ localhost ~]# ifconfig
>
> cloud0 Link encap:Ethernet HWaddr 06:D2:8C:26:6D:D7
>
> inet addr:169.254.0.1 Bcast:169.254.255.255 Mask:255.255.0.0
>
> inet6 addr: fe80::4d2:8cff:fe26:6dd7/64 Scope:Link
>
> UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
>
> RX packets:0 errors:0 dropped:0 overruns:0 frame:0
>
> TX packets:6 errors:0 dropped:0 overruns:0 carrier:0
>
> collisions:0 txqueuelen:0
>
> RX bytes:0 (0.0 b) TX bytes:468 (468.0 b)
>
>  cloudbr0 Link encap:Ethernet HWaddr 00:19:99:B8:C7:51
>
> inet addr:192.168.0.10 Bcast:192.168.0.255 Mask:255.255.255.0
>
> inet6 addr: 240f:3:50fb:1:219:99ff:feb8:c751/64 Scope:Global
>
> inet6 addr: fe80::219:99ff:feb8:c751/64 Scope:Link
>
> UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
>
> RX packets:2232 errors:0 dropped:0 overruns:0 frame:0
>
> TX packets:2578 errors:0 dropped:0 overruns:0 carrier:0
>
> collisions:0 txqueuelen:0
>
> RX bytes:460822 (450.0 KiB) TX bytes:4766553 (4.5 MiB)
>
>  eth0 Link encap:Ethernet HWaddr 00:19:99:B8:C7:51
>
> inet6 addr: fe80::219:99ff:feb8:c751/64 Scope:Link
>
> UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
>
> RX packets:3961 errors:0 dropped:0 overruns:0 frame:0
>
> TX packets:4469 errors:0 dropped:0 overruns:0 carrier:0
>
> collisions:0 txqueuelen:1000
>
> RX bytes:1088806 (1.0 MiB) TX bytes:4892195 (4.6 MiB)
>
> Memory:ff180000-ff1fffff
>
>  eth1 Link encap:Ethernet HWaddr 00:19:99:B8:C7:52
>
> UP BROADCAST MULTICAST MTU:1500 Metric:1
>
> RX packets:0 errors:0 dropped:0 overruns:0 frame:0
>
> TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
>
> collisions:0 txqueuelen:1000
>
> RX bytes:0 (0.0 b) TX bytes:0 (0.0 b)
>
> Memory:ff100000-ff17ffff
>
>  eth2 Link encap:Ethernet HWaddr 00:19:99:B8:C7:53
>
> UP BROADCAST MULTICAST MTU:1500 Metric:1
>
> RX packets:0 errors:0 dropped:0 overruns:0 frame:0
>
> TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
>
> collisions:0 txqueuelen:1000
>
> RX bytes:0 (0.0 b) TX bytes:0 (0.0 b)
>
> Memory:ff080000-ff0fffff
>
>  eth3 Link encap:Ethernet HWaddr 00:19:99:B8:C7:54
>
> UP BROADCAST MULTICAST MTU:1500 Metric:1
>
> RX packets:0 errors:0 dropped:0 overruns:0 frame:0
>
> TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
>
> collisions:0 txqueuelen:1000
>
> RX bytes:0 (0.0 b) TX bytes:0 (0.0 b)
>
> Memory:ff000000-ff07ffff
>
>  eth4 Link encap:Ethernet HWaddr 00:50:43:00:82:1D
>
> UP BROADCAST MULTICAST MTU:1500 Metric:1
>
> RX packets:0 errors:0 dropped:0 overruns:0 frame:0
>
> TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
>
> collisions:0 txqueuelen:1000
>
> RX bytes:0 (0.0 b) TX bytes:0 (0.0 b)
>
> Interrupt:17
>
>  eth5 Link encap:Ethernet HWaddr 00:19:99:C8:77:FE
>
> UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
>
> RX packets:0 errors:0 dropped:0 overruns:0 frame:0
>
> TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
>
> collisions:0 txqueuelen:1000
>
> RX bytes:0 (0.0 b) TX bytes:0 (0.0 b)
>
> Interrupt:18
>
>  lo Link encap:Local Loopback
>
> inet addr:127.0.0.1 Mask:255.0.0.0
>
> inet6 addr: ::1/128 Scope:Host
>
> UP LOOPBACK RUNNING MTU:65536 Metric:1
>
> RX packets:470938 errors:0 dropped:0 overruns:0 frame:0
>
> TX packets:470938 errors:0 dropped:0 overruns:0 carrier:0
>
> collisions:0 txqueuelen:0
>
> RX bytes:111338942 (106.1 MiB) TX bytes:111338942 (106.1 MiB)
>
>
>
>  [root ＠ localhost ~]# netstat -rn
>
> Kernel IP routing table
>
> Destination Gateway Genmask Flags MSS Window irtt Iface
>
> 192.168.0.0 0.0.0.0 255.255.255.0 U 0 0 0 cloudbr0
>
> 169.254.0.0 0.0.0.0 255.255.0.0 U 0 0 0 cloud0
>
> 0.0.0.0 192.168.0.1 0.0.0.0 UG 0 0 0 cloudbr0
>
>
>  マウント状況は以下の通りです。
>
> [root ＠ localhost ~]# df -kh
>
> Filesystem Size Used Avail Use% Mounted on
>
> /dev/mapper/VolGroup-lv_root
>
> 50G 4.9G 42G 11% /
>
> tmpfs 7.7G 80K 7.7G 1% /dev/shm
>
> /dev/sda1 477M 36M 416M 8% /boot
>
> /dev/mapper/VolGroup-lv_home
>
> 977G 101M 928G 1% /home
>
>
>  ログをtailしたところ、以下の3行のメッセージが継続して出ておりました。
>
>
>  2015-01-09 09:41:36,137 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 09:41:37,650 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 09:41:37,650 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
>
>  こちらが出る前に、以下のメッセージが表示されておりましたので、
>
> db.propertiesにあるnodeのIPを変更致しました。
>
> Detected management node left, id:1, nodeIP:169.254.0.1
>
> 変更したファイルと場所
>
> [root ＠ localhost ~]# cat /etc/cloudstack/management/db.properties | grep
> node.IP
>
> # management server clustering parameters, change cluster.node.IP to the
> machine IP address
>
> cluster.node.IP=192.168.0.10
>
> 結果、表示されるログのIPは192.168.0.10と変わりましたが、継続して出ております。
>
>
>  また、例外エラーがmanagement-server.log上で一気に表示されることを確認しました。
>
> 下記の通り、Unable to contact resource.とありましたので、ホストの強制再接続を
>
> 試しておりますが、再びログに表示される次第となっております。
>
>
>
>  [root ＠ localhost ~]# tail -f
> /var/log/cloudstack/management/management-server.log
>
> 2015-01-09 11:07:54,151 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:07:55,650 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:07:55,650 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:07:55,651 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:07:57,150 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:07:57,150 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:07:57,150 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:07:58,650 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:07:58,650 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:07:58,650 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:00,149 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:08:00,149 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:08:00,150 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:01,637 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:08:01,637 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:08:01,637 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:03,149 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:08:03,150 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:08:03,150 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:04,637 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:08:04,637 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:08:04,637 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:06,137 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:08:06,137 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:08:06,137 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:07,649 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:08:07,649 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:08:07,650 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:09,150 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:08:09,150 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:08:09,150 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:10,649 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:08:10,649 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:08:10,650 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:12,137 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:08:12,137 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:08:12,137 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:13,650 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:08:13,650 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:08:13,651 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:15,150 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:08:15,150 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:08:15,150 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:16,637 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:08:16,637 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:08:16,637 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:17,219 DEBUG
> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
> is ready to launch secondary storage VM
>
> 2015-01-09 11:08:17,225 INFO
> [cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null)
> No running secondary storage vms found in datacenter id=1, starting one
>
> 2015-01-09 11:08:17,237 INFO
> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Found a
> stopped secondary storage vm, bring it up to running pool. secStorageVm vm
> id : 152
>
> 2015-01-09 11:08:17,252 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-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
>
> 2015-01-09 11:08:17,253 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Successfully transitioned to start state for
> VM[SecondaryStorageVm|s-152-VM] reservation id =
> b2a1eb1c-d8a9-4058-b720-02c178b1d7f8
>
> 2015-01-09 11:08:17,266 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Trying to deploy VM, vm has dcId: 1 and podId: 1
>
> 2015-01-09 11:08:17,267 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Deploy avoids pods: null, clusters: null, hosts: null
>
> 2015-01-09 11:08:17,270 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) DeploymentPlanner allocation algorithm: random
>
> 2015-01-09 11:08:17,270 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Trying to allocate a host and storage pools from dc:1,
> pod:1,cluster:null, requested cpu: 500, requested ram: 268435456
>
> 2015-01-09 11:08:17,270 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Is ROOT volume READY (pool already allocated)?: No
>
> 2015-01-09 11:08:17,271 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Searching resources only under specified Pod: 1
>
> 2015-01-09 11:08:17,272 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Listing clusters in order of aggregate capacity, that
> have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
>
> 2015-01-09 11:08:17,274 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) CPUOverprovisioningFactor considered: 1.0
>
> 2015-01-09 11:08:17,287 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Checking resources in Cluster: 1 under Pod: 1
>
> 2015-01-09 11:08:17,287 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1
> cluster:1
>
> 2015-01-09 11:08:17,290 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to
> check for allocation: [Host[-1-Routing]]
>
> 2015-01-09 11:08:17,295 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Found 1 hosts for allocation after
> prioritization: [Host[-1-Routing]]
>
> 2015-01-09 11:08:17,295 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=256
>
> 2015-01-09 11:08:17,298 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:FirstFitRoutingAllocator) Checking if host: 1 has enough
> capacity for requested CPU: 500 and requested RAM: 268435456 ,
> cpuOverprovisioningFactor: 1.0
>
> 2015-01-09 11:08:17,303 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 19200 and
> CPU after applying overprovisioning: 19200
>
> 2015-01-09 11:08:17,304 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:FirstFitRoutingAllocator) Free CPU: 19200 , Requested CPU:
> 500
>
> 2015-01-09 11:08:17,304 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:FirstFitRoutingAllocator) Free RAM: 16420503552 , Requested
> RAM: 268435456
>
> 2015-01-09 11:08:17,304 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:FirstFitRoutingAllocator) Host has enough CPU and RAM
> available
>
> 2015-01-09 11:08:17,304 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1,
> used: 0, reserved: 0, actual total: 19200, total with overprovisioning:
> 19200; requested cpu:500,alloc_from_last_host?:false
> ,considerReservedCapacity?: true
>
> 2015-01-09 11:08:17,304 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1,
> used: 0, reserved: 0, total: 16420503552; requested mem:
> 268435456,alloc_from_last_host?:false ,considerReservedCapacity?: true
>
> 2015-01-09 11:08:17,304 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Found a suitable host, adding to
> list: 1
>
> 2015-01-09 11:08:17,304 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Host Allocator returning 1 suitable
> hosts
>
> 2015-01-09 11:08:17,307 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Checking suitable pools for volume (Id, Type):
> (152,ROOT)
>
> 2015-01-09 11:08:17,308 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) We need to allocate new storagepool for this volume
>
> 2015-01-09 11:08:17,308 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Calling StoragePoolAllocators to find suitable pools
>
> 2015-01-09 11:08:17,310 DEBUG
> [storage.allocator.LocalStoragePoolAllocator] (secstorage-1:null)
> LocalStoragePoolAllocator trying to find storage pool to fit the vm
>
> 2015-01-09 11:08:17,310 DEBUG
> [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null)
> Looking for pools in dc: 1 pod:1 cluster:1
>
> 2015-01-09 11:08:17,312 DEBUG
> [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null)
> FirstFitStoragePoolAllocator has 1 pools to check for allocation
>
> 2015-01-09 11:08:17,312 DEBUG
> [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null)
> Checking if storage pool is suitable, name: localhost ,poolId: 200
>
> 2015-01-09 11:08:17,313 DEBUG
> [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Is
> localStorageAllocationNeeded? true
>
> 2015-01-09 11:08:17,313 DEBUG
> [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Is
> storage pool shared? false
>
> 2015-01-09 11:08:17,317 DEBUG [cloud.storage.StorageManagerImpl]
> (secstorage-1:null) Checking pool 200 for storage, totalSize:
> 1048881356800, usedBytes: 105758720, usedPct: 1.008300121976198E-4, disable
> threshold: 0.85
>
> 2015-01-09 11:08:17,327 DEBUG [cloud.storage.StorageManagerImpl]
> (secstorage-1:null) Checking pool: 200 for volume allocation
> [Vol[152|vm=152|ROOT]], maxSize : 1048881356800, totalAllocatedSize :
> 139264, askingSize : 0, allocated disable threshold: 0.85
>
> 2015-01-09 11:08:17,327 DEBUG
> [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null)
> FirstFitStoragePoolAllocator returning 1 suitable storage pools
>
> 2015-01-09 11:08:17,329 DEBUG
> [storage.allocator.LocalStoragePoolAllocator] (secstorage-1:null) Found
> suitable local storage pool 200, adding to list
>
> 2015-01-09 11:08:17,330 DEBUG
> [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null)
> Looking for pools in dc: 1 pod:1 cluster:1
>
> 2015-01-09 11:08:17,332 DEBUG
> [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null)
> FirstFitStoragePoolAllocator has 1 pools to check for allocation
>
> 2015-01-09 11:08:17,333 DEBUG
> [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null)
> Checking if storage pool is suitable, name: localhost ,poolId: 200
>
> 2015-01-09 11:08:17,333 DEBUG
> [storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null)
> StoragePool is in avoid set, skipping this pool
>
> 2015-01-09 11:08:17,333 DEBUG
> [storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null)
> FirstFitStoragePoolAllocator returning 0 suitable storage pools
>
> 2015-01-09 11:08:17,333 DEBUG
> [storage.allocator.LocalStoragePoolAllocator] (secstorage-1:null)
> LocalStoragePoolAllocator returning 1 suitable storage pools
>
> 2015-01-09 11:08:17,333 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Trying to find a potenial host and associated storage
> pools from the suitable host/pool lists for this VM
>
> 2015-01-09 11:08:17,333 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Checking if host: 1 can access any suitable storage
> pool for volume: ROOT
>
> 2015-01-09 11:08:17,335 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Host: 1 can access pool: 200
>
> 2015-01-09 11:08:17,336 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Found a potential host id: 1 name: localhost and
> associated storage pools for this VM
>
> 2015-01-09 11:08:17,338 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-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(152|ROOT-->Pool(200))]
>
>
> 2015-01-09 11:08:17,339 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Deployment found - P0=VM[SecondaryStorageVm|s-152-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(152|ROOT-->Pool(200))]
>
>
> 2015-01-09 11:08:17,358 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-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
>
> 2015-01-09 11:08:17,371 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) Hosts's actual total CPU: 19200 and CPU after applying
> overprovisioning: 19200
>
> 2015-01-09 11:08:17,371 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) We are allocating VM, increasing the used capacity of
> this host:1
>
> 2015-01-09 11:08:17,371 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) Current Used CPU: 0 , Free CPU:19200 ,Requested CPU:
> 500
>
> 2015-01-09 11:08:17,371 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) Current Used RAM: 0 , Free RAM:16420503552 ,Requested
> RAM: 268435456
>
> 2015-01-09 11:08:17,371 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) CPU STATS after allocation: for host: 1, old used: 0,
> old reserved: 0, actual total: 19200, total with overprovisioning: 19200;
> new used:500, reserved:0; requested cpu:500,alloc_from_last:false
>
> 2015-01-09 11:08:17,371 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) RAM STATS after allocation: for host: 1, old used: 0,
> old reserved: 0, total: 16420503552; new used: 268435456, reserved: 0;
> requested mem: 268435456,alloc_from_last:false
>
> 2015-01-09 11:08:17,383 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) VM is being created in podId: 1
>
> 2015-01-09 11:08:17,393 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Lock is acquired for network id 204 as a part of
> network implement
>
> 2015-01-09 11:08:17,393 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Network id=204 is already implemented
>
> 2015-01-09 11:08:17,394 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Lock is released for network id 204 as a part of
> network implement
>
> 2015-01-09 11:08:17,449 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to prepare for
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:17,449 DEBUG [network.element.NiciraNvpElement]
> (secstorage-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network defaultGuestNetwork
>
> 2015-01-09 11:08:17,449 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking JuniperSRX to prepare for
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:17,449 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Netscaler to prepare for
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:17,449 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking F5BigIP to prepare for
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:17,449 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:17,450 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking BigSwitchVnsElement to prepare for
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:17,450 DEBUG [network.element.BigSwitchVnsElement]
> (secstorage-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network defaultGuestNetwork
>
> 2015-01-09 11:08:17,450 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to prepare for
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:17,450 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to prepare for
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:17,450 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to prepare for
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:17,450 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to prepare for
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:17,450 WARN [network.element.VpcVirtualRouterElement]
> (secstorage-1:null) Network Ntwk[204|Guest|6] is not associated with any
> VPC
>
> 2015-01-09 11:08:17,460 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Lock is acquired for network id 202 as a part of
> network implement
>
> 2015-01-09 11:08:17,460 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Network id=202 is already implemented
>
> 2015-01-09 11:08:17,461 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Lock is released for network id 202 as a part of
> network implement
>
> 2015-01-09 11:08:17,520 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to prepare for
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
>
> 2015-01-09 11:08:17,521 DEBUG [network.element.NiciraNvpElement]
> (secstorage-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking JuniperSRX to prepare for
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
>
> 2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Netscaler to prepare for
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
>
> 2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking F5BigIP to prepare for
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
>
> 2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
>
> 2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking BigSwitchVnsElement to prepare for
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
>
> 2015-01-09 11:08:17,521 DEBUG [network.element.BigSwitchVnsElement]
> (secstorage-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to prepare for
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
>
> 2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to prepare for
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
>
> 2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to prepare for
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
>
> 2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to prepare for
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
>
> 2015-01-09 11:08:17,522 WARN [network.element.VpcVirtualRouterElement]
> (secstorage-1:null) Network Ntwk[202|Control|3] is not associated with any
> VPC
>
> 2015-01-09 11:08:17,525 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Lock is acquired for network id 201 as a part of
> network implement
>
> 2015-01-09 11:08:17,525 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Network id=201 is already implemented
>
> 2015-01-09 11:08:17,526 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Lock is released for network id 201 as a part of
> network implement
>
> 2015-01-09 11:08:17,571 DEBUG [network.guru.PodBasedNetworkGuru]
> (secstorage-1:null) Allocated a nic
> NicProfile[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103-null
> for VM[SecondaryStorageVm|s-152-VM]
>
> 2015-01-09 11:08:17,584 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to prepare for
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
>
> 2015-01-09 11:08:17,584 DEBUG [network.element.NiciraNvpElement]
> (secstorage-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:17,584 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking JuniperSRX to prepare for
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
>
> 2015-01-09 11:08:17,584 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Netscaler to prepare for
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
>
> 2015-01-09 11:08:17,584 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking F5BigIP to prepare for
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
>
> 2015-01-09 11:08:17,584 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
>
> 2015-01-09 11:08:17,585 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking BigSwitchVnsElement to prepare for
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
>
> 2015-01-09 11:08:17,585 DEBUG [network.element.BigSwitchVnsElement]
> (secstorage-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:17,585 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to prepare for
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
>
> 2015-01-09 11:08:17,585 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to prepare for
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
>
> 2015-01-09 11:08:17,585 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to prepare for
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
>
> 2015-01-09 11:08:17,585 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to prepare for
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
>
> 2015-01-09 11:08:17,585 WARN [network.element.VpcVirtualRouterElement]
> (secstorage-1:null) Network Ntwk[201|Management|2] is not associated with
> any VPC
>
> 2015-01-09 11:08:17,589 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Lock is acquired for network id 203 as a part of
> network implement
>
> 2015-01-09 11:08:17,589 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Network id=203 is already implemented
>
> 2015-01-09 11:08:17,590 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Lock is released for network id 203 as a part of
> network implement
>
> 2015-01-09 11:08:17,637 DEBUG [network.guru.PodBasedNetworkGuru]
> (secstorage-1:null) Allocated a nic
> NicProfile[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108-null
> for VM[SecondaryStorageVm|s-152-VM]
>
> 2015-01-09 11:08:17,649 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to prepare for
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
>
> 2015-01-09 11:08:17,649 DEBUG [network.element.NiciraNvpElement]
> (secstorage-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:17,649 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking JuniperSRX to prepare for
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
>
> 2015-01-09 11:08:17,649 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Netscaler to prepare for
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
>
> 2015-01-09 11:08:17,649 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking F5BigIP to prepare for
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
>
> 2015-01-09 11:08:17,649 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
>
> 2015-01-09 11:08:17,650 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking BigSwitchVnsElement to prepare for
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
>
> 2015-01-09 11:08:17,650 DEBUG [network.element.BigSwitchVnsElement]
> (secstorage-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:17,650 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to prepare for
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
>
> 2015-01-09 11:08:17,650 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to prepare for
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
>
> 2015-01-09 11:08:17,650 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to prepare for
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
>
> 2015-01-09 11:08:17,650 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to prepare for
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
>
> 2015-01-09 11:08:17,650 WARN [network.element.VpcVirtualRouterElement]
> (secstorage-1:null) Network Ntwk[203|Storage|4] is not associated with any
> VPC
>
> 2015-01-09 11:08:17,653 DEBUG [cloud.storage.StorageManagerImpl]
> (secstorage-1:null) Checking if we need to prepare 1 volumes for
> VM[SecondaryStorageVm|s-152-VM]
>
> 2015-01-09 11:08:17,666 DEBUG [cloud.storage.StorageManagerImpl]
> (secstorage-1:null) Creating volume: Vol[152|vm=152|ROOT]
>
> 2015-01-09 11:08:17,666 DEBUG [cloud.storage.StorageManagerImpl]
> (secstorage-1:null) Trying to create in Pool[200|Filesystem]
>
> 2015-01-09 11:08:17,690 DEBUG [cloud.template.TemplateManagerImpl]
> (secstorage-1:null) Template 3 has already been downloaded to pool 200
>
> 2015-01-09 11:08:17,700 DEBUG [agent.transport.Request]
> (secstorage-1:null) Seq 1-816644129: Sending { Cmd , MgmtId: 7501364227543,
> via: 1, Ver: v1, Flags: 100111,
> [{"storage.CreateCommand":{"volId":152,"pool":{"id":200,"uuid":"89e750c4-79af-4ed3-bee6-53fcec68ac96","host":"192.168.0.10","path":"/var/lib/libvirt/images/","port":0,"type":"Filesystem"},"diskCharacteristics":{"size":0,"tags":[],"type":"ROOT","name":"ROOT-152","useLocalStorage":true,"recreatable":true,"diskOfferingId":9,"volumeId":152,"hyperType":"KVM"},"templateUrl":"b5740808-e1e4-4537-8d57-5c9fa4addc94","wait":0}}]
> }
>
> 2015-01-09 11:08:17,745 DEBUG [agent.transport.Request]
> (AgentManager-Handler-10:null) Seq 1-816644129: Processing: { Ans: ,
> MgmtId: 7501364227543, via: 1, Ver: v1, Flags: 110,
> [{"storage.CreateAnswer":{"requestTemplateReload":false,"result":false,"details":"Exception:
> com.cloud.utils.exception.CloudRuntimeException\nMessage:
> org.libvirt.LibvirtException: Storage volume not found: no storage vol with
> matching name 'b5740808-e1e4-4537-8d57-5c9fa4addc94'\nStack:
> com.cloud.utils.exception.CloudRuntimeException:
> org.libvirt.LibvirtException: Storage volume not found: no storage vol with
> matching name 'b5740808-e1e4-4537-8d57-5c9fa4addc94'\n\tat
> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getVolume(LibvirtStorageAdaptor.java:90)\n\tat
> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getPhysicalDisk(LibvirtStorageAdaptor.java:437)\n\tat
> com.cloud.hypervisor.kvm.storage.LibvirtStoragePool.getPhysicalDisk(LibvirtStoragePool.java:123)\n\tat
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:1279)\n\tat
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1072)\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:1145)\n\tat
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat
> java.lang.Thread.run(Thread.java:745)\n","wait":0}}] }
>
> 2015-01-09 11:08:17,745 DEBUG [agent.manager.AgentAttache]
> (AgentManager-Handler-10:null) Seq 1-816644129: No more commands found
>
> 2015-01-09 11:08:17,745 DEBUG [agent.transport.Request]
> (secstorage-1:null) Seq 1-816644129: Received: { Ans: , MgmtId:
> 7501364227543, via: 1, Ver: v1, Flags: 110, { CreateAnswer } }
>
> 2015-01-09 11:08:17,746 DEBUG [cloud.storage.StorageManagerImpl]
> (secstorage-1:null) Unable to create volume Vol[152|vm=152|ROOT]
>
> 2015-01-09 11:08:17,758 INFO [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Unable to contact resource.
>
> com.cloud.exception.StorageUnavailableException: Resource
> [StoragePool:200] is unreachable: Unable to create Vol[152|vm=152|ROOT]
>
> at
> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3488)
>
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:748)
>
>
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:471)
>
>
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:464)
>
>
> at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:269)
>
>
> at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696)
>
>
> at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1307)
>
>
> at
> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:121)
>
>
> at
> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:52)
>
>
> at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
>
> at
> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
>
> at
> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
>
> at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
>
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
>
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>
>
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>
>
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>
>
> at java.lang.Thread.run(Thread.java:745)
>
> 2015-01-09 11:08:17,770 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Cleaning up resources for the vm
> VM[SecondaryStorageVm|s-152-VM] in Starting state
>
> 2015-01-09 11:08:17,774 DEBUG [agent.transport.Request]
> (secstorage-1:null) Seq 1-816644130: Sending { Cmd , MgmtId: 7501364227543,
> via: 1, Ver: v1, Flags: 100111,
> [{"StopCommand":{"isProxy":false,"vmName":"s-152-VM","wait":0}}] }
>
> 2015-01-09 11:08:17,794 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
> (consoleproxy-1:null) Zone 1 is ready to launch console proxy
>
> 2015-01-09 11:08:17,794 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
> (consoleproxy-1:null) Expand console proxy standby capacity for zone zone1
>
> 2015-01-09 11:08:17,800 INFO [cloud.consoleproxy.ConsoleProxyManagerImpl]
> (consoleproxy-1:null) Found a stopped console proxy, bring it up to running
> pool. proxy vm id : 2
>
> 2015-01-09 11:08:17,814 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
>
> 2015-01-09 11:08:17,814 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Successfully transitioned to start state for
> VM[ConsoleProxy|v-2-VM] reservation id =
> 09d9d4b5-2cf9-487e-aa85-cd98be5b03d9
>
> 2015-01-09 11:08:17,828 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Trying to deploy VM, vm has dcId: 1 and podId: 1
>
> 2015-01-09 11:08:17,828 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Deploy avoids pods: null, clusters: null, hosts: null
>
> 2015-01-09 11:08:17,833 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Root volume is ready, need to place VM in volume's
> cluster
>
> 2015-01-09 11:08:17,833 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Vol[2|vm=2|ROOT] is READY, changing deployment plan
> to use this pool's dcId: 1 , podId: 1 , and clusterId: 1
>
> 2015-01-09 11:08:17,835 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) DeploymentPlanner allocation algorithm: random
>
> 2015-01-09 11:08:17,835 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Trying to allocate a host and storage pools from
> dc:1, pod:1,cluster:1, requested cpu: 500, requested ram: 1073741824
>
> 2015-01-09 11:08:17,835 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Is ROOT volume READY (pool already allocated)?: Yes
>
> 2015-01-09 11:08:17,835 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Searching resources only under specified Cluster: 1
>
> 2015-01-09 11:08:17,845 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Checking resources in Cluster: 1 under Pod: 1
>
> 2015-01-09 11:08:17,845 DEBUG [allocator.impl.FirstFitAllocator]
> (consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1
> cluster:1
>
> 2015-01-09 11:08:17,849 DEBUG [allocator.impl.FirstFitAllocator]
> (consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to
> check for allocation: [Host[-1-Routing]]
>
> 2015-01-09 11:08:17,856 DEBUG [allocator.impl.FirstFitAllocator]
> (consoleproxy-1:FirstFitRoutingAllocator) Found 1 hosts for allocation
> after prioritization: [Host[-1-Routing]]
>
> 2015-01-09 11:08:17,857 DEBUG [allocator.impl.FirstFitAllocator]
> (consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=500Mhz,
> Ram=1024
>
> 2015-01-09 11:08:17,860 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
>
> 2015-01-09 11:08:17,865 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 19200
> and CPU after applying overprovisioning: 19200
>
> 2015-01-09 11:08:17,866 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 18700 , Requested CPU:
> 500
>
> 2015-01-09 11:08:17,866 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 16152068096 ,
> Requested RAM: 1073741824
>
> 2015-01-09 11:08:17,866 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and RAM
> available
>
> 2015-01-09 11:08:17,866 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host:
> 1, used: 500, reserved: 0, actual total: 19200, total with
> overprovisioning: 19200; requested cpu:500,alloc_from_last_host?:false
> ,considerReservedCapacity?: true
>
> 2015-01-09 11:08:17,866 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host:
> 1, used: 268435456, reserved: 0, total: 16420503552; requested mem:
> 1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
>
> 2015-01-09 11:08:17,866 DEBUG [allocator.impl.FirstFitAllocator]
> (consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host, adding to
> list: 1
>
> 2015-01-09 11:08:17,866 DEBUG [allocator.impl.FirstFitAllocator]
> (consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning 1
> suitable hosts
>
> 2015-01-09 11:08:17,870 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Checking suitable pools for volume (Id, Type):
> (2,ROOT)
>
> 2015-01-09 11:08:17,870 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Volume has pool(200) already allocated, checking if
> pool can be reused, poolId: 200
>
> 2015-01-09 11:08:17,870 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) finding pool by id '200'
>
> 2015-01-09 11:08:17,872 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Planner need not allocate a pool for this volume
> since its READY
>
> 2015-01-09 11:08:17,872 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Trying to find a potenial host and associated storage
> pools from the suitable host/pool lists for this VM
>
> 2015-01-09 11:08:17,873 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Checking if host: 1 can access any suitable storage
> pool for volume: ROOT
>
> 2015-01-09 11:08:17,875 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Host: 1 can access pool: 200
>
> 2015-01-09 11:08:17,875 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Found a potential host id: 1 name: localhost and
> associated storage pools for this VM
>
> 2015-01-09 11:08:17,878 DEBUG [cloud.deploy.FirstFitPlanner]
> (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()]
>
> 2015-01-09 11:08:17,878 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()]
>
> 2015-01-09 11:08:17,897 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
>
> 2015-01-09 11:08:17,910 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) Hosts's actual total CPU: 19200 and CPU after
> applying overprovisioning: 19200
>
> 2015-01-09 11:08:17,910 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) We are allocating VM, increasing the used capacity of
> this host:1
>
> 2015-01-09 11:08:17,910 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) Current Used CPU: 500 , Free CPU:18700 ,Requested
> CPU: 500
>
> 2015-01-09 11:08:17,910 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) Current Used RAM: 268435456 , Free RAM:16152068096
> ,Requested RAM: 1073741824
>
> 2015-01-09 11:08:17,911 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) CPU STATS after allocation: for host: 1, old used:
> 500, old reserved: 0, actual total: 19200, total with overprovisioning:
> 19200; new used:1000, reserved:0; requested cpu:500,alloc_from_last:false
>
> 2015-01-09 11:08:17,911 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) RAM STATS after allocation: for host: 1, old used:
> 268435456, old reserved: 0, total: 16420503552; new used: 1342177280,
> reserved: 0; requested mem: 1073741824,alloc_from_last:false
>
> 2015-01-09 11:08:17,922 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) VM is being created in podId: 1
>
> 2015-01-09 11:08:17,931 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Lock is acquired for network id 204 as a part of
> network implement
>
> 2015-01-09 11:08:17,931 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Network id=204 is already implemented
>
> 2015-01-09 11:08:17,932 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Lock is released for network id 204 as a part of
> network implement
>
> 2015-01-09 11:08:17,985 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking NiciraNvp to prepare for
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:17,986 DEBUG [network.element.NiciraNvpElement]
> (consoleproxy-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network defaultGuestNetwork
>
> 2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking JuniperSRX to prepare for
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Netscaler to prepare for
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking F5BigIP to prepare for
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to prepare for
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking BigSwitchVnsElement to prepare for
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:17,986 DEBUG [network.element.BigSwitchVnsElement]
> (consoleproxy-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network defaultGuestNetwork
>
> 2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VirtualRouter to prepare for
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Ovs to prepare for
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking SecurityGroupProvider to prepare for
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:17,987 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VpcVirtualRouter to prepare for
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:17,987 WARN [network.element.VpcVirtualRouterElement]
> (consoleproxy-1:null) Network Ntwk[204|Guest|6] is not associated with any
> VPC
>
> 2015-01-09 11:08:17,989 DEBUG [agent.transport.Request]
> (AgentManager-Handler-11:null) Seq 1-816644130: Processing: { Ans: ,
> MgmtId: 7501364227543, via: 1, Ver: v1, Flags: 110,
> [{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
>
> 2015-01-09 11:08:17,989 DEBUG [agent.manager.AgentAttache]
> (AgentManager-Handler-11:null) Seq 1-816644130: No more commands found
>
> 2015-01-09 11:08:17,989 DEBUG [agent.transport.Request]
> (secstorage-1:null) Seq 1-816644130: Received: { Ans: , MgmtId:
> 7501364227543, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
>
> 2015-01-09 11:08:17,997 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Lock is acquired for network id 202 as a part of
> network implement
>
> 2015-01-09 11:08:17,997 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Network id=202 is already implemented
>
> 2015-01-09 11:08:17,998 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Lock is released for network id 202 as a part of
> network implement
>
> 2015-01-09 11:08:18,019 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to release
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:18,019 DEBUG [network.element.NiciraNvpElement]
> (secstorage-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network defaultGuestNetwork
>
> 2015-01-09 11:08:18,019 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking JuniperSRX to release
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:18,019 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Netscaler to release
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking F5BigIP to release
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking CiscoNexus1000vVSM to release
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking BigSwitchVnsElement to release
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:18,020 DEBUG [network.element.BigSwitchVnsElement]
> (secstorage-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network defaultGuestNetwork
>
> 2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to release
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to release
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to release
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to release
> Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
>
> 2015-01-09 11:08:18,026 DEBUG [network.guru.ControlNetworkGuru]
> (secstorage-1:null) Released nic: NicProfile[605-152-null-null-null
>
> 2015-01-09 11:08:18,036 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to release
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,036 DEBUG [network.element.NiciraNvpElement]
> (secstorage-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,036 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking JuniperSRX to release
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,036 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Netscaler to release
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,036 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking F5BigIP to release
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,036 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking CiscoNexus1000vVSM to release
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,036 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking BigSwitchVnsElement to release
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,037 DEBUG [network.element.BigSwitchVnsElement]
> (secstorage-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,037 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to release
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,037 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to release
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,037 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to release
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,037 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to release
> Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,045 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
> (secstorage-1:null) Releasing ip address for
> reservationId=b2a1eb1c-d8a9-4058-b720-02c178b1d7f8, instance=606
>
> 2015-01-09 11:08:18,046 DEBUG [network.guru.PodBasedNetworkGuru]
> (secstorage-1:null) Released nic: NicProfile[606-152-null-null-null
>
> 2015-01-09 11:08:18,058 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to release
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,058 DEBUG [network.element.NiciraNvpElement]
> (secstorage-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,058 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking JuniperSRX to release
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,058 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Netscaler to release
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,058 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking F5BigIP to release
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,058 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking CiscoNexus1000vVSM to release
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,059 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking BigSwitchVnsElement to release
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,059 DEBUG [network.element.BigSwitchVnsElement]
> (secstorage-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,059 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to release
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,059 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to release
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,059 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to release
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,059 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to release
> Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking NiciraNvp to prepare for
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
>
> 2015-01-09 11:08:18,068 DEBUG [network.element.NiciraNvpElement]
> (consoleproxy-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking JuniperSRX to prepare for
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
>
> 2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Netscaler to prepare for
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
>
> 2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking F5BigIP to prepare for
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
>
> 2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to prepare for
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
>
> 2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking BigSwitchVnsElement to prepare for
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
>
> 2015-01-09 11:08:18,068 DEBUG [network.element.BigSwitchVnsElement]
> (consoleproxy-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VirtualRouter to prepare for
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
>
> 2015-01-09 11:08:18,069 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Ovs to prepare for
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
>
> 2015-01-09 11:08:18,069 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking SecurityGroupProvider to prepare for
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
>
> 2015-01-09 11:08:18,069 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VpcVirtualRouter to prepare for
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
>
> 2015-01-09 11:08:18,069 WARN [network.element.VpcVirtualRouterElement]
> (consoleproxy-1:null) Network Ntwk[202|Control|3] is not associated with
> any VPC
>
> 2015-01-09 11:08:18,069 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
> (secstorage-1:null) Releasing ip address for
> reservationId=b2a1eb1c-d8a9-4058-b720-02c178b1d7f8, instance=607
>
> 2015-01-09 11:08:18,071 DEBUG [network.guru.PodBasedNetworkGuru]
> (secstorage-1:null) Released nic: NicProfile[607-152-null-null-null
>
> 2015-01-09 11:08:18,073 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Lock is acquired for network id 201 as a part of
> network implement
>
> 2015-01-09 11:08:18,073 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Network id=201 is already implemented
>
> 2015-01-09 11:08:18,074 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Lock is released for network id 201 as a part of
> network implement
>
> 2015-01-09 11:08:18,082 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to release
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,082 DEBUG [network.element.NiciraNvpElement]
> (secstorage-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,082 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking JuniperSRX to release
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Netscaler to release
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking F5BigIP to release
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking CiscoNexus1000vVSM to release
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking BigSwitchVnsElement to release
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,083 DEBUG [network.element.BigSwitchVnsElement]
> (secstorage-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to release
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to release
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to release
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to release
> Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
>
> 2015-01-09 11:08:18,084 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Successfully released network resources for the vm
> VM[SecondaryStorageVm|s-152-VM]
>
> 2015-01-09 11:08:18,084 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Successfully cleanued up resources for the vm
> VM[SecondaryStorageVm|s-152-VM] in Starting state
>
> 2015-01-09 11:08:18,087 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) DeploymentPlanner allocation algorithm: random
>
> 2015-01-09 11:08:18,088 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Trying to allocate a host and storage pools from dc:1,
> pod:1,cluster:null, requested cpu: 500, requested ram: 268435456
>
> 2015-01-09 11:08:18,088 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Is ROOT volume READY (pool already allocated)?: No
>
> 2015-01-09 11:08:18,088 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Searching resources only under specified Pod: 1
>
> 2015-01-09 11:08:18,090 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Listing clusters in order of aggregate capacity, that
> have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
>
> 2015-01-09 11:08:18,091 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) CPUOverprovisioningFactor considered: 1.0
>
> 2015-01-09 11:08:18,104 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Checking resources in Cluster: 1 under Pod: 1
>
> 2015-01-09 11:08:18,104 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1
> cluster:1
>
> 2015-01-09 11:08:18,108 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to
> check for allocation: [Host[-1-Routing]]
>
> 2015-01-09 11:08:18,113 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Found 1 hosts for allocation after
> prioritization: [Host[-1-Routing]]
>
> 2015-01-09 11:08:18,113 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=256
>
> 2015-01-09 11:08:18,113 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Host name: localhost, hostId: 1 is
> in avoid set, skipping this and trying other available hosts
>
> 2015-01-09 11:08:18,113 DEBUG [allocator.impl.FirstFitAllocator]
> (secstorage-1:FirstFitRoutingAllocator) Host Allocator returning 0 suitable
> hosts
>
> 2015-01-09 11:08:18,113 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) No suitable hosts found
>
> 2015-01-09 11:08:18,113 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) No suitable hosts found under this Cluster: 1
>
> 2015-01-09 11:08:18,113 DEBUG [cloud.deploy.FirstFitPlanner]
> (secstorage-1:null) Could not find suitable Deployment Destination for this
> VM under any clusters, returning.
>
> 2015-01-09 11:08:18,120 DEBUG [network.guru.PodBasedNetworkGuru]
> (consoleproxy-1:null) Allocated a nic
> NicProfile[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105-null for
> VM[ConsoleProxy|v-2-VM]
>
> 2015-01-09 11:08:18,139 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking NiciraNvp to prepare for
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
>
> 2015-01-09 11:08:18,140 DEBUG [network.element.NiciraNvpElement]
> (consoleproxy-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,140 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking JuniperSRX to prepare for
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
>
> 2015-01-09 11:08:18,140 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Netscaler to prepare for
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
>
> 2015-01-09 11:08:18,140 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking F5BigIP to prepare for
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
>
> 2015-01-09 11:08:18,140 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to prepare for
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
>
> 2015-01-09 11:08:18,140 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking BigSwitchVnsElement to prepare for
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
>
> 2015-01-09 11:08:18,140 DEBUG [network.element.BigSwitchVnsElement]
> (consoleproxy-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,140 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VirtualRouter to prepare for
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
>
> 2015-01-09 11:08:18,141 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Ovs to prepare for
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
>
> 2015-01-09 11:08:18,141 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking SecurityGroupProvider to prepare for
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
>
> 2015-01-09 11:08:18,141 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VpcVirtualRouter to prepare for
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
>
> 2015-01-09 11:08:18,141 WARN [network.element.VpcVirtualRouterElement]
> (consoleproxy-1:null) Network Ntwk[201|Management|2] is not associated with
> any VPC
>
> 2015-01-09 11:08:18,144 DEBUG [cloud.storage.StorageManagerImpl]
> (consoleproxy-1:null) Checking if we need to prepare 1 volumes for
> VM[ConsoleProxy|v-2-VM]
>
> 2015-01-09 11:08:18,145 DEBUG [cloud.storage.StorageManagerImpl]
> (consoleproxy-1:null) No need to recreate the volume: Vol[2|vm=2|ROOT],
> since it already has a pool assigned: 200, adding disk to VM
>
> 2015-01-09 11:08:18,151 DEBUG [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Detected management node left, id:3,
> nodeIP:192.168.0.10
>
> 2015-01-09 11:08:18,151 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
>
> 2015-01-09 11:08:18,152 INFO [cloud.cluster.ClusterManagerImpl]
> (Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
> timestamp but is pingable
>
> 2015-01-09 11:08:18,153 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
> (consoleproxy-1:null) Boot Args for VM[ConsoleProxy|v-2-VM]: template=domP
> type=consoleproxy host=192.168.0.10 port=8250 name=v-2-VM premium=true
> zone=1 pod=1 guid=Proxy.2 proxy_vm=2 disable_rp_filter=true
> eth2ip=192.168.0.111 eth2mask=255.255.255.0 gateway=192.168.0.1
> eth0ip=169.254.0.22 eth0mask=255.255.0.0 eth1ip=192.168.0.105
> eth1mask=255.255.255.0 mgmtcidr=192.168.0.0/24 localgw=192.168.0.1
> <http://192.168.0.0/24localgw=192.168.0.1> internaldns1=8.8.8.8
> internaldns2=8.8.4.4 dns1=8.8.8.8 dns2=8.8.4.4
>
> 2015-01-09 11:08:18,158 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) VM state transitted from :Starting to Stopped with
> event: OperationFailedvm's original host id: null new host id: null host id
> before state transition: 1
>
> 2015-01-09 11:08:18,169 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) Hosts's actual total CPU: 19200 and CPU after applying
> overprovisioning: 19200
>
> 2015-01-09 11:08:18,169 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) release cpu from host: 1, old used: 1000,reserved: 0,
> actual total: 19200, total with overprovisioning: 19200; new used:
> 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
>
> 2015-01-09 11:08:18,169 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) release mem from host: 1, old used:
> 1342177280,reserved: 0, total: 16420503552; new used:
> 1073741824,reserved:0; movedfromreserved: false,moveToReserveredfalse
>
> 2015-01-09 11:08:18,189 WARN
> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
> Exception while trying to start secondary storage vm
>
> com.cloud.exception.InsufficientServerCapacityException: Unable to create
> a deployment for VM[SecondaryStorageVm|s-152-VM]Scope=interface
> com.cloud.dc.DataCenter; id=1
>
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:728)
>
>
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:471)
>
>
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:464)
>
>
> at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:269)
>
>
> at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696)
>
>
> at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1307)
>
>
> at
> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:121)
>
>
> at
> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:52)
>
>
> at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
>
> at
> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
>
> at
> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
>
> at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
>
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
>
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>
>
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>
>
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>
>
> at java.lang.Thread.run(Thread.java:745)
>
> 2015-01-09 11:08:18,192 INFO
> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Unable
> to start secondary storage vm for standby capacity, secStorageVm vm Id :
> 152, will recycle it and start a new one
>
> 2015-01-09 11:08:18,196 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) VM is already stopped: VM[SecondaryStorageVm|s-152-VM]
>
> 2015-01-09 11:08:18,209 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) VM state transitted from :Stopped to Expunging with
> event: ExpungeOperationvm's original host id: null new host id: null host
> id before state transition: null
>
> 2015-01-09 11:08:18,211 DEBUG [agent.transport.Request]
> (consoleproxy-1:null) Seq 1-816644131: Sending { Cmd , MgmtId:
> 7501364227543, via: 1, Ver: v1, Flags: 100111,
> [{"StartCommand":{"vm":{"id":2,"name":"v-2-VM","type":"ConsoleProxy","cpus":1,"speed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"Debian
> GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP type=consoleproxy
> host=192.168.0.10 port=8250 name=v-2-VM premium=true zone=1 pod=1
> guid=Proxy.2 proxy_vm=2 disable_rp_filter=true eth2ip=192.168.0.111
> eth2mask=255.255.255.0 gateway=192.168.0.1 eth0ip=169.254.0.22
> eth0mask=255.255.0.0 eth1ip=192.168.0.105 eth1mask=255.255.255.0 mgmtcidr=192.168.0.0/24
> localgw=192.168.0.1 <http://192.168.0.0/24localgw=192.168.0.1>
> internaldns1=8.8.8.8 internaldns2=8.8.4.4 dns1=8.8.8.8
> dns2=8.8.4.4","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"c121518cceb6351f","params":{},"uuid":"0922ad08-05ca-4838-b97c-7b3855d277df","disks":[{"id":2,"name":"ROOT-2","mountPoint":"/var/lib/libvirt/images/","path":"aaa87362-beb7-4f00-9f2c-e3042f4a2025","size":0,"type":"ROOT","storagePoolType":"Filesystem","storagePoolUuid":"89e750c4-79af-4ed3-bee6-53fcec68ac96","deviceId":0}],"nics":[{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"5a555f14-1c0d-4eab-9d3b-c02603df1c52","ip":"192.168.0.111","netmask":"255.255.255.0","gateway":"192.168.0.1","mac":"06:ac:94:00:00:0c","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true,"name":"cloudbr0"},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"6051ade4-661d-43fd-a07b-9a58df26d45a","ip":"169.254.0.22","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:00:16","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"b9fc57e7-cc45-4a64-816b-9177716d6952","ip":"192.168.0.105","netmask":"255.255.255.0","gateway":"192.168.0.1","mac":"06:a8:4a:00:00:06","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"cloudbr0"}]},"hostIp":"192.168.0.10","wait":0}},{"check.CheckSshCommand":{"ip":"169.254.0.22","port":3922,"interval":6,"retries":100,"name":"v-2-VM","wait":0}}]
> }
>
> 2015-01-09 11:08:18,213 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Destroying vm VM[SecondaryStorageVm|s-152-VM]
>
> 2015-01-09 11:08:18,213 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Cleaning up NICS
>
> 2015-01-09 11:08:18,213 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Cleaning network for vm: 152
>
> 2015-01-09 11:08:18,218 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 routers to update status.
>
> 2015-01-09 11:08:18,220 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
>
> 2015-01-09 11:08:18,243 DEBUG [network.guru.DirectNetworkGuru]
> (secstorage-1:null) Deallocate network: networkId: 204, ip: 192.168.0.112
>
> 2015-01-09 11:08:18,259 DEBUG [agent.transport.Request]
> (AgentManager-Handler-12:null) Seq 1-816644131: Processing: { Ans: ,
> MgmtId: 7501364227543, via: 1, Ver: v1, Flags: 110,
> [{"StartAnswer":{"vm":{"id":2,"name":"v-2-VM","type":"ConsoleProxy","cpus":1,"speed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"Debian
> GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP type=consoleproxy
> host=192.168.0.10 port=8250 name=v-2-VM premium=true zone=1 pod=1
> guid=Proxy.2 proxy_vm=2 disable_rp_filter=true eth2ip=192.168.0.111
> eth2mask=255.255.255.0 gateway=192.168.0.1 eth0ip=169.254.0.22
> eth0mask=255.255.0.0 eth1ip=192.168.0.105 eth1mask=255.255.255.0 mgmtcidr=192.168.0.0/24
> localgw=192.168.0.1 <http://192.168.0.0/24localgw=192.168.0.1>
> internaldns1=8.8.8.8 internaldns2=8.8.4.4 dns1=8.8.8.8
> dns2=8.8.4.4","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"c121518cceb6351f","vncAddr":"192.168.0.10","params":{},"uuid":"0922ad08-05ca-4838-b97c-7b3855d277df","disks":[{"id":2,"name":"ROOT-2","mountPoint":"/var/lib/libvirt/images/","path":"aaa87362-beb7-4f00-9f2c-e3042f4a2025","size":0,"type":"ROOT","storagePoolType":"Filesystem","storagePoolUuid":"89e750c4-79af-4ed3-bee6-53fcec68ac96","deviceId":0}],"nics":[{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"5a555f14-1c0d-4eab-9d3b-c02603df1c52","ip":"192.168.0.111","netmask":"255.255.255.0","gateway":"192.168.0.1","mac":"06:ac:94:00:00:0c","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true,"name":"cloudbr0"},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"6051ade4-661d-43fd-a07b-9a58df26d45a","ip":"169.254.0.22","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:00:16","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"b9fc57e7-cc45-4a64-816b-9177716d6952","ip":"192.168.0.105","netmask":"255.255.255.0","gateway":"192.168.0.1","mac":"06:a8:4a:00:00:06","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"cloudbr0"}]},"result":false,"details":"org.libvirt.LibvirtException:
> Storage volume not found: no storage vol with matching name
> 'aaa87362-beb7-4f00-9f2c-e3042f4a2025'","wait":0}},{"Answer":{"result":false,"details":"Stopped
> by previous failure","wait":0}}] }
>
> 2015-01-09 11:08:18,259 DEBUG [agent.manager.AgentAttache]
> (AgentManager-Handler-12:null) Seq 1-816644131: No more commands found
>
> 2015-01-09 11:08:18,259 DEBUG [agent.transport.Request]
> (consoleproxy-1:null) Seq 1-816644131: Received: { Ans: , MgmtId:
> 7501364227543, via: 1, Ver: v1, Flags: 110, { StartAnswer, Answer } }
>
> 2015-01-09 11:08:18,265 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 routers to update status.
>
> 2015-01-09 11:08:18,267 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
>
> 2015-01-09 11:08:18,272 INFO [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Unable to start VM on Host[-1-Routing] due to
> org.libvirt.LibvirtException: Storage volume not found: no storage vol with
> matching name 'aaa87362-beb7-4f00-9f2c-e3042f4a2025'
>
> 2015-01-09 11:08:18,282 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Removed nic id=604
>
> 2015-01-09 11:08:18,292 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Cleaning up resources for the vm
> VM[ConsoleProxy|v-2-VM] in Starting state
>
> 2015-01-09 11:08:18,295 DEBUG [agent.transport.Request]
> (consoleproxy-1:null) Seq 1-816644132: Sending { Cmd , MgmtId:
> 7501364227543, via: 1, Ver: v1, Flags: 100111,
> [{"StopCommand":{"isProxy":false,"vmName":"v-2-VM","wait":0}}] }
>
> 2015-01-09 11:08:18,315 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Removed nic id=605
>
> 2015-01-09 11:08:18,345 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Removed nic id=606
>
> 2015-01-09 11:08:18,374 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Removed nic id=607
>
> 2015-01-09 11:08:18,375 DEBUG [cloud.storage.StorageManagerImpl]
> (secstorage-1:null) Cleaning storage for vm: 152
>
> 2015-01-09 11:08:18,398 DEBUG [cloud.storage.StorageManagerImpl]
> (secstorage-1:null) Expunging Vol[152|vm=152|ROOT]
>
> 2015-01-09 11:08:18,403 DEBUG [cloud.storage.StorageManagerImpl]
> (secstorage-1:null) Marking volume that was never created as destroyed:
> Vol[152|vm=152|ROOT]
>
> 2015-01-09 11:08:18,425 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Expunged VM[SecondaryStorageVm|s-152-VM]
>
> 2015-01-09 11:08:18,442 INFO
> [cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null)
> Primary secondary storage is not even started, wait until next turn
>
> 2015-01-09 11:08:18,509 DEBUG [agent.transport.Request]
> (AgentManager-Handler-13:null) Seq 1-816644132: Processing: { Ans: ,
> MgmtId: 7501364227543, via: 1, Ver: v1, Flags: 110,
> [{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
>
> 2015-01-09 11:08:18,510 DEBUG [agent.manager.AgentAttache]
> (AgentManager-Handler-13:null) Seq 1-816644132: No more commands found
>
> 2015-01-09 11:08:18,510 DEBUG [agent.transport.Request]
> (consoleproxy-1:null) Seq 1-816644132: Received: { Ans: , MgmtId:
> 7501364227543, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
>
> 2015-01-09 11:08:18,536 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking NiciraNvp to release
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:18,536 DEBUG [network.element.NiciraNvpElement]
> (consoleproxy-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network defaultGuestNetwork
>
> 2015-01-09 11:08:18,536 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking JuniperSRX to release
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Netscaler to release
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking F5BigIP to release
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking BigSwitchVnsElement to release
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:18,537 DEBUG [network.element.BigSwitchVnsElement]
> (consoleproxy-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network defaultGuestNetwork
>
> 2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VirtualRouter to release
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Ovs to release
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking SecurityGroupProvider to release
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VpcVirtualRouter to release
> Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
>
> 2015-01-09 11:08:18,543 DEBUG [network.guru.ControlNetworkGuru]
> (consoleproxy-1:null) Released nic: NicProfile[6-2-null-null-null
>
> 2015-01-09 11:08:18,555 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking NiciraNvp to release
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,555 DEBUG [network.element.NiciraNvpElement]
> (consoleproxy-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,555 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking JuniperSRX to release
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,555 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Netscaler to release
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,555 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking F5BigIP to release
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,555 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,555 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking BigSwitchVnsElement to release
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,555 DEBUG [network.element.BigSwitchVnsElement]
> (consoleproxy-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,556 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VirtualRouter to release
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,556 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Ovs to release
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,556 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking SecurityGroupProvider to release
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,556 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VpcVirtualRouter to release
> Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,563 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
> (consoleproxy-1:null) Releasing ip address for
> reservationId=09d9d4b5-2cf9-487e-aa85-cd98be5b03d9, instance=7
>
> 2015-01-09 11:08:18,564 DEBUG [network.guru.PodBasedNetworkGuru]
> (consoleproxy-1:null) Released nic: NicProfile[7-2-null-null-null
>
> 2015-01-09 11:08:18,576 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking NiciraNvp to release
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,576 DEBUG [network.element.NiciraNvpElement]
> (consoleproxy-1:null) Checking if NiciraNvpElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,576 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking JuniperSRX to release
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,576 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Netscaler to release
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,576 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking F5BigIP to release
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,576 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,576 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking BigSwitchVnsElement to release
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,576 DEBUG [network.element.BigSwitchVnsElement]
> (consoleproxy-1:null) Checking if BigSwitchVnsElement can handle service
> Connectivity on network null
>
> 2015-01-09 11:08:18,577 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VirtualRouter to release
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,577 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Ovs to release
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,577 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking SecurityGroupProvider to release
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,577 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VpcVirtualRouter to release
> Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
>
> 2015-01-09 11:08:18,577 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Successfully released network resources for the vm
> VM[ConsoleProxy|v-2-VM]
>
> 2015-01-09 11:08:18,577 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Successfully cleanued up resources for the vm
> VM[ConsoleProxy|v-2-VM] in Starting state
>
> 2015-01-09 11:08:18,582 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Root volume is ready, need to place VM in volume's
> cluster
>
> 2015-01-09 11:08:18,583 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Vol[2|vm=2|ROOT] is READY, changing deployment plan
> to use this pool's dcId: 1 , podId: 1 , and clusterId: 1
>
> 2015-01-09 11:08:18,584 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) DeploymentPlanner allocation algorithm: random
>
> 2015-01-09 11:08:18,585 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Trying to allocate a host and storage pools from
> dc:1, pod:1,cluster:1, requested cpu: 500, requested ram: 1073741824
>
> 2015-01-09 11:08:18,585 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Is ROOT volume READY (pool already allocated)?: Yes
>
> 2015-01-09 11:08:18,585 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Searching resources only under specified Cluster: 1
>
> 2015-01-09 11:08:18,596 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Checking resources in Cluster: 1 under Pod: 1
>
> 2015-01-09 11:08:18,596 DEBUG [allocator.impl.FirstFitAllocator]
> (consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1
> cluster:1
>
> 2015-01-09 11:08:18,600 DEBUG [allocator.impl.FirstFitAllocator]
> (consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to
> check for allocation: [Host[-1-Routing]]
>
> 2015-01-09 11:08:18,604 DEBUG [allocator.impl.FirstFitAllocator]
> (consoleproxy-1:FirstFitRoutingAllocator) Found 1 hosts for allocation
> after prioritization: [Host[-1-Routing]]
>
> 2015-01-09 11:08:18,604 DEBUG [allocator.impl.FirstFitAllocator]
> (consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=500Mhz,
> Ram=1024
>
> 2015-01-09 11:08:18,604 DEBUG [allocator.impl.FirstFitAllocator]
> (consoleproxy-1:FirstFitRoutingAllocator) Host name: localhost, hostId: 1
> is in avoid set, skipping this and trying other available hosts
>
> 2015-01-09 11:08:18,605 DEBUG [allocator.impl.FirstFitAllocator]
> (consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning 0
> suitable hosts
>
> 2015-01-09 11:08:18,605 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) No suitable hosts found
>
> 2015-01-09 11:08:18,605 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) No suitable hosts found under this Cluster: 1
>
> 2015-01-09 11:08:18,605 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Could not find suitable Deployment Destination for
> this VM under any clusters, returning.
>
> 2015-01-09 11:08:18,607 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) DeploymentPlanner allocation algorithm: random
>
> 2015-01-09 11:08:18,607 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Trying to allocate a host and storage pools from
> dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 1073741824
>
> 2015-01-09 11:08:18,607 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Is ROOT volume READY (pool already allocated)?: No
>
> 2015-01-09 11:08:18,607 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Searching resources only under specified Pod: 1
>
> 2015-01-09 11:08:18,609 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
>
> 2015-01-09 11:08:18,610 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) CPUOverprovisioningFactor considered: 1.0
>
> 2015-01-09 11:08:18,614 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) Removing from the clusterId list these clusters from
> avoid set: [1]
>
> 2015-01-09 11:08:18,614 DEBUG [cloud.deploy.FirstFitPlanner]
> (consoleproxy-1:null) No clusters found after removing disabled clusters
> and clusters in avoid list, returning.
>
> 2015-01-09 11:08:18,639 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) VM state transitted from :Starting to Stopped with
> event: OperationFailedvm's original host id: null new host id: null host id
> before state transition: 1
>
> 2015-01-09 11:08:18,648 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) Hosts's actual total CPU: 19200 and CPU after
> applying overprovisioning: 19200
>
> 2015-01-09 11:08:18,649 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) release cpu from host: 1, old used: 500,reserved: 0,
> actual total: 19200, total with overprovisioning: 19200; new used:
> 0,reserved:0; movedfromreserved: false,moveToReserveredfalse
>
> 2015-01-09 11:08:18,649 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) release mem from host: 1, old used:
> 1073741824,reserved: 0, total: 16420503552; new used: 0,reserved:0;
> movedfromreserved: false,moveToReserveredfalse
>
> 2015-01-09 11:08:18,661 WARN [cloud.consoleproxy.ConsoleProxyManagerImpl]
> (consoleproxy-1:null) Exception while trying to start console proxy
>
> com.cloud.exception.InsufficientServerCapacityException: Unable to create
> a deployment for VM[ConsoleProxy|v-2-VM]Scope=interface
> com.cloud.dc.DataCenter; id=1
>
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:728)
>
>
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:471)
>
>
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:464)
>
>
> at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:632)
>
>
> at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1166)
>
>
> at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1985)
>
>
> at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:175)
>
>
> at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
>
> at
> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
>
> at
> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
>
> at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
>
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
>
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
>
>
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>
>
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>
>
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>
>
> at java.lang.Thread.run(Thread.java:745)
>
>
>  最後となりますが、追記について承知致しました。
>
> ログを確認している最中ですが、お礼の返信が3日以上
>
> あいてしまいましたので、取り急ぎご返信まで。
>
> 重ねてとなりますが、ありがとうございました。
>
> 2015年1月6日 3:49 giraffe.forest <giraffe.forest ＠ wh.commufa.jp>:
>
>> 永喜多さん
>>
>> こんにちは CloudStackユーザ会の中谷と申します。
>> どうぞよろしくお願いいたします。
>>
>> 試しに似た構成でインストールしてみました。
>> 結果として，うまく動かすことができました。
>> まず参考として環境情報を記載いたします。
>>
>> ・使用したマニュアル
>> http://cloudstack.apache.org/docs/ja-JP/Apache_CloudStack/
>> 4.1.1/html/Installation_Guide/installation.html
>>
>> ・1サーバ(management-serverとagentの同居)
>> ・1NIC (10.0.0.3)
>> ・Apache CloudStack 4.1.1
>> ・SystemVMテンプレート：acton-systemvm-02062012.qcow2.bz2
>> ・CentOS6.6 64bit
>> ・プライマリストレージ：ローカルディスクを使用(NFSアクセスではない)
>> ・セカンダリストレージ：NFSv3アクセス
>> ・OS環境設定
>> [root ＠ kvm01 ~]# rpm -qa | grep kvm
>> qemu-kvm-0.12.1.2-2.448.el6_6.x86_64
>> [root ＠ kvm01 ~]# rpm -qa | grep libvirt
>> libvirt-client-0.10.2-46.el6_6.2.x86_64
>> libvirt-0.10.2-46.el6_6.2.x86_64
>> [root ＠ kvm01 ~]# rpm -qa | grep cloudstack
>> cloudstack-awsapi-4.1.1-0.el6.x86_64
>> cloudstack-management-4.1.1-0.el6.x86_64
>> cloudstack-agent-4.1.1-0.el6.x86_64
>> cloudstack-common-4.1.1-0.el6.x86_64
>> [root ＠ kvm01 ~]#
>> [root ＠ kvm01 ~]# ifconfig
>> cloudbr0  Link encap:Ethernet  HWaddr 00:0C:29:C4:2E:77
>>          inet addr:10.0.0.3  Bcast:10.0.0.255  Mask:255.255.255.0
>>          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
>>          RX packets:453792 errors:0 dropped:0 overruns:0 frame:0
>>          TX packets:280715 errors:0 dropped:0 overruns:0 carrier:0
>>          collisions:0 txqueuelen:0
>>          RX bytes:653734368 (623.4 MiB)  TX bytes:24991359 (23.8 MiB)
>>
>> eth0      Link encap:Ethernet  HWaddr 00:0C:29:C4:2E:77
>>          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
>>          RX packets:466261 errors:0 dropped:0 overruns:0 frame:0
>>          TX packets:283903 errors:0 dropped:0 overruns:0 carrier:0
>>          collisions:0 txqueuelen:1000
>>          RX bytes:660823626 (630.2 MiB)  TX bytes:25160943 (23.9 MiB)
>>
>> lo        Link encap:Local Loopback
>>          inet addr:127.0.0.1  Mask:255.0.0.0
>>          UP LOOPBACK RUNNING  MTU:65536  Metric:1
>>          RX packets:62030 errors:0 dropped:0 overruns:0 frame:0
>>          TX packets:62030 errors:0 dropped:0 overruns:0 carrier:0
>>          collisions:0 txqueuelen:0
>>          RX bytes:11016103 (10.5 MiB)  TX bytes:11016103 (10.5 MiB)
>>
>> [root ＠ kvm01 ~]#
>> [root ＠ kvm01 ~]# netstat -rn
>> Kernel IP routing table
>> Destination     Gateway         Genmask         Flags   MSS Window  irtt
>> Iface
>> 10.0.0.0        0.0.0.0         255.255.255.0   U         0 0          0
>> cloudbr0
>> 0.0.0.0         10.0.0.1        0.0.0.0         UG        0 0          0
>> cloudbr0
>> [root ＠ kvm01 ~]#
>> [root ＠ kvm01 ~]# hostname -f
>> kvm01.dom.local
>> [root ＠ kvm01 ~]# ping www.cloudstack.org
>> PING www.apache.org (192.87.106.229) 56(84) bytes of data.
>> 64 bytes from aurora-2012.apache.org (192.87.106.229): icmp_seq=1 ttl=51
>> time=258 ms
>> 64 bytes from aurora-2012.apache.org (192.87.106.229): icmp_seq=2 ttl=51
>> time=258 ms
>> 64 bytes from aurora-2012.apache.org (192.87.106.229): icmp_seq=3 ttl=51
>> time=259 ms
>> ^C
>> --- www.apache.org ping statistics ---
>> 4 packets transmitted, 3 received, 25% packet loss, time 3411ms
>> rtt min/avg/max/mdev = 258.247/258.885/259.743/0.861 ms
>> [root ＠ kvm01 ~]#
>> [root ＠ kvm01 ~]# getenforce
>> Disabled
>> [root ＠ kvm01 ~]#
>>
>> システムVMとインスタンスが起動しています。
>> [root ＠ kvm01 ~]# virsh list
>> Id    Name                           State
>> ----------------------------------------------------
>> 1     s-1-VM                         running
>> 2     v-2-VM                         running
>> 3     r-7-VM                         running
>> 4     i-2-6-VM                       running
>>
>> [root ＠ kvm01 ~]#
>>
>>  ※システムVM自体は、WebUI上でStoppedでしたので、WebUIから2台とも削除致しました
>>> その後、自動作成されずにおります
>>>
>>
>> いくつか設定を確認してみてください。
>>
>> (1)ローカルストレージ利用時の注意点
>> ・永喜多さんの環境もプライマリストレージはNFSではなく，ローカルストレージでしょうか。
>> その場合，ゾーン作成時にLocal Storage Enabledをチェック(有効)にしましたでしょうか。
>> 当方の操作では
>> WebUIにログイン後
>> 「CloudStackを使用したことがあるので、このガイドをスキップする。」
>> を選択し
>> インフラストラクチャ->ゾーン->ゾーンの追加
>> でゾーンを追加しています。
>> その場合はゾーン作成ウィザードにてLocal Storage Enabledの項目が画面の下の方にでてきます。
>>
>> ・WebUIのグローバル設定で
>> system.vm.use.local.storageはtrueに設定してください。
>> 設定後はmanagement-serverのプロセス再起動が必要です。
>>
>> (2)management-serverのIPアドレス設定の確認
>>
>> ・WebUIのグローバル設定で
>> hostがサーバのIPアアドレスに設定はされているか確認してください。
>>
>> ・サーバの設定ファイル：/etc/cloudstack/management/db.properties
>> にて，以下パラメータが正しく設定されているか確認してください。
>> 例：
>> ：
>> cluster.node.IP=10.0.0.3
>> ：
>> db.cloud.host=localhost
>> ：
>>
>> ※KVM環境にmanagement-serverを同居させておくと
>> KVMのデフォルトネットワーク(virbr0)のIPが割り当てられ邪魔をする場合があります。
>> 以下のように最初から無効にしておくと便利です。
>>
>> [root ＠ kvm01 ~]# virsh net-list --all
>> Name                 State      Autostart     Persistent
>> --------------------------------------------------
>> default              active     yes           yes
>>
>> [root ＠ kvm01 ~]# virsh net-destroy default
>> Network default destroyed
>>
>> [root ＠ kvm01 ~]# virsh net-autostart default --disable
>> Network default unmarked as autostarted
>>
>> [root ＠ kvm01 ~]# virsh net-list --all
>> Name                 State      Autostart     Persistent
>> --------------------------------------------------
>> default              inactive   no            yes
>>
>> [root ＠ kvm01 ~]#
>>
>> (3)仮想スイッチ名の確認
>> WebUIの
>> インフラストラクチャ->ゾーン->[ゾーンを選択]->Physical Network 1->[Physical Networkを選択]->
>> ゲスト：KVM トラフィックのラベル:cloudbr0
>> 管理：KVM トラフィックのラベル:cloudbr0
>> のようにラベル名が
>> サーバに設定した仮想スイッチ名と同一になっているか確認してください。
>>
>> (4)その他
>> WebUIのグローバル設定で
>> secstorage.allowed.internal.sites
>> も設定してみてください。
>> 例：10.0.0.0/24
>>
>>
>> 本題にはいります。
>> これら設定を確認した後に
>> 1)ログをtailしてください。
>> [root ＠ kvm01 ~]# tail -f /var/log/cloudstack/management/management-server.
>> log
>> [root ＠ kvm01 ~]# tail -f /var/log/cloudstack/agent/agent.log
>> 2)インフラストラクチャ->ゾーン->[ゾーンを選択]にてゾーンを無効化
>> 3)インフラストラクチャ->ゾーン->[ゾーンを選択]にてゾーンを有効化
>> 上記操作実施後，しばらくすると例外エラーが発生していると思われます。
>> その例外エラーの上100行程度の情報が解析のヒントになります。
>>
>> ERROR以外にDEBUGやINFOにも情報がうもれてしまっているので
>> 例外エラーの上を確認していきます。
>>
>> 例：
>> この上
>> 2015-01-06 03:13:02,026 INFO  [user.vm.DeployVMCmd]
>> (Job-Executor-10:job-10) Unable to create a deployment for VM[User|vm02]
>> com.cloud.exception.InsufficientServerCapacityException: Unable to
>> create a deployment for VM[User|vm02]Scope=interface
>> com.cloud.dc.DataCenter; id=1
>>        at org.apache.cloudstack.engine.cloud.entity.api.
>> VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:186)
>>        at org.apache.cloudstack.engine.cloud.entity.api.
>> VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:198)
>>        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(
>> UserVmManagerImpl.java:3870)
>>        at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(
>> UserVmManagerImpl.java:3464)
>>
>>
>> 以上です。
>>
>> 追記：
>> もしSystemVMが起動するようになったら今度はVMインスタンスを起動すると思いますが
>> ローカルストレージ利用時は初期登録されているコンピュートオファリングは利用できません。
>> ストレージの種類：localの
>> コンピュートオファリングを別途作成し利用する必要があります。
>> またセキュリティグループの解放も必要です。
>>
>>
>>
>> -----Original Message----- From: 永喜多
>> Sent: Monday, January 05, 2015 8:38 PM
>> To: users ＠ cloudstack.jp
>> Subject: [cloudstack-users:0409]【質問】システムVM2台の作成、起動について（CentOS6.6+KVM+ver4.1.1）
>>
>>
>>
>> はじめまして、永喜多と申します。
>>
>>
>> 掲題の件について、後述の環境にて構築中です。
>>
>>
>> management-server.logや、agent.logを確認しても、
>>
>> VM2台の作成について問題切り分けができなくなりました。
>> このため、可能であれば解決に向け、確認箇所のご相談ができればと存じます。
>> ※システムVM自体は、WebUI上でStoppedでしたので、WebUIから2台とも削除致しました
>>  その後、自動作成されずにおります
>>
>>
>> ▽環境
>> ----------
>> OS：CentOS6.6
>>
>> HV：KVM / qemu-kvm-0.12.1.2-2.448.el6_6.x86_64
>>
>> DB ：mysql-server-5.1.73-3.el6_5.x86_64
>>
>> ネットワーク：Basic
>>
>> ipv6：no
>>
>> IPアドレス：static 1つ
>>
>> CloudStackシステムテンプレート：4.1.1
>>
>> サーバは1台、/mnt/secondaryは別PC
>>
>> ※HostとManagementは同一サーバ：192.168.0.10
>> secondary：192.168.0.2
>> ----------
>>
>>
>> 以下は、agentとmanagementのログとなります。
>>
>>
>> ▽agent.log
>>
>> [root ＠ cloud ~]# tail -n 15 /var/log/cloudstack/agent/agent.log
>> at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(
>> LibvirtComputingResource.java:2304)
>> at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.
>> executeRequest(LibvirtComputingResource.java:1094)
>> at com.cloud.agent.Agent.processRequest(Agent.java:525)
>> at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)
>> at com.cloud.utils.nio.Task.run(Task.java:83)
>> at java.util.concurrent.ThreadPoolExecutor.runWorker(
>> ThreadPoolExecutor.java:1145)
>> at java.util.concurrent.ThreadPoolExecutor$Worker.run(
>> ThreadPoolExecutor.java:615)
>> at java.lang.Thread.run(Thread.java:745)
>> 2015-01-05 17:22:16,943 INFO  [cloud.agent.Agent]
>> (agentRequest-Handler-4:null) Proccess agent ready command, agent id = 3
>> 2015-01-05 17:22:16,943 INFO  [cloud.agent.Agent]
>> (agentRequest-Handler-4:null) Set agent id 3
>> 2015-01-05 17:22:16,945 INFO  [cloud.agent.Agent]
>> (agentRequest-Handler-4:null) Ready command is processed: agent id = 3
>> 2015-01-05 17:22:17,062 INFO  [cloud.agent.Agent]
>> (agentRequest-Handler-5:null) Proccess agent ready command, agent id = 3
>> 2015-01-05 17:22:17,063 INFO  [cloud.agent.Agent]
>> (agentRequest-Handler-5:null) Set agent id 3
>> 2015-01-05 17:22:17,065 INFO  [cloud.agent.Agent]
>> (agentRequest-Handler-5:null) Ready command is processed: agent id = 3
>> 2015-01-05 17:22:20,867 INFO  [cloud.agent.Agent] (Agent-Handler-5:null)
>> Connected to the server
>>
>>
>>
>>
>>
>> ▽management.log
>> [root ＠ cloud ~]# tail -n 30 /var/log/cloudstack/
>> management/management-server.log
>> 2015-01-05 20:12:16,288 DEBUG [agent.manager.AgentManagerImpl]
>> (AgentManager-Handler-8:null) Ping from 3
>> 2015-01-05 20:12:16,676 DEBUG [agent.transport.Request]
>> (StatsCollector-1:null) Seq 3-2055733424: Received:  { Ans: , MgmtId:
>> 179176544198247, via: 3, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
>> 2015-01-05 20:12:28,769 DEBUG [cloud.server.StatsCollector]
>> (StatsCollector-2:null) VmStatsCollector is running...
>> 2015-01-05 20:12:29,323 DEBUG [cloud.server.StatsCollector]
>> (StatsCollector-3:null) StorageCollector is running...
>> 2015-01-05 20:12:29,328 DEBUG [cloud.server.StatsCollector]
>> (StatsCollector-3:null) There is no secondary storage VM for secondary
>> storage host nfs://192.168.0.2/mnt/secondary
>> 2015-01-05 20:12:41,801 DEBUG [storage.secondary.SecondaryStorageManagerImpl]
>> (secstorage-1:null) Primary storage is not ready, wait until it is ready to
>> launch secondary storage vm
>> 2015-01-05 20:12:41,801 DEBUG [storage.secondary.SecondaryStorageManagerImpl]
>> (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
>> 2015-01-05 20:12:42,360 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
>> (consoleproxy-1:null) Primary storage is not ready, wait until it is ready
>> to launch console proxy
>> 2015-01-05 20:12:42,361 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
>> (consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
>> 2015-01-05 20:12:42,757 DEBUG [network.router.
>> VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0
>> routers to update status.
>> 2015-01-05 20:12:42,758 DEBUG [network.router.
>> VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0
>> networks to update RvR status.
>> 2015-01-05 20:12:42,813 DEBUG [network.router.
>> VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0
>> routers to update status.
>> 2015-01-05 20:12:42,815 DEBUG [network.router.
>> VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0
>> networks to update RvR status.
>> 2015-01-05 20:12:42,892 DEBUG [cloud.alert.AlertManagerImpl]
>> (CapacityChecker:null) Running Capacity Checker ...
>> 2015-01-05 20:12:42,892 DEBUG [cloud.alert.AlertManagerImpl]
>> (CapacityChecker:null) recalculating system capacity
>> 2015-01-05 20:12:42,892 DEBUG [cloud.alert.AlertManagerImpl]
>> (CapacityChecker:null) Executing cpu/ram capacity update
>> 2015-01-05 20:12:42,903 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (CapacityChecker:null) Found 0 VMs on host 3
>> 2015-01-05 20:12:42,905 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (CapacityChecker:null) Found 0 VM, not running on host 3
>> 2015-01-05 20:12:42,909 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (CapacityChecker:null) No need to calibrate cpu capacity, host:3 usedCpu: 0
>> reservedCpu: 0
>> 2015-01-05 20:12:42,909 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (CapacityChecker:null) No need to calibrate memory capacity, host:3
>> usedMem: 0 reservedMem: 0
>> 2015-01-05 20:12:42,909 DEBUG [cloud.alert.AlertManagerImpl]
>> (CapacityChecker:null) Done executing cpu/ram capacity update
>> 2015-01-05 20:12:42,909 DEBUG [cloud.alert.AlertManagerImpl]
>> (CapacityChecker:null) Executing storage capacity update
>> 2015-01-05 20:12:42,929 DEBUG [cloud.storage.StorageManagerImpl]
>> (CapacityChecker:null) Successfully set Capacity - 105421733888 for
>> capacity type - 3 , DataCenterId - 1, HostOrPoolId - 200, PodId 1
>> 2015-01-05 20:12:42,929 DEBUG [cloud.alert.AlertManagerImpl]
>> (CapacityChecker:null) Done executing storage capacity update
>> 2015-01-05 20:12:42,929 DEBUG [cloud.alert.AlertManagerImpl]
>> (CapacityChecker:null) Executing capacity updates for public ip and Vlans
>> 2015-01-05 20:12:42,939 DEBUG [cloud.alert.AlertManagerImpl]
>> (CapacityChecker:null) Done capacity updates for public ip and Vlans
>> 2015-01-05 20:12:42,939 DEBUG [cloud.alert.AlertManagerImpl]
>> (CapacityChecker:null) Executing capacity updates for private ip
>> 2015-01-05 20:12:42,949 DEBUG [cloud.alert.AlertManagerImpl]
>> (CapacityChecker:null) Done executing capacity updates for private ip
>> 2015-01-05 20:12:42,949 DEBUG [cloud.alert.AlertManagerImpl]
>> (CapacityChecker:null) Done recalculating system capacity
>> 2015-01-05 20:12:42,974 DEBUG [cloud.alert.AlertManagerImpl]
>> (CapacityChecker:null) Done running Capacity Checker ...
>>
>>
>>
>> 以上となります。
>>
>>
>>
>> 設定ファイル群の記載については、どこまで記述するのがよいか
>> 不明瞭だったため、さしあたりログのみを記載させていただきました。
>>
>>
>> システムVM2台の作成、起動について、ご教授頂けたら幸いです。
>>
>>
>> --
>>
>> -------------------------------------------
>> 永喜多
>> mailto:E-Mail%3An ＠ gakita.me
>> -------------------------------------------
>>
>>
>>
>>
>>
>> _______________________________________________
>> users mailing list
>> users ＠ cloudstack.jp
>> http://ml.cloudstack.jp/mailman/listinfo/users
>>
>
>
>
> --
> -------------------------------------------
> 永喜多
> E-Mail:n ＠ gakita.me
> -------------------------------------------
>



-- 
-------------------------------------------
永喜多
E-Mail:n ＠ gakita.me
-------------------------------------------
-------------- next part --------------
HTML$B$NE:IU%U%!%$%k$rJ]4I$7$^$7$?(B...
URL: <http://ml.cloudstack.jp/pipermail/users/attachments/20150110/b7a25aa0/attachment-0001.html>