Is this for a KVM host based on centos 7? On Dec 11, 2016 23:28, "Felipe Arturo Polanco" <felipeapola...@gmail.com> wrote:
> Hi, > > I'm having major issues when trying to add a new host into a fresh install > of Cloudstack, I have tested in 4.6 and 4.8 and get the same result, in 4.9 > the agent can't connect but it does from 4.8 downwards. > > From the logs I see that the management can ssh into the host and issue the > cloudstack-setup-agent command with some parameters and it does succeed but > after that it tries to insert some values into the mysql cloud database in > the "host" table but it fails, after that it tries to send something via > API and fails too. > > **I'm setting this up in VMWare workstation 12 on a laptop with nested > virtualization** > > I followed this guide > http://docs.cloudstack.apache.org/projects/cloudstack-installation/en/4.8/ > management-server/index.html > and this one for the host > http://docs.cloudstack.apache.org/projects/cloudstack-installation/en/4.8/ > configuration.html#adding-a-host > > I checked and have the ports open in management: > > Proto Recv-Q Send-Q Local Address Foreign Address State > PID/Program name > tcp 0 0 0.0.0.0:111 0.0.0.0:* LISTEN > 1172/rpcbind > tcp 0 0 0.0.0.0:20400 0.0.0.0:* LISTEN > 10316/java > tcp 0 0 0.0.0.0:8080 0.0.0.0:* LISTEN > 10316/java > tcp 0 0 0.0.0.0:20048 0.0.0.0:* LISTEN > 1237/rpc.mountd > tcp 0 0 192.168.122.1:53 0.0.0.0:* LISTEN > 2073/dnsmasq > tcp 0 0 0.0.0.0:44373 0.0.0.0:* LISTEN > 1168/rpc.statd > tcp 0 0 0.0.0.0:22 0.0.0.0:* LISTEN > 1157/sshd > tcp 0 0 0.0.0.0:8250 0.0.0.0:* LISTEN > 10316/java > tcp 0 0 0.0.0.0:45662 0.0.0.0:* LISTEN > - > tcp 0 0 0.0.0.0:36385 0.0.0.0:* LISTEN > 10316/java > tcp 0 0 0.0.0.0:2049 0.0.0.0:* LISTEN > - > tcp 0 0 0.0.0.0:9090 0.0.0.0:* LISTEN > 10316/java > tcp 0 0 127.0.0.1:8005 0.0.0.0:* LISTEN > 10316/java > tcp 0 0 0.0.0.0:37029 0.0.0.0:* LISTEN > 10316/java > tcp 0 64 192.168.1.147:22 192.168.1.113:54267 > ESTABLISHED 4269/sshd: felipe [ > tcp 0 0 127.0.0.1:52772 127.0.0.1:3306 > ESTABLISHED 10316/java > tcp 0 0 127.0.0.1:52890 127.0.0.1:3306 > ESTABLISHED 10316/java > tcp 0 0 127.0.0.1:52774 127.0.0.1:3306 > ESTABLISHED 10316/java > tcp 0 0 127.0.0.1:52892 127.0.0.1:3306 > ESTABLISHED 10316/java > tcp 0 0 192.168.1.147:22 192.168.1.113:54020 > ESTABLISHED 2803/sshd: felipe [ > tcp 0 0 127.0.0.1:52886 127.0.0.1:3306 > ESTABLISHED 10316/java > tcp 0 0 127.0.0.1:52786 127.0.0.1:3306 > ESTABLISHED 10316/java > tcp 0 0 127.0.0.1:52884 127.0.0.1:3306 > ESTABLISHED 10316/java > tcp6 0 0 :::3306 :::* LISTEN > 10111/mysqld > tcp6 0 0 :::111 :::* LISTEN > 1172/rpcbind > tcp6 0 0 :::20048 :::* LISTEN > 1237/rpc.mountd > tcp6 0 0 :::22 :::* LISTEN > 1157/sshd > tcp6 0 0 :::39704 :::* LISTEN > - > tcp6 0 0 :::60640 :::* LISTEN > 1168/rpc.statd > tcp6 0 0 :::2049 :::* LISTEN > - > tcp6 0 0 127.0.0.1:3306 127.0.0.1:52890 > ESTABLISHED 10111/mysqld > tcp6 0 0 127.0.0.1:3306 127.0.0.1:52772 > ESTABLISHED 10111/mysqld > tcp6 0 0 127.0.0.1:3306 127.0.0.1:52892 > ESTABLISHED 10111/mysqld > tcp6 0 453 127.0.0.1:3306 127.0.0.1:52774 > ESTABLISHED 10111/mysqld > tcp6 0 0 127.0.0.1:3306 127.0.0.1:52884 > ESTABLISHED 10111/mysqld > tcp6 0 0 127.0.0.1:3306 127.0.0.1:52886 > ESTABLISHED 10111/mysqld > tcp6 0 0 127.0.0.1:3306 127.0.0.1:52786 > ESTABLISHED 10111/mysqld > udp 0 0 0.0.0.0:20048 0.0.0.0:* > 1237/rpc.mountd > udp 0 0 0.0.0.0:44766 0.0.0.0:* > 956/dhclient > udp 0 0 0.0.0.0:40682 0.0.0.0:* > 10316/java > udp 0 0 0.0.0.0:57148 0.0.0.0:* > - > udp 0 0 0.0.0.0:2049 0.0.0.0:* > - > udp 0 0 192.168.122.1:53 0.0.0.0:* > 2073/dnsmasq > udp 0 0 0.0.0.0:67 0.0.0.0:* > 2073/dnsmasq > udp 0 0 0.0.0.0:68 0.0.0.0:* > 956/dhclient > udp 0 0 0.0.0.0:111 0.0.0.0:* > 1172/rpcbind > udp 0 0 0.0.0.0:4446 0.0.0.0:* > 10316/java > udp 0 0 0.0.0.0:4446 0.0.0.0:* > 10316/java > udp 0 0 0.0.0.0:39791 0.0.0.0:* > 1168/rpc.statd > udp 0 0 0.0.0.0:917 0.0.0.0:* > 1172/rpcbind > udp 0 0 127.0.0.1:920 0.0.0.0:* > 1168/rpc.statd > udp6 0 0 :::20048 :::* > 1237/rpc.mountd > udp6 0 0 :::38744 :::* > 1168/rpc.statd > udp6 0 0 :::2049 :::* > - > udp6 0 0 :::111 :::* > 1172/rpcbind > udp6 0 0 :::55463 :::* > 956/dhclient > udp6 0 0 :::35028 :::* > - > udp6 0 0 :::917 :::* > 1172/rpcbind > > > The IPs are: > 192.168.1.147 MANAGEMENT > 192.168.1.140 host > > Here are my logs from management where it fails: > > 2016-12-11 19:24:32,887 DEBUG [c.c.r.ResourceManagerImpl] > (AgentConnectTaskPool-111:ctx-0f9761e6) (logid:61cc1e9a) Dispatching > resource state event CREATE_HOST_VO_FOR_CONNECTED to OvmDiscoverer > 2016-12-11 19:24:32,887 DEBUG [c.c.r.ResourceManagerImpl] > (AgentConnectTaskPool-111:ctx-0f9761e6) (logid:61cc1e9a) Dispatching > resource state event CREATE_HOST_VO_FOR_CONNECTED to KvmServerDiscoverer > 2016-12-11 19:24:32,892 DEBUG [c.c.u.d.T.Transaction] > (AgentConnectTaskPool-111:ctx-0f9761e6) (logid:61cc1e9a) Rolling back the > transaction: Time = 1 Name = AgentConnectTaskPool-111; called by > -TransactionLegacy.rollback:879-TransactionLegacy.removeUpTo:822- > TransactionLegacy.close:646-TransactionContextInterceptor.invoke:36- > ReflectiveMethodInvocation.proceed:161-ExposeInvocationInterceptor. > invoke:91-ReflectiveMethodInvocation.proceed:172- > JdkDynamicAopProxy.invoke:204-$Proxy62.persist:-1-ResourceManagerImpl. > createHostVO:1699-ResourceManagerImpl.createHostVOForConnectedAgent:1950- > GeneratedMethodAccessor100.invoke:-1 > 2016-12-11 19:24:32,892 DEBUG [c.c.a.m.AgentManagerImpl] > (AgentConnectTaskPool-111:ctx-0f9761e6) (logid:61cc1e9a) Failed to handle > host connection: com.cloud.utils.exception.CloudRuntimeException: DB > Exception on: com.mysql.jdbc.JDBC4PreparedStatement@378d930f: INSERT INTO > host (host.disconnected, host.name, host.status, host.type, > host.private_ip_address, host.private_mac_address, host.private_netmask, > host.public_netmask, host.public_ip_address, host.public_mac_address, > host.storage_ip_address, host.cluster_id, host.storage_netmask, > host.storage_mac_address, host.storage_ip_address_2, > host.storage_netmask_2, host.storage_mac_address_2, host.hypervisor_type, > host.proxy_port, host.resource, host.fs_type, host.available, host.setup, > host.resource_state, host.hypervisor_version, host.update_count, host.uuid, > host.data_center_id, host.pod_id, host.cpu_sockets, host.cpus, host.url, > host.speed, host.ram, host.parent, host.guid, host.capabilities, > host.total_size, host.last_ping, host.mgmt_server_id, host.dom0_memory, > host.version, host.created) VALUES (null, _binary'server3', 'Creating', > 'Routing', _binary'192.168.1.140', _binary'00:0c:29:13:3b:2a', > _binary'255.255.255.0', null, null, null, _binary'192.168.1.140', 1, > _binary'255.255.255.0', _binary'00:0c:29:13:3b:2a', null, null, null, > 'KVM', null, null, null, 1, 0, 'Creating', null, 0, > _binary'624c5f5a-4d30-42b8-98ce-9cf9f9593900', 1, 1, 2, 2, null, 2601, > -49401856, null, > _binary'4cff4b32-72bc-31d6-af43-c59ff0ca2711-LibvirtComputingResource', > _binary'hvm,snapshot', null, 1446779563, 52237163884, 0, _binary'4.8.0', > '2016-12-12 00:24:32') > 2016-12-11 19:24:32,893 WARN [c.c.a.m.AgentManagerImpl] > (AgentConnectTaskPool-111:ctx-0f9761e6) (logid:61cc1e9a) Unable to create > attache for agent: Seq 0-0: { Cmd , MgmtId: -1, via: 0, Ver: v1, Flags: 1, > [{"com.cloud.agent.api.StartupRoutingCommand":{" > cpuSockets":2,"cpus":2,"speed":2601,"memory":-49401856," > dom0MinMemory":1073741824,"poolSync":false,"caps":"hvm, > snapshot","pool":"/root","hypervisorType":"KVM"," > hostDetails":{"Host.OS.Kernel.Version":"3.10.0-327.36.3.el7. > x86_64","com.cloud.network.Networks.RouterPrivateIpStrategy":" > HostLocal","Host.OS.Version":"7.2.1511","Host.OS":"CentOS"}, > "hostTags":[],"groupDetails":{},"type":"Routing"," > dataCenter":"1","pod":"1","cluster":"1","guid":"4cff4b32- > 72bc-31d6-af43-c59ff0ca2711-LibvirtComputingResource"," > name":"server3","id":0,"version":"4.8.0","privateIpAddress":"192.168.1. > 140","privateMacAddress":"00:0c:29:13:3b:2a"," > privateNetmask":"255.255.255.0","storageIpAddress":"192. > 168.1.140","storageNetmask":"255.255.255.0","storageMacAddress":"00:0c:29: > 13:3b:2a","resourceName":"LibvirtComputingResource"," > gatewayIpAddress":"192.168.1.1","wait":0}},{"com.cloud.agent.api. > StartupStorageCommand":{"totalSize":0,"poolInfo":{" > uuid":"8616ce35-3d7f-4359-940d-6d8e481f934d","host":" > 192.168.1.140","localPath":"/var/lib/libvirt/images"," > hostPath":"/var/lib/libvirt/images","poolType":" > Filesystem","capacityBytes":18746441728,"availableBytes": > 17023397888},"resourceType":"STORAGE_POOL","hostDetails":{} > ,"type":"Storage","dataCenter":"1","pod":"1","guid":" > 4cff4b32-72bc-31d6-af43-c59ff0ca2711-LibvirtComputingResource"," > name":"server3","id":0,"version":"4.8.0","resourceName":" > LibvirtComputingResource","wait":0}}] > } > 2016-12-11 19:24:32,977 WARN [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-13:null) (logid:) Throwing away a request because it > came through as the first command on a connect: Seq 0--1: { Cmd , MgmtId: > -1, via: 0, Ver: v1, Flags: 111, > [{"com.cloud.agent.api.ShutdownCommand":{"reason":"sig.kill","wait":0}}] } > 2016-12-11 19:24:32,977 WARN [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-14:null) (logid:) Throwing away a request because it > came through as the first command on a connect: Seq 0-1: { Cmd , MgmtId: > -1, via: 0, Ver: v1, Flags: 11, > [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand > ":{"newGroupStates":{},"_hostVmStateReport":{},"_ > gatewayAccessible":true,"_vnetAccessible":true," > hostType":"Routing","hostId":0,"wait":0}}] > } > 2016-12-11 19:24:34,268 INFO [c.c.a.m.AgentManagerImpl] > (AgentManager-Handler-15:null) (logid:) Connection from /192.168.1.140 > closed but no cleanup was done. > > > Here are the logs of the agent > > 2016-12-11 19:27:02,054 INFO [cloud.agent.AgentShell] (main:null) (logid:) > Agent started > 2016-12-11 19:27:02,056 INFO [cloud.agent.AgentShell] (main:null) (logid:) > Implementation Version is 4.8.0 > 2016-12-11 19:27:02,057 INFO [cloud.agent.AgentShell] (main:null) (logid:) > agent.properties found at /etc/cloudstack/agent/agent.properties > 2016-12-11 19:27:02,061 INFO [cloud.agent.AgentShell] (main:null) (logid:) > Defaulting to using properties file for storage > 2016-12-11 19:27:02,062 INFO [cloud.agent.AgentShell] (main:null) (logid:) > Defaulting to the constant time backoff algorithm > 2016-12-11 19:27:02,075 INFO [cloud.utils.LogUtils] (main:null) (logid:) > log4j configuration found at /etc/cloudstack/agent/log4j-cloud.xml > 2016-12-11 19:27:02,087 INFO [cloud.agent.AgentShell] (main:null) (logid:) > Preferring IPv4 address family for agent connection > 2016-12-11 19:27:02,200 INFO [cloud.agent.Agent] (main:null) (logid:) id > is 0 > 2016-12-11 19:27:02,202 WARN [cloud.resource.ServerResourceBase] > (main:null) (logid:) Nics are not specified in properties file/db, will try > to autodiscover > 2016-12-11 19:27:02,207 INFO [cloud.resource.ServerResourceBase] > (main:null) (logid:) Designating private to be nic eth0 > 2016-12-11 19:27:02,223 INFO [kvm.resource.LibvirtConnection] (main:null) > (logid:) No existing libvirtd connection found. Opening a new one > 2016-12-11 19:27:02,402 INFO [org.reflections.Reflections] (main:null) > (logid:) Reflections took 35 ms to scan 1 urls, producing 7 keys and 10 > values > 2016-12-11 19:27:02,532 INFO [kvm.resource.LibvirtComputingResource] > (main:null) (logid:) No libvirt.vif.driver specified. Defaults to > BridgeVifDriver. > 2016-12-11 19:27:02,551 INFO [cloud.agent.Agent] (main:null) (logid:) > Agent [id = 0 : type = LibvirtComputingResource : zone = 1 : pod = 1 : > workers = 5 : host = 192.168.1.147 : port = 8250 > 2016-12-11 19:27:02,554 INFO [utils.nio.NioClient] (main:null) (logid:) > Connecting to 192.168.1.147:8250 > 2016-12-11 19:27:02,715 INFO [utils.nio.NioClient] (main:null) (logid:) > SSL: Handshake done > 2016-12-11 19:27:02,715 INFO [utils.nio.NioClient] (main:null) (logid:) > Connected to 192.168.1.147:8250 > 2016-12-11 19:27:02,722 WARN [kvm.resource.LibvirtComputingResource] > (Agent-Handler-1:null) (logid:) Could not read cpuinfo_max_freq > 2016-12-11 19:27:02,762 INFO [kvm.storage.LibvirtStorageAdaptor] > (Agent-Handler-1:null) (logid:) Attempting to create storage pool > 8616ce35-3d7f-4359-940d-6d8e481f934d (Filesystem) in libvirt > 2016-12-11 19:27:02,766 INFO [kvm.storage.LibvirtStorageAdaptor] > (Agent-Handler-1:null) (logid:) Found existing defined storage pool > 8616ce35-3d7f-4359-940d-6d8e481f934d, using it. > 2016-12-11 19:27:02,766 INFO [kvm.storage.LibvirtStorageAdaptor] > (Agent-Handler-1:null) (logid:) Trying to fetch storage pool > 8616ce35-3d7f-4359-940d-6d8e481f934d from libvirt > 2016-12-11 19:27:02,819 INFO [cloud.serializer.GsonHelper] > (Agent-Handler-1:null) (logid:) Default Builder inited. > 2016-12-11 19:27:02,848 INFO [cloud.agent.Agent] (Agent-Handler-2:null) > (logid:) Proccess agent startup answer, agent id = 0 > 2016-12-11 19:27:02,849 INFO [cloud.agent.Agent] (Agent-Handler-2:null) > (logid:) Set agent id 0 > 2016-12-11 19:27:02,856 INFO [cloud.agent.Agent] (Agent-Handler-2:null) > (logid:) Startup Response Received: agent id = 0 > 2016-12-11 19:27:02,859 INFO [cloud.agent.Agent] > (AgentShutdownThread:null) (logid:) Stopping the agent: Reason = sig.kill >