You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Ana Paula de Sousa (JIRA)" <ji...@apache.org> on 2014/02/21 22:17:19 UTC
[jira] [Created] (CLOUDSTACK-6153) Unable to start a VM on
Cloudstack
Ana Paula de Sousa created CLOUDSTACK-6153:
----------------------------------------------
Summary: Unable to start a 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 on my lab.
Reporter: Ana Paula de Sousa
When I'm at the UI of cloudstack and I try to add a VM on "System VMs" it gives me a loading symbol and never get out of it, and it makes me unable to test the environment.
The log of the management-server.log gives me:
2014-02-21 18:01:23,297 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Executing storage capacity update
2014-02-21 18:01:23,303 DEBUG [cloud.storage.StorageManagerImpl] (CapacityChecker:null) Successfully set Capacity - 47275958272 for $
2014-02-21 18:01:23,303 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Done executing storage capacity update
2014-02-21 18:01:23,303 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Executing capacity updates for public ip and Vla$
2014-02-21 18:01:23,310 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Done capacity updates for public ip and Vlans
2014-02-21 18:01:23,310 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Executing capacity updates for private ip
2014-02-21 18:01:23,316 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Done executing capacity updates for private ip
2014-02-21 18:01:23,316 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Done recalculating system capacity
2014-02-21 18:01:23,352 DEBUG [cloud.alert.AlertManagerImpl] (CapacityChecker:null) Done running Capacity Checker ...
2014-02-21 18:01:24,845 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-13:null) Ping from 1
2014-02-21 18:01:34,566 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) VmStatsCollector is running...
2014-02-21 18:01:50,323 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) StorageCollector is running...
2014-02-21 18:01:50,328 INFO [storage.endpoint.DefaultEndPointSelector] (StatsCollector-3:null) No running ssvm is found, so comman$
2014-02-21 18:01:50,386 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-365101145: Received: { Ans: , MgmtId: 1593876$
2014-02-21 18:01:52,796 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:01:52,798 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:01:52,804 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:01:52,806 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:01:59,393 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Resetting hosts suitable for reconnect
2014-02-21 18:01:59,395 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed resetting hosts suitable for recon$
2014-02-21 18:01:59,395 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Acquiring hosts for clusters already owned b$
2014-02-21 18:01:59,396 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed acquiring hosts for clusters alrea$
2014-02-21 18:01:59,396 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Acquiring hosts for clusters not owned by an$
2014-02-21 18:01:59,396 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed acquiring hosts for clusters not o$
2014-02-21 18:01:59,676 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) HostStatsCollector is running...
2014-02-21 18:02:00,291 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-365101146: Received: { Ans: , MgmtId: 1593876$
2014-02-21 18:02:22,796 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:02:22,797 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:02:22,805 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:02:22,806 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:02:24,850 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-1:null) Ping from 1
2014-02-21 18:02:34,570 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) VmStatsCollector is running...
2014-02-21 18:02:50,387 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) StorageCollector is running...
2014-02-21 18:02:50,393 INFO [storage.endpoint.DefaultEndPointSelector] (StatsCollector-3:null) No running ssvm is found, so comman$
2014-02-21 18:02:50,450 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-365101147: Received: { Ans: , MgmtId: 1593876$
2014-02-21 18:02:52,796 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:02:52,798 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:02:52,804 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:02:52,806 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:03:00,292 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) HostStatsCollector is running...
2014-02-21 18:03:00,889 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 1-365101148: Received: { Ans: , MgmtId: 1593876$
2014-02-21 18:03:22,796 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:03:22,797 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:03:22,804 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:03:22,806 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:03:24,873 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-4:null) Ping from 1
2014-02-21 18:03:29,393 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Resetting hosts suitable for reconnect
2014-02-21 18:03:29,395 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed resetting hosts suitable for recon$
2014-02-21 18:03:29,395 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Acquiring hosts for clusters already owned b$
2014-02-21 18:03:29,396 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed acquiring hosts for clusters alrea$
2014-02-21 18:03:29,396 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Acquiring hosts for clusters not owned by an$
2014-02-21 18:03:29,396 DEBUG [host.dao.HostDaoImpl] (ClusteredAgentManager Timer:null) Completed acquiring hosts for clusters not o$
2014-02-21 18:03:34,574 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) VmStatsCollector is running...
2014-02-21 18:03:46,486 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null) ===START=== 10.16.1.34 -- GET command=listZones&respo$
2014-02-21 18:03:46,498 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null) ===END=== 10.16.1.34 -- GET command=listZones&respons$
2014-02-21 18:03:46,576 DEBUG [cloud.api.ApiServlet] (catalina-exec-14:null) ===START=== 10.16.1.34 -- GET command=listPods&respon$
2014-02-21 18:03:46,590 DEBUG [cloud.api.ApiServlet] (catalina-exec-14:null) ===END=== 10.16.1.34 -- GET command=listPods&response$
2014-02-21 18:03:46,597 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===START=== 10.16.1.34 -- GET command=listClusters&res$
2014-02-21 18:03:46,612 DEBUG [cloud.api.ApiServlet] (catalina-exec-1:null) ===END=== 10.16.1.34 -- GET command=listClusters&respo$
2014-02-21 18:03:46,617 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===START=== 10.16.1.34 -- GET command=listHosts&respo$
2014-02-21 18:03:46,625 DEBUG [api.query.QueryManagerImpl] (catalina-exec-22:null) >>>Searching for hosts>>>
2014-02-21 18:03:46,632 DEBUG [api.query.QueryManagerImpl] (catalina-exec-22:null) >>>Generating Response>>>
2014-02-21 18:03:46,639 DEBUG [cloud.api.ApiServlet] (catalina-exec-22:null) ===END=== 10.16.1.34 -- GET command=listHosts&respons$
2014-02-21 18:03:46,644 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===START=== 10.16.1.34 -- GET command=listStoragePools$
2014-02-21 18:03:46,657 DEBUG [cloud.api.ApiServlet] (catalina-exec-5:null) ===END=== 10.16.1.34 -- GET command=listStoragePools&r$
2014-02-21 18:03:46,666 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===START=== 10.16.1.34 -- GET command=listImageStores&$
2014-02-21 18:03:46,680 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null) ===END=== 10.16.1.34 -- GET command=listImageStores&re$
2014-02-21 18:03:46,683 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null) ===START=== 10.16.1.34 -- GET command=listSystemVms&re$
2014-02-21 18:03:46,692 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:null) ===END=== 10.16.1.34 -- GET command=listSystemVms&resp$
2014-02-21 18:03:46,698 DEBUG [cloud.api.ApiServlet] (catalina-exec-19:null) ===START=== 10.16.1.34 -- GET command=listRouters&res$
2014-02-21 18:03:46,712 DEBUG [cloud.api.ApiServlet] (catalina-exec-19:null) ===END=== 10.16.1.34 -- GET command=listRouters&respo$
2014-02-21 18:03:46,715 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null) ===START=== 10.16.1.34 -- GET command=listRouters&res$
2014-02-21 18:03:46,721 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null) ===END=== 10.16.1.34 -- GET command=listRouters&respo$
2014-02-21 18:03:46,728 DEBUG [cloud.api.ApiServlet] (catalina-exec-20:null) ===START=== 10.16.1.34 -- GET command=listCapacity&re$
2014-02-21 18:03:46,744 DEBUG [cloud.api.ApiServlet] (catalina-exec-20:null) ===END=== 10.16.1.34 -- GET command=listCapacity&resp$
2014-02-21 18:03:50,451 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) StorageCollector is running...
2014-02-21 18:03:50,456 INFO [storage.endpoint.DefaultEndPointSelector] (StatsCollector-2:null) No running ssvm is found, so comman$
2014-02-21 18:03:50,518 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 1-365101149: Received: { Ans: , MgmtId: 1593876$
2014-02-21 18:03:52,796 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:03:52,797 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:03:52,804 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:03:52,806 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:04:00,889 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) HostStatsCollector is running...
2014-02-21 18:04:01,512 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-365101150: Received: { Ans: , MgmtId: 1593876$
2014-02-21 18:04:13,588 DEBUG [cloud.api.ApiServlet] (catalina-exec-15:null) ===START=== 10.16.1.34 -- GET command=listSystemVms&r$
2014-02-21 18:04:13,598 DEBUG [cloud.api.ApiServlet] (catalina-exec-15:null) ===END=== 10.16.1.34 -- GET command=listSystemVms&res$
2014-02-21 18:04:22,796 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:04:22,797 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:04:22,804 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to up$
2014-02-21 18:04:22,806 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to u$
2014-02-21 18:04:24,873 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-7:null) Ping from 1
The agent.log gives me:
2014-02-21 18:08:24,884 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 1-49: { Cmd , MgmtId: -1, via: 1, Ver: v1, F$
2014-02-21 18:08:24,896 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null) Received response: Seq 1-49: { Ans: , MgmtId: 159387626793$
2014-02-21 18:08:50,816 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Processing command: com.cloud.agent.api.GetStorageSt$
2014-02-21 18:09:03,959 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Processing command: com.cloud.agent.api.GetHostStats$
2014-02-21 18:09:03,960 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Executing: /bin/bash -c idle=$(t$
2014-02-21 18:09:04,479 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Execution is successful.
2014-02-21 18:09:04,480 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Executing: /bin/bash -c freeMem=$
2014-02-21 18:09:04,486 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Execution is successful.
2014-02-21 18:09:04,486 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Executing: /bin/bash -c free|gre$
2014-02-21 18:09:04,490 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Execution is successful.
2014-02-21 18:09:24,825 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Executing: /usr/share/cloudstack-common/scr$
2014-02-21 18:09:24,887 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Execution is successful.
2014-02-21 18:09:24,889 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 1-50: { Cmd , MgmtId: -1, via: 1, Ver: v1, F$
2014-02-21 18:09:24,902 DEBUG [cloud.agent.Agent] (Agent-Handler-3:null) Received response: Seq 1-50: { 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)