cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Ana Paula de Sousa (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (CLOUDSTACK-6153) Unable to start a System VM on Cloudstack
Date Fri, 21 Feb 2014 21:35:29 GMT

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

Ana Paula de Sousa updated CLOUDSTACK-6153:
-------------------------------------------

    Description: 
When I'm at the UI of cloudstack and I try to add a VM on "System VMs" it gives me a warning saying "fail to start System vm", and it makes me unable to test the environment.

The log of the management-server.log gives me:
2014-02-21 18:30:24,867 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:null) Ping from 1
2014-02-21 18:30:29,399 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Resetting hosts suitable for reconnect
2014-02-21 18:30:29,401 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed resetting hosts suitable for recon$
2014-02-21 18:30:29,401 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Acquiring hosts for clusters already owned b$
2014-02-21 18:30:29,402 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed acquiring hosts for clusters alrea$
2014-02-21 18:30:29,402 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Acquiring hosts for clusters not owned by an$
2014-02-21 18:30:29,402 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed acquiring hosts for clusters not o$
2014-02-21 18:30:34,699 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) VmStatsCollector is running...
2014-02-21 18:30:52,123 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Primary storage is not ready, wait$
2014-02-21 18:30:52,123 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch seco$
2014-02-21 18:30:52,201 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console p$
2014-02-21 18:30:52,201 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Expand console proxy standby capaci$
2014-02-21 18:30:52,205 INFO  [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Found a stopped console proxy, brin$
2014-02-21 18:30:52,217 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM state transitted from :Stopped to Starti$
2014-02-21 18:30:52,217 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Successfully transitioned to start state fo$
2014-02-21 18:30:52,263 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Trying to deploy VM, vm has dcId: 1 and pod$
2014-02-21 18:30:52,264 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Deploy avoids pods: null, clusters: null, h$
2014-02-21 18:30:52,266 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) StorageCollector is running...
2014-02-21 18:30:52,267 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Deploy avoids pods: null, clusters:$
2014-02-21 18:30:52,268 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) DeploymentPlanner allocation algori$
2014-02-21 18:30:52,268 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Trying to allocate a host and stora$
2014-02-21 18:30:52,268 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Is ROOT volume READY (pool already $
2014-02-21 18:30:52,268 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Searching all possible resources under this Zone:$
2014-02-21 18:30:52,270 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Listing clusters in order of aggregate capacity, $
2014-02-21 18:30:52,272 INFO  [storage.endpoint.DefaultEndPointSelector] (StatsCollector-3:null) No running ssvm is found, so comman$
2014-02-21 18:30:52,279 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking resources in Cluster: 1 un$
2014-02-21 18:30:52,279 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc: $
2014-02-21 18:30:52,292 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 h$
2014-02-21 18:30:52,294 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found 1 hosts for allocat$
2014-02-21 18:30:52,294 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=500Mhz,$
2014-02-21 18:30:52,297 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Checking if host: 1 has$
2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CP$
2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 29608 , Reque$
2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 8356601856 , $
2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and$
2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU fr$
2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM fr$
2014-02-21 18:30:52,299 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host, ad$
2014-02-21 18:30:52,299 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning $
2014-02-21 18:30:52,299 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking suitable pools for volume $
2014-02-21 18:30:52,299 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) We need to allocate new storagepool$
2014-02-21 18:30:52,299 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Calling StoragePoolAllocators to fi$
2014-02-21 18:30:52,300 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) LocalStoragePoolAllocator trying t$
2014-02-21 18:30:52,300 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) ClusterScopeStoragePoolAllo$
2014-02-21 18:30:52,300 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) Looking for pools in dc: 1 $
2014-02-21 18:30:52,301 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) No storage pools available $
2014-02-21 18:30:52,301 DEBUG [storage.allocator.ZoneWideStoragePoolAllocator] (consoleproxy-1:null) ZoneWideStoragePoolAllocator to$
2014-02-21 18:30:52,304 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) No suitable pools found for volume:$
2014-02-21 18:30:52,304 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) No suitable pools found
2014-02-21 18:30:52,304 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) No suitable storagePools found unde$
2014-02-21 18:30:52,307 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Could not find suitable Deployment $
2014-02-21 18:30:52,307 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Searching all possible resources under this Zone:$
2014-02-21 18:30:52,308 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Listing clusters in order of aggregate capacity, $
2014-02-21 18:30:52,311 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Removing from the clusterId list these clusters f$
2014-02-21 18:30:52,311 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) No clusters found after removing disabled cluster$
2014-02-21 18:30:52,346 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-365101203: Received:  { Ans: , MgmtId: 1593876$
2014-02-21 18:30:52,405 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM state transitted from :Starting to Stopp$
2014-02-21 18:30:52,410 WARN  [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Exception while trying to start con$
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-1-VM]Scope=interface co$
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:842)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:571)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:556)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:928)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1672)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
        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$Sync.innerRunAndReset(FutureTask.java:351)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:701)
2014-02-21 18:30:52,767 DEBUG [cloud.network.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:null) External devices stats $
2014-02-21 18:30:52,794 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:null) Found 0 running routers.
2014-02-21 18:30:52,796 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:30:52,798 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:30:52,804 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:null) Found 0 running routers.
2014-02-21 18:30:52,804 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:30:52,806 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:30:53,295 DEBUG [storage.snapshot.SnapshotSchedulerImpl] (SnapshotPollTask:null) Snapshot scheduler.poll is being call$
2014-02-21 18:30:53,297 DEBUG [storage.snapshot.SnapshotSchedulerImpl] (SnapshotPollTask:null) Got 0 snapshots to be executed at 201$


The agent.log gives me:
2014-02-21 18:32:24,892 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 1-73:  { Cmd , MgmtId: -1, via: 1, Ver: v1, F$
2014-02-21 18:32:24,903 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Received response: Seq 1-73:  { Ans: , MgmtId: 159387626793$
2014-02-21 18:32:52,447 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Processing command: com.cloud.agent.api.GetStorageSt$
2014-02-21 18:33:18,307 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.GetHostStats$
2014-02-21 18:33:18,307 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c idle=$(t$
2014-02-21 18:33:18,829 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful.
2014-02-21 18:33:18,829 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c freeMem=$
2014-02-21 18:33:18,839 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful.
2014-02-21 18:33:18,839 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c free|gre$
2014-02-21 18:33:18,847 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful.
2014-02-21 18:33:24,827 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Executing: /usr/share/cloudstack-common/scr$
2014-02-21 18:33:24,883 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Execution is successful.
2014-02-21 18:33:24,884 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 1-74:  { Cmd , MgmtId: -1, via: 1, Ver: v1, F$
2014-02-21 18:33:24,895 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null) Received response: Seq 1-74:  { Ans: , MgmtId: 159387626793$



The output of "ifconfig" on my hypervisor is:
br0       Link encap:Ethernet  Endereço de HW 1c:6f:65:d7:4a:4b  
          inet end.: 10.16.1.34  Bcast:10.16.255.255  Masc:255.255.0.0
          endereço inet6: fe80::1e6f:65ff:fed7:4a4b/64 Escopo:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1
          pacotes RX:58025 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:48982 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:0 
          RX bytes:71081838 (71.0 MB) TX bytes:6757079 (6.7 MB)

br1       Link encap:Ethernet  Endereço de HW ee:24:80:dd:23:f9  
          endereço inet6: fe80::ec24:80ff:fedd:23f9/64 Escopo:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1
          pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:183 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:0 
          RX bytes:0 (0.0 B) TX bytes:52722 (52.7 KB)

br1:avahi Link encap:Ethernet  Endereço de HW ee:24:80:dd:23:f9  
          inet end.: 169.254.10.37  Bcast:169.254.255.255  Masc:255.255.0.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1

cloud0    Link encap:Ethernet  Endereço de HW 56:8c:6c:b0:95:a8  
          inet end.: 169.254.0.1  Bcast:169.254.255.255  Masc:255.255.0.0
          endereço inet6: fe80::548c:6cff:feb0:95a8/64 Escopo:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1
          pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:63 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:0 
          RX bytes:0 (0.0 B) TX bytes:11411 (11.4 KB)

eth0      Link encap:Ethernet  Endereço de HW 00:e0:4c:68:17:30  
          UP BROADCAST MULTICAST  MTU:1500  Métrica:1
          pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:0 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:1000 
          RX bytes:0 (0.0 B) TX bytes:0 (0.0 B)

eth1      Link encap:Ethernet  Endereço de HW 5c:d9:98:b1:6f:2d  
          UP BROADCAST MULTICAST  MTU:1500  Métrica:1
          pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:0 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:1000 
          RX bytes:0 (0.0 B) TX bytes:0 (0.0 B)

eth2      Link encap:Ethernet  Endereço de HW 1c:6f:65:d7:4a:4b  
          endereço inet6: fe80::1e6f:65ff:fed7:4a4b/64 Escopo:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1
          pacotes RX:61601 erros:0 descartados:102 excesso:0 quadro:0
          Pacotes TX:49016 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:1000 
          RX bytes:72158063 (72.1 MB) TX bytes:6778184 (6.7 MB)

lo        Link encap:Loopback Local  
          inet end.: 127.0.0.1  Masc:255.0.0.0
          endereço inet6: ::1/128 Escopo:Máquina
          UP LOOPBACK RUNNING  MTU:65536  Métrica:1
          pacotes RX:245 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:245 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:0 
          RX bytes:20092 (20.0 KB) TX bytes:20092 (20.0 KB)

virbr0    Link encap:Ethernet  Endereço de HW 8a:7e:d9:10:69:32  
          inet end.: 192.168.122.1  Bcast:192.168.122.255  Masc:255.255.255.0
          UP BROADCAST MULTICAST  MTU:1500  Métrica:1
          pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:0 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:0 
          RX bytes:0 (0.0 B) TX bytes:0 (0.0 B)

I have the br0, which is the public, network and the br1, which is the private network.

The /etc/cloudstack/agent/agent.properties looks like:
#Storage
#Fri Feb 21 17:20:25 BRT 2014
guest.network.device=br0
workers=5
private.network.device=br1
port=8250
resource=com.cloud.hypervisor.kvm.resource.LibvirtComputingResource
pod=1
zone=1
guid=2e1d6dee-aa9a-3e29-8fb7-995490b62daf
public.network.device=br0
cluster=1
local.storage.uuid=eae1fe36-6779-435c-99b5-e39af074ef74
domr.scripts.dir=scripts/network/domr/kvm
LibvirtComputingResource.id=1
host=10.16.1.32


  was:
When I'm at the UI of cloudstack and I try to add a VM on "System VMs" it gives me a warning saying "fail to start vm", and it makes me unable to test the environment.

The log of the management-server.log gives me:
2014-02-21 18:30:24,867 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:null) Ping from 1
2014-02-21 18:30:29,399 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Resetting hosts suitable for reconnect
2014-02-21 18:30:29,401 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed resetting hosts suitable for recon$
2014-02-21 18:30:29,401 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Acquiring hosts for clusters already owned b$
2014-02-21 18:30:29,402 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed acquiring hosts for clusters alrea$
2014-02-21 18:30:29,402 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Acquiring hosts for clusters not owned by an$
2014-02-21 18:30:29,402 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed acquiring hosts for clusters not o$
2014-02-21 18:30:34,699 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) VmStatsCollector is running...
2014-02-21 18:30:52,123 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Primary storage is not ready, wait$
2014-02-21 18:30:52,123 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch seco$
2014-02-21 18:30:52,201 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console p$
2014-02-21 18:30:52,201 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Expand console proxy standby capaci$
2014-02-21 18:30:52,205 INFO  [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Found a stopped console proxy, brin$
2014-02-21 18:30:52,217 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM state transitted from :Stopped to Starti$
2014-02-21 18:30:52,217 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Successfully transitioned to start state fo$
2014-02-21 18:30:52,263 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Trying to deploy VM, vm has dcId: 1 and pod$
2014-02-21 18:30:52,264 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Deploy avoids pods: null, clusters: null, h$
2014-02-21 18:30:52,266 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) StorageCollector is running...
2014-02-21 18:30:52,267 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Deploy avoids pods: null, clusters:$
2014-02-21 18:30:52,268 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) DeploymentPlanner allocation algori$
2014-02-21 18:30:52,268 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Trying to allocate a host and stora$
2014-02-21 18:30:52,268 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Is ROOT volume READY (pool already $
2014-02-21 18:30:52,268 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Searching all possible resources under this Zone:$
2014-02-21 18:30:52,270 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Listing clusters in order of aggregate capacity, $
2014-02-21 18:30:52,272 INFO  [storage.endpoint.DefaultEndPointSelector] (StatsCollector-3:null) No running ssvm is found, so comman$
2014-02-21 18:30:52,279 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking resources in Cluster: 1 un$
2014-02-21 18:30:52,279 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc: $
2014-02-21 18:30:52,292 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 h$
2014-02-21 18:30:52,294 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found 1 hosts for allocat$
2014-02-21 18:30:52,294 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=500Mhz,$
2014-02-21 18:30:52,297 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Checking if host: 1 has$
2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CP$
2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 29608 , Reque$
2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 8356601856 , $
2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and$
2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU fr$
2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM fr$
2014-02-21 18:30:52,299 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host, ad$
2014-02-21 18:30:52,299 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning $
2014-02-21 18:30:52,299 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking suitable pools for volume $
2014-02-21 18:30:52,299 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) We need to allocate new storagepool$
2014-02-21 18:30:52,299 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Calling StoragePoolAllocators to fi$
2014-02-21 18:30:52,300 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) LocalStoragePoolAllocator trying t$
2014-02-21 18:30:52,300 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) ClusterScopeStoragePoolAllo$
2014-02-21 18:30:52,300 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) Looking for pools in dc: 1 $
2014-02-21 18:30:52,301 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) No storage pools available $
2014-02-21 18:30:52,301 DEBUG [storage.allocator.ZoneWideStoragePoolAllocator] (consoleproxy-1:null) ZoneWideStoragePoolAllocator to$
2014-02-21 18:30:52,304 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) No suitable pools found for volume:$
2014-02-21 18:30:52,304 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) No suitable pools found
2014-02-21 18:30:52,304 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) No suitable storagePools found unde$
2014-02-21 18:30:52,307 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Could not find suitable Deployment $
2014-02-21 18:30:52,307 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Searching all possible resources under this Zone:$
2014-02-21 18:30:52,308 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Listing clusters in order of aggregate capacity, $
2014-02-21 18:30:52,311 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Removing from the clusterId list these clusters f$
2014-02-21 18:30:52,311 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) No clusters found after removing disabled cluster$
2014-02-21 18:30:52,346 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-365101203: Received:  { Ans: , MgmtId: 1593876$
2014-02-21 18:30:52,405 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM state transitted from :Starting to Stopp$
2014-02-21 18:30:52,410 WARN  [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Exception while trying to start con$
com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-1-VM]Scope=interface co$
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:842)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:571)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:556)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:928)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1672)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
        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$Sync.innerRunAndReset(FutureTask.java:351)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:701)
2014-02-21 18:30:52,767 DEBUG [cloud.network.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:null) External devices stats $
2014-02-21 18:30:52,794 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:null) Found 0 running routers.
2014-02-21 18:30:52,796 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:30:52,798 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:30:52,804 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:null) Found 0 running routers.
2014-02-21 18:30:52,804 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:30:52,806 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:30:53,295 DEBUG [storage.snapshot.SnapshotSchedulerImpl] (SnapshotPollTask:null) Snapshot scheduler.poll is being call$
2014-02-21 18:30:53,297 DEBUG [storage.snapshot.SnapshotSchedulerImpl] (SnapshotPollTask:null) Got 0 snapshots to be executed at 201$


The agent.log gives me:
2014-02-21 18:32:24,892 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 1-73:  { Cmd , MgmtId: -1, via: 1, Ver: v1, F$
2014-02-21 18:32:24,903 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Received response: Seq 1-73:  { Ans: , MgmtId: 159387626793$
2014-02-21 18:32:52,447 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Processing command: com.cloud.agent.api.GetStorageSt$
2014-02-21 18:33:18,307 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.GetHostStats$
2014-02-21 18:33:18,307 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c idle=$(t$
2014-02-21 18:33:18,829 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful.
2014-02-21 18:33:18,829 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c freeMem=$
2014-02-21 18:33:18,839 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful.
2014-02-21 18:33:18,839 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c free|gre$
2014-02-21 18:33:18,847 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful.
2014-02-21 18:33:24,827 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Executing: /usr/share/cloudstack-common/scr$
2014-02-21 18:33:24,883 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Execution is successful.
2014-02-21 18:33:24,884 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 1-74:  { Cmd , MgmtId: -1, via: 1, Ver: v1, F$
2014-02-21 18:33:24,895 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null) Received response: Seq 1-74:  { Ans: , MgmtId: 159387626793$



The output of "ifconfig" on my hypervisor is:
br0       Link encap:Ethernet  Endereço de HW 1c:6f:65:d7:4a:4b  
          inet end.: 10.16.1.34  Bcast:10.16.255.255  Masc:255.255.0.0
          endereço inet6: fe80::1e6f:65ff:fed7:4a4b/64 Escopo:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1
          pacotes RX:58025 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:48982 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:0 
          RX bytes:71081838 (71.0 MB) TX bytes:6757079 (6.7 MB)

br1       Link encap:Ethernet  Endereço de HW ee:24:80:dd:23:f9  
          endereço inet6: fe80::ec24:80ff:fedd:23f9/64 Escopo:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1
          pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:183 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:0 
          RX bytes:0 (0.0 B) TX bytes:52722 (52.7 KB)

br1:avahi Link encap:Ethernet  Endereço de HW ee:24:80:dd:23:f9  
          inet end.: 169.254.10.37  Bcast:169.254.255.255  Masc:255.255.0.0
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1

cloud0    Link encap:Ethernet  Endereço de HW 56:8c:6c:b0:95:a8  
          inet end.: 169.254.0.1  Bcast:169.254.255.255  Masc:255.255.0.0
          endereço inet6: fe80::548c:6cff:feb0:95a8/64 Escopo:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1
          pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:63 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:0 
          RX bytes:0 (0.0 B) TX bytes:11411 (11.4 KB)

eth0      Link encap:Ethernet  Endereço de HW 00:e0:4c:68:17:30  
          UP BROADCAST MULTICAST  MTU:1500  Métrica:1
          pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:0 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:1000 
          RX bytes:0 (0.0 B) TX bytes:0 (0.0 B)

eth1      Link encap:Ethernet  Endereço de HW 5c:d9:98:b1:6f:2d  
          UP BROADCAST MULTICAST  MTU:1500  Métrica:1
          pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:0 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:1000 
          RX bytes:0 (0.0 B) TX bytes:0 (0.0 B)

eth2      Link encap:Ethernet  Endereço de HW 1c:6f:65:d7:4a:4b  
          endereço inet6: fe80::1e6f:65ff:fed7:4a4b/64 Escopo:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1
          pacotes RX:61601 erros:0 descartados:102 excesso:0 quadro:0
          Pacotes TX:49016 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:1000 
          RX bytes:72158063 (72.1 MB) TX bytes:6778184 (6.7 MB)

lo        Link encap:Loopback Local  
          inet end.: 127.0.0.1  Masc:255.0.0.0
          endereço inet6: ::1/128 Escopo:Máquina
          UP LOOPBACK RUNNING  MTU:65536  Métrica:1
          pacotes RX:245 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:245 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:0 
          RX bytes:20092 (20.0 KB) TX bytes:20092 (20.0 KB)

virbr0    Link encap:Ethernet  Endereço de HW 8a:7e:d9:10:69:32  
          inet end.: 192.168.122.1  Bcast:192.168.122.255  Masc:255.255.255.0
          UP BROADCAST MULTICAST  MTU:1500  Métrica:1
          pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
          Pacotes TX:0 erros:0 descartados:0 excesso:0 portadora:0
          colisões:0 txqueuelen:0 
          RX bytes:0 (0.0 B) TX bytes:0 (0.0 B)

I have the br0, which is the public, network and the br1, which is the private network.

The /etc/cloudstack/agent/agent.properties looks like:
#Storage
#Fri Feb 21 17:20:25 BRT 2014
guest.network.device=br0
workers=5
private.network.device=br1
port=8250
resource=com.cloud.hypervisor.kvm.resource.LibvirtComputingResource
pod=1
zone=1
guid=2e1d6dee-aa9a-3e29-8fb7-995490b62daf
public.network.device=br0
cluster=1
local.storage.uuid=eae1fe36-6779-435c-99b5-e39af074ef74
domr.scripts.dir=scripts/network/domr/kvm
LibvirtComputingResource.id=1
host=10.16.1.32



> Unable to start a System VM on Cloudstack
> -----------------------------------------
>
>                 Key: CLOUDSTACK-6153
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-6153
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>         Environment: Two physical machines, one for the hypervisor  and another for the management server. They're on a internal network at my lab.
>            Reporter: Ana Paula de Sousa
>              Labels: agent, issue, kvm, management, systemvm, vm
>
> When I'm at the UI of cloudstack and I try to add a VM on "System VMs" it gives me a warning saying "fail to start System vm", and it makes me unable to test the environment.
> The log of the management-server.log gives me:
> 2014-02-21 18:30:24,867 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-10:null) Ping from 1
> 2014-02-21 18:30:29,399 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Resetting hosts suitable for reconnect
> 2014-02-21 18:30:29,401 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed resetting hosts suitable for recon$
> 2014-02-21 18:30:29,401 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Acquiring hosts for clusters already owned b$
> 2014-02-21 18:30:29,402 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed acquiring hosts for clusters alrea$
> 2014-02-21 18:30:29,402 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Acquiring hosts for clusters not owned by an$
> 2014-02-21 18:30:29,402 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed acquiring hosts for clusters not o$
> 2014-02-21 18:30:34,699 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) VmStatsCollector is running...
> 2014-02-21 18:30:52,123 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Primary storage is not ready, wait$
> 2014-02-21 18:30:52,123 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is not ready to launch seco$
> 2014-02-21 18:30:52,201 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console p$
> 2014-02-21 18:30:52,201 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Expand console proxy standby capaci$
> 2014-02-21 18:30:52,205 INFO  [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Found a stopped console proxy, brin$
> 2014-02-21 18:30:52,217 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM state transitted from :Stopped to Starti$
> 2014-02-21 18:30:52,217 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Successfully transitioned to start state fo$
> 2014-02-21 18:30:52,263 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Trying to deploy VM, vm has dcId: 1 and pod$
> 2014-02-21 18:30:52,264 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Deploy avoids pods: null, clusters: null, h$
> 2014-02-21 18:30:52,266 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) StorageCollector is running...
> 2014-02-21 18:30:52,267 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Deploy avoids pods: null, clusters:$
> 2014-02-21 18:30:52,268 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) DeploymentPlanner allocation algori$
> 2014-02-21 18:30:52,268 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Trying to allocate a host and stora$
> 2014-02-21 18:30:52,268 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Is ROOT volume READY (pool already $
> 2014-02-21 18:30:52,268 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Searching all possible resources under this Zone:$
> 2014-02-21 18:30:52,270 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Listing clusters in order of aggregate capacity, $
> 2014-02-21 18:30:52,272 INFO  [storage.endpoint.DefaultEndPointSelector] (StatsCollector-3:null) No running ssvm is found, so comman$
> 2014-02-21 18:30:52,279 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking resources in Cluster: 1 un$
> 2014-02-21 18:30:52,279 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc: $
> 2014-02-21 18:30:52,292 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 h$
> 2014-02-21 18:30:52,294 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found 1 hosts for allocat$
> 2014-02-21 18:30:52,294 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=500Mhz,$
> 2014-02-21 18:30:52,297 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Checking if host: 1 has$
> 2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CP$
> 2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 29608 , Reque$
> 2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 8356601856 , $
> 2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and$
> 2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU fr$
> 2014-02-21 18:30:52,299 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM fr$
> 2014-02-21 18:30:52,299 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host, ad$
> 2014-02-21 18:30:52,299 DEBUG [allocator.impl.FirstFitAllocator] (consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning $
> 2014-02-21 18:30:52,299 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Checking suitable pools for volume $
> 2014-02-21 18:30:52,299 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) We need to allocate new storagepool$
> 2014-02-21 18:30:52,299 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Calling StoragePoolAllocators to fi$
> 2014-02-21 18:30:52,300 DEBUG [storage.allocator.LocalStoragePoolAllocator] (consoleproxy-1:null) LocalStoragePoolAllocator trying t$
> 2014-02-21 18:30:52,300 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) ClusterScopeStoragePoolAllo$
> 2014-02-21 18:30:52,300 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) Looking for pools in dc: 1 $
> 2014-02-21 18:30:52,301 DEBUG [storage.allocator.ClusterScopeStoragePoolAllocator] (consoleproxy-1:null) No storage pools available $
> 2014-02-21 18:30:52,301 DEBUG [storage.allocator.ZoneWideStoragePoolAllocator] (consoleproxy-1:null) ZoneWideStoragePoolAllocator to$
> 2014-02-21 18:30:52,304 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) No suitable pools found for volume:$
> 2014-02-21 18:30:52,304 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) No suitable pools found
> 2014-02-21 18:30:52,304 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) No suitable storagePools found unde$
> 2014-02-21 18:30:52,307 DEBUG [cloud.deploy.DeploymentPlanningManagerImpl] (consoleproxy-1:null) Could not find suitable Deployment $
> 2014-02-21 18:30:52,307 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Searching all possible resources under this Zone:$
> 2014-02-21 18:30:52,308 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Listing clusters in order of aggregate capacity, $
> 2014-02-21 18:30:52,311 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) Removing from the clusterId list these clusters f$
> 2014-02-21 18:30:52,311 DEBUG [cloud.deploy.FirstFitPlanner] (consoleproxy-1:null) No clusters found after removing disabled cluster$
> 2014-02-21 18:30:52,346 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-365101203: Received:  { Ans: , MgmtId: 1593876$
> 2014-02-21 18:30:52,405 DEBUG [cloud.capacity.CapacityManagerImpl] (consoleproxy-1:null) VM state transitted from :Starting to Stopp$
> 2014-02-21 18:30:52,410 WARN  [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Exception while trying to start con$
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a deployment for VM[ConsoleProxy|v-1-VM]Scope=interface co$
>         at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:842)
>         at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:578)
>         at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:571)
>         at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:556)
>         at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:928)
>         at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1672)
>         at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157)
>         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$Sync.innerRunAndReset(FutureTask.java:351)
>         at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>         at java.lang.Thread.run(Thread.java:701)
> 2014-02-21 18:30:52,767 DEBUG [cloud.network.ExternalDeviceUsageManagerImpl] (ExternalNetworkMonitor-1:null) External devices stats $
> 2014-02-21 18:30:52,794 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:null) Found 0 running routers.
> 2014-02-21 18:30:52,796 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
> 2014-02-21 18:30:52,798 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
> 2014-02-21 18:30:52,804 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1:null) Found 0 running routers.
> 2014-02-21 18:30:52,804 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
> 2014-02-21 18:30:52,806 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
> 2014-02-21 18:30:53,295 DEBUG [storage.snapshot.SnapshotSchedulerImpl] (SnapshotPollTask:null) Snapshot scheduler.poll is being call$
> 2014-02-21 18:30:53,297 DEBUG [storage.snapshot.SnapshotSchedulerImpl] (SnapshotPollTask:null) Got 0 snapshots to be executed at 201$
> The agent.log gives me:
> 2014-02-21 18:32:24,892 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 1-73:  { Cmd , MgmtId: -1, via: 1, Ver: v1, F$
> 2014-02-21 18:32:24,903 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Received response: Seq 1-73:  { Ans: , MgmtId: 159387626793$
> 2014-02-21 18:32:52,447 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Processing command: com.cloud.agent.api.GetStorageSt$
> 2014-02-21 18:33:18,307 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.GetHostStats$
> 2014-02-21 18:33:18,307 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c idle=$(t$
> 2014-02-21 18:33:18,829 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful.
> 2014-02-21 18:33:18,829 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c freeMem=$
> 2014-02-21 18:33:18,839 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful.
> 2014-02-21 18:33:18,839 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c free|gre$
> 2014-02-21 18:33:18,847 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful.
> 2014-02-21 18:33:24,827 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Executing: /usr/share/cloudstack-common/scr$
> 2014-02-21 18:33:24,883 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Execution is successful.
> 2014-02-21 18:33:24,884 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 1-74:  { Cmd , MgmtId: -1, via: 1, Ver: v1, F$
> 2014-02-21 18:33:24,895 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null) Received response: Seq 1-74:  { Ans: , MgmtId: 159387626793$
> The output of "ifconfig" on my hypervisor is:
> br0       Link encap:Ethernet  Endereço de HW 1c:6f:65:d7:4a:4b  
>           inet end.: 10.16.1.34  Bcast:10.16.255.255  Masc:255.255.0.0
>           endereço inet6: fe80::1e6f:65ff:fed7:4a4b/64 Escopo:Link
>           UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1
>           pacotes RX:58025 erros:0 descartados:0 excesso:0 quadro:0
>           Pacotes TX:48982 erros:0 descartados:0 excesso:0 portadora:0
>           colisões:0 txqueuelen:0 
>           RX bytes:71081838 (71.0 MB) TX bytes:6757079 (6.7 MB)
> br1       Link encap:Ethernet  Endereço de HW ee:24:80:dd:23:f9  
>           endereço inet6: fe80::ec24:80ff:fedd:23f9/64 Escopo:Link
>           UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1
>           pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
>           Pacotes TX:183 erros:0 descartados:0 excesso:0 portadora:0
>           colisões:0 txqueuelen:0 
>           RX bytes:0 (0.0 B) TX bytes:52722 (52.7 KB)
> br1:avahi Link encap:Ethernet  Endereço de HW ee:24:80:dd:23:f9  
>           inet end.: 169.254.10.37  Bcast:169.254.255.255  Masc:255.255.0.0
>           UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1
> cloud0    Link encap:Ethernet  Endereço de HW 56:8c:6c:b0:95:a8  
>           inet end.: 169.254.0.1  Bcast:169.254.255.255  Masc:255.255.0.0
>           endereço inet6: fe80::548c:6cff:feb0:95a8/64 Escopo:Link
>           UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1
>           pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
>           Pacotes TX:63 erros:0 descartados:0 excesso:0 portadora:0
>           colisões:0 txqueuelen:0 
>           RX bytes:0 (0.0 B) TX bytes:11411 (11.4 KB)
> eth0      Link encap:Ethernet  Endereço de HW 00:e0:4c:68:17:30  
>           UP BROADCAST MULTICAST  MTU:1500  Métrica:1
>           pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
>           Pacotes TX:0 erros:0 descartados:0 excesso:0 portadora:0
>           colisões:0 txqueuelen:1000 
>           RX bytes:0 (0.0 B) TX bytes:0 (0.0 B)
> eth1      Link encap:Ethernet  Endereço de HW 5c:d9:98:b1:6f:2d  
>           UP BROADCAST MULTICAST  MTU:1500  Métrica:1
>           pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
>           Pacotes TX:0 erros:0 descartados:0 excesso:0 portadora:0
>           colisões:0 txqueuelen:1000 
>           RX bytes:0 (0.0 B) TX bytes:0 (0.0 B)
> eth2      Link encap:Ethernet  Endereço de HW 1c:6f:65:d7:4a:4b  
>           endereço inet6: fe80::1e6f:65ff:fed7:4a4b/64 Escopo:Link
>           UP BROADCAST RUNNING MULTICAST  MTU:1500  Métrica:1
>           pacotes RX:61601 erros:0 descartados:102 excesso:0 quadro:0
>           Pacotes TX:49016 erros:0 descartados:0 excesso:0 portadora:0
>           colisões:0 txqueuelen:1000 
>           RX bytes:72158063 (72.1 MB) TX bytes:6778184 (6.7 MB)
> lo        Link encap:Loopback Local  
>           inet end.: 127.0.0.1  Masc:255.0.0.0
>           endereço inet6: ::1/128 Escopo:Máquina
>           UP LOOPBACK RUNNING  MTU:65536  Métrica:1
>           pacotes RX:245 erros:0 descartados:0 excesso:0 quadro:0
>           Pacotes TX:245 erros:0 descartados:0 excesso:0 portadora:0
>           colisões:0 txqueuelen:0 
>           RX bytes:20092 (20.0 KB) TX bytes:20092 (20.0 KB)
> virbr0    Link encap:Ethernet  Endereço de HW 8a:7e:d9:10:69:32  
>           inet end.: 192.168.122.1  Bcast:192.168.122.255  Masc:255.255.255.0
>           UP BROADCAST MULTICAST  MTU:1500  Métrica:1
>           pacotes RX:0 erros:0 descartados:0 excesso:0 quadro:0
>           Pacotes TX:0 erros:0 descartados:0 excesso:0 portadora:0
>           colisões:0 txqueuelen:0 
>           RX bytes:0 (0.0 B) TX bytes:0 (0.0 B)
> I have the br0, which is the public, network and the br1, which is the private network.
> The /etc/cloudstack/agent/agent.properties looks like:
> #Storage
> #Fri Feb 21 17:20:25 BRT 2014
> guest.network.device=br0
> workers=5
> private.network.device=br1
> port=8250
> resource=com.cloud.hypervisor.kvm.resource.LibvirtComputingResource
> pod=1
> zone=1
> guid=2e1d6dee-aa9a-3e29-8fb7-995490b62daf
> public.network.device=br0
> cluster=1
> local.storage.uuid=eae1fe36-6779-435c-99b5-e39af074ef74
> domr.scripts.dir=scripts/network/domr/kvm
> LibvirtComputingResource.id=1
> host=10.16.1.32



--
This message was sent by Atlassian JIRA
(v6.1.5#6160)

Mime
View raw message