You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Keyur Bhalerao <ke...@persistent.com> on 2016/02/01 20:39:54 UTC

DB Exception while adding Host on Cloud stack 4.6 fresh installation (Ubuntu 15.04)

Hi ,

I have installed Cloud stack version 4.6 to be more precise  -
{"listcapabilitiesresponse":{"capability":{"securitygroupsenabled":false,"cloudstackversion":"4.6.2","userpublictemplateenabled":true,"supportELB":"false","projectinviterequired":false,"allowusercreateprojects":true,"customdiskofferingminsize":1,"customdiskofferingmaxsize":1024,"regionsecondaryenabled":false,"kvmsnapshotenabled":false,"allowuserviewdestroyedvm":true,"allowuserexpungerecovervm":true}}}

On Ubuntu 15.04 with following KVM details -

Compiled against library: libvirt 1.2.12
Using library: libvirt 1.2.12
Using API: QEMU 1.2.12
Running hypervisor: QEMU 2.2.0

It's a single VM installation where storage and management server are on same VM . I have followed all the required steps from the documentation provided in - http://www.shapeblue.com/deploying-cloudstack-with-kvm/
I am able to successfully login management console and create ZONE , POD , CLUSTER successfully. Its failing while adding the host . Here are the log details (Log level changed to TRACE). Cloud stack- Agent dies after we try to add host from the console. It says active (exited)

Management Logs :

2016-02-01 11:14:15,761 TRACE [c.c.u.d.T.Connection] (AgentConnectTaskPool-1:ctx-370d8502) Creating a DB connection with  txn:  for 0: dbconn78420063. Stack: -TransactionLegacy.prepareAutoCloseStatement:477-GenericDaoBase.persist:1368-HostDaoImpl.persist:797-HostDaoImpl.persist:69-NativeMethodAccessorImpl.invoke0:-2-NativeMethodAccessorImpl.invoke:57-DelegatingMethodAccessorImpl.invoke:43-Method.invoke:606-AopUtils.invokeJoinpointUsingReflection:317-ReflectiveMethodInvocation.invokeJoinpoint:183-ReflectiveMethodInvocation.proceed:150-TransactionContextInterceptor.invoke:34
2016-02-01 11:14:15,769 TRACE [c.c.u.d.T.Statement] (AgentConnectTaskPool-1:ctx-370d8502) Preparing: 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 (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2016-02-01 11:14:15,837 TRACE [c.c.u.d.T.Statement] (AgentConnectTaskPool-1:ctx-370d8502) Closing: com.mysql.jdbc.JDBC4PreparedStatement@5f47875e: 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'cstest-virtual-machine', 'Creating', 'Routing', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'255.255.252.0', _binary'255.255.252.0', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'10.25.1.89', 2, _binary'255.255.252.0', _binary'00:50:56:b3:1f:88', null, null, null, 'KVM', null, null, null, 1, 0, 'Creating', null, 0, _binary'ffc9fd4c-4778-427d-95ba-e17293bb145e', 2, 2, 1, 1, null, 2393, -32403456, null, _binary'6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource', _binary'hvm,snapshot', null, 1420267632, 20696084691758, 0, _binary'4.6.2', '2016-02-01 19:14:15')
2016-02-01 11:14:15,837 TRACE [c.c.u.d.T.Connection] (AgentConnectTaskPool-1:ctx-370d8502) txn: Not closing DB connection because we're still in a transaction.
2016-02-01 11:14:15,837 DEBUG [c.c.u.d.T.Transaction] (AgentConnectTaskPool-1:ctx-370d8502) Rolling back the transaction: Time = 77 Name =  AgentConnectTaskPool-1; 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-$Proxy59.persist:-1-ResourceManagerImpl.createHostVO:1701-ResourceManagerImpl.createHostVOForConnectedAgent:1952-NativeMethodAccessorImpl.invoke0:-2
2016-02-01 11:14:15,838 TRACE [c.c.u.d.T.Connection] (AgentConnectTaskPool-1:ctx-370d8502) Closing DB connection: dbconn78420063
2016-02-01 11:14:15,839 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-1:ctx-370d8502) Failed to handle host connection: com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@5f47875e: 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'cstest-virtual-machine', 'Creating', 'Routing', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'255.255.252.0', _binary'255.255.252.0', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'10.25.1.89', 2, _binary'255.255.252.0', _binary'00:50:56:b3:1f:88', null, null, null, 'KVM', null, null, null, 1, 0, 'Creating', null, 0, _binary'ffc9fd4c-4778-427d-95ba-e17293bb145e', 2, 2, 1, 1, null, 2393, -32403456, null, _binary'6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource', _binary'hvm,snapshot', null, 1420267632, 20696084691758, 0, _binary'4.6.2', '2016-02-01 19:14:15')
2016-02-01 11:14:15,850 TRACE [c.c.u.n.Link] (AgentConnectTaskPool-1:ctx-370d8502) Sending packet of length 1837


Agent Logs :
2016-02-01 11:14:14,930 INFO  [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) Trying to fetch storage pool 654eecc6-a2fd-468f-a725-6d41e9a6b875 from libvirt
2016-02-01 11:14:14,930 DEBUG [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) Looking for libvirtd connection at: qemu:///system
2016-02-01 11:14:14,955 DEBUG [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) Succesfully refreshed pool 654eecc6-a2fd-468f-a725-6d41e9a6b875 Capacity: 210186788864 Used: 5995126784 Available: 204191662080
2016-02-01 11:14:14,959 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Executing: hostname
2016-02-01 11:14:14,961 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Execution is successful.
2016-02-01 11:14:14,961 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Executing: hostname
2016-02-01 11:14:14,962 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Execution is successful.
2016-02-01 11:14:15,116 INFO  [cloud.serializer.GsonHelper] (Agent-Handler-1:null) Default Builder inited.
2016-02-01 11:14:15,203 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Sending Startup: Seq 0-0:  { Cmd , MgmtId: -1, via: 0, Ver: v1, Flags: 1, [{"com.cloud.agent.api.StartupRoutingCommand":{"cpuSockets":1,"cpus":1,"speed":2393,"memory":-32403456,"dom0MinMemory":1073741824,"poolSync":false,"caps":"hvm,snapshot","pool":"/root","hypervisorType":"KVM","hostDetails":{"com.cloud.network.Networks.RouterPrivateIpStrategy":"HostLocal","Host.OS":"Ubuntu","Host.OS.Kernel.Version":"3.19.0-15-generic","Host.OS.Version":"15.04"},"hostTags":[],"groupDetails":{},"type":"Routing","dataCenter":"2","pod":"2","cluster":"2","guid":"6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource","name":"cstest-virtual-machine","id":0,"version":"4.6.2","publicIpAddress":"10.25.1.89","publicNetmask":"255.255.252.0","publicMacAddress":"00:50:56:b3:1f:88","privateIpAddress":"10.25.1.89","privateMacAddress":"00:50:56:b3:1f:88","privateNetmask":"255.255.252.0","storageIpAddress":"10.25.1.89","storageNetmask":"255.255.252.0","storageMacAddress":"00:50:56:b3:1f:88","resourceName":"LibvirtComputingResource","gatewayIpAddress":"10.25.0.1","wait":0}},{"com.cloud.agent.api.StartupStorageCommand":{"totalSize":0,"poolInfo":{"uuid":"654eecc6-a2fd-468f-a725-6d41e9a6b875","host":"10.25.1.89","localPath":"/var/lib/libvirt/images","hostPath":"/var/lib/libvirt/images","poolType":"Filesystem","capacityBytes":210186788864,"availableBytes":204191662080},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"2","pod":"2","guid":"6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource","name":"cstest-virtual-machine","id":0,"version":"4.6.2","resourceName":"LibvirtComputingResource","wait":0}}] }
2016-02-01 11:14:15,203 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Startup task created
2016-02-01 11:14:15,396 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Received response: Seq 0-0:  { Ans: , MgmtId: 20696084691758, via: -1, Ver: v1, Flags: 100000, [{"com.cloud.agent.api.StartupAnswer":{"hostId":0,"pingInterval":60,"result":true,"wait":0}}] }
2016-02-01 11:14:15,397 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Startup task cancelled
2016-02-01 11:14:15,397 INFO  [cloud.agent.Agent] (Agent-Handler-2:null) Proccess agent startup answer, agent id = 0
2016-02-01 11:14:15,397 INFO  [cloud.agent.Agent] (Agent-Handler-2:null) Set agent id 0
2016-02-01 11:14:15,422 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Adding a watch list
2016-02-01 11:14:15,423 INFO  [cloud.agent.Agent] (Agent-Handler-2:null) Startup Response Received: agent id = 0
2016-02-01 11:14:15,423 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-1:null) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms
2016-02-01 11:14:16,024 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Request:Seq -1--1:  { Cmd , MgmtId: -1, via: -1, Ver: v1, Flags: 111, [{"com.cloud.agent.api.ReadyCommand":{"_details":"com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@5f47875e: 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'cstest-virtual-machine', 'Creating', 'Routing', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'255.255.252.0', _binary'255.255.252.0', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'10.25.1.89', 2, _binary'255.255.252.0', _binary'00:50:56:b3:1f:88', null, null, null, 'KVM', null, null, null, 1, 0, 'Creating', null, 0, _binary'ffc9fd4c-4778-427d-95ba-e17293bb145e', 2, 2, 1, 1, null, 2393, -32403456, null, _binary'6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource', _binary'hvm,snapshot', null, 1420267632, 20696084691758, 0, _binary'4.6.2', '2016-02-01 19:14:15')","wait":0}}] }
2016-02-01 11:14:16,028 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Processing command: com.cloud.agent.api.ReadyCommand
2016-02-01 11:14:16,028 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Not ready to connect to mgt server: com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@5f47875e: 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'cstest-virtual-machine', 'Creating', 'Routing', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'255.255.252.0', _binary'255.255.252.0', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'10.25.1.89', 2, _binary'255.255.252.0', _binary'00:50:56:b3:1f:88', null, null, null, 'KVM', null, null, null, 1, 0, 'Creating', null, 0, _binary'ffc9fd4c-4778-427d-95ba-e17293bb145e', 2, 2, 1, 1, null, 2393, -32403456, null, _binary'6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource', _binary'hvm,snapshot', null, 1420267632, 20696084691758, 0, _binary'4.6.2', '2016-02-01 19:14:15')
2016-02-01 11:14:16,030 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-1:null) Execution is successful.
2016-02-01 11:14:16,036 DEBUG [kvm.resource.LibvirtConnection] (UgentTask-1:null) Looking for libvirtd connection at: qemu:///system
2016-02-01 11:14:16,039 DEBUG [cloud.agent.Agent] (UgentTask-1:null) Sending ping: 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-02-01 11:14:16,042 INFO  [cloud.agent.Agent] (AgentShutdownThread:null) Stopping the agent: Reason = sig.kill
2016-02-01 11:14:16,043 DEBUG [cloud.agent.Agent] (AgentShutdownThread:null) Sending shutdown to management server


Any pointers or help would be much appreciated.

Thanks,
Keyur Bhalerao

DISCLAIMER
==========
This e-mail may contain privileged and confidential information which is the property of Persistent Systems Ltd. It is intended only for the use of the individual or entity to which it is addressed. If you are not the intended recipient, you are not authorized to read, retain, copy, print, distribute or use this message. If you have received this communication in error, please notify the sender and delete all copies of this message. Persistent Systems Ltd. does not accept any liability for virus infected mails.


RE: DB Exception while adding Host on Cloud stack 4.6 fresh installation (Ubuntu 15.04)

Posted by Glenn Wagner <gl...@shapeblue.com>.
Hi,

How you tried to mount the NFS share manually on the KVM host to see if it works

Regards
Glenn



[ShapeBlue]<http://www.shapeblue.com>
Glenn Wagner
Senior Consultant       ,       ShapeBlue


d:       | s: +27 21 527 0091<tel:|%20s:%20+27%2021%20527%200091>        |      m:      +27 73 917 4111<tel:+27%2073%20917%204111>

e:      glenn.wagner@shapeblue.com | t: <mailto:glenn.wagner@shapeblue.com%20|%20t:>     |      w:      www.shapeblue.com<http://www.shapeblue.com>

a:      2nd Floor, Oudehuis Centre, 122 Main Rd, Somerset West Cape Town 7130 South Africa


[cid:imagee236c1.png@e2ce0923.4981560a]


Shape Blue Ltd is a company incorporated in England & Wales. ShapeBlue Services India LLP is a company incorporated in India and is operated under license from Shape Blue Ltd. Shape Blue Brasil Consultoria Ltda is a company incorporated in Brasil and is operated under license from Shape Blue Ltd. ShapeBlue SA Pty Ltd is a company registered by The Republic of South Africa and is traded under license from Shape Blue Ltd. ShapeBlue is a registered trademark.
This email and any attachments to it may be confidential and are intended solely for the use of the individual to whom it is addressed. Any views or opinions expressed are solely those of the author and do not necessarily represent those of Shape Blue Ltd or related companies. If you are not the intended recipient of this email, you must neither take any action based upon its contents, nor copy or show it to anyone. Please contact the sender if you believe you have received this email in error.




-----Original Message-----
From: Keyur Bhalerao [mailto:keyur_bhalerao@persistent.com]
Sent: Monday, 01 February 2016 9:40 PM
To: users@cloudstack.apache.org
Subject: DB Exception while adding Host on Cloud stack 4.6 fresh installation (Ubuntu 15.04)

Hi ,

I have installed Cloud stack version 4.6 to be more precise - {"listcapabilitiesresponse":{"capability":{"securitygroupsenabled":false,"cloudstackversion":"4.6.2","userpublictemplateenabled":true,"supportELB":"false","projectinviterequired":false,"allowusercreateprojects":true,"customdiskofferingminsize":1,"customdiskofferingmaxsize":1024,"regionsecondaryenabled":false,"kvmsnapshotenabled":false,"allowuserviewdestroyedvm":true,"allowuserexpungerecovervm":true}}}

On Ubuntu 15.04 with following KVM details -

Compiled against library: libvirt 1.2.12 Using library: libvirt 1.2.12 Using API: QEMU 1.2.12 Running hypervisor: QEMU 2.2.0

It's a single VM installation where storage and management server are on same VM . I have followed all the required steps from the documentation provided in - http://www.shapeblue.com/deploying-cloudstack-with-kvm/
I am able to successfully login management console and create ZONE , POD , CLUSTER successfully. Its failing while adding the host . Here are the log details (Log level changed to TRACE). Cloud stack- Agent dies after we try to add host from the console. It says active (exited)

Management Logs :

2016-02-01 11:14:15,761 TRACE [c.c.u.d.T.Connection] (AgentConnectTaskPool-1:ctx-370d8502) Creating a DB connection with txn: for 0: dbconn78420063. Stack: -TransactionLegacy.prepareAutoCloseStatement:477-GenericDaoBase.persist:1368-HostDaoImpl.persist:797-HostDaoImpl.persist:69-NativeMethodAccessorImpl.invoke0:-2-NativeMethodAccessorImpl.invoke:57-DelegatingMethodAccessorImpl.invoke:43-Method.invoke:606-AopUtils.invokeJoinpointUsingReflection:317-ReflectiveMethodInvocation.invokeJoinpoint:183-ReflectiveMethodInvocation.proceed:150-TransactionContextInterceptor.invoke:34
2016-02-01 11:14:15,769 TRACE [c.c.u.d.T.Statement] (AgentConnectTaskPool-1:ctx-370d8502) Preparing: 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 (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2016-02-01 11:14:15,837 TRACE [c.c.u.d.T.Statement] (AgentConnectTaskPool-1:ctx-370d8502) Closing: com.mysql.jdbc.JDBC4PreparedStatement@5f47875e: 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'cstest-virtual-machine', 'Creating', 'Routing', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'255.255.252.0', _binary'255.255.252.0', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'10.25.1.89', 2, _binary'255.255.252.0', _binary'00:50:56:b3:1f:88', null, null, null, 'KVM', null, null, null, 1, 0, 'Creating', null, 0, _binary'ffc9fd4c-4778-427d-95ba-e17293bb145e', 2, 2, 1, 1, null, 2393, -32403456, null, _binary'6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource', _binary'hvm,snapshot', null, 1420267632, 20696084691758, 0, _binary'4.6.2', '2016-02-01 19:14:15')
2016-02-01 11:14:15,837 TRACE [c.c.u.d.T.Connection] (AgentConnectTaskPool-1:ctx-370d8502) txn: Not closing DB connection because we're still in a transaction.
2016-02-01 11:14:15,837 DEBUG [c.c.u.d.T.Transaction] (AgentConnectTaskPool-1:ctx-370d8502) Rolling back the transaction: Time = 77 Name = AgentConnectTaskPool-1; 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-$Proxy59.persist:-1-ResourceManagerImpl.createHostVO:1701-ResourceManagerImpl.createHostVOForConnectedAgent:1952-NativeMethodAccessorImpl.invoke0:-2
2016-02-01 11:14:15,838 TRACE [c.c.u.d.T.Connection] (AgentConnectTaskPool-1:ctx-370d8502) Closing DB connection: dbconn78420063
2016-02-01 11:14:15,839 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-1:ctx-370d8502) Failed to handle host connection: com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@5f47875e: 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'cstest-virtual-machine', 'Creating', 'Routing', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'255.255.252.0', _binary'255.255.252.0', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'10.25.1.89', 2, _binary'255.255.252.0', _binary'00:50:56:b3:1f:88', null, null, null, 'KVM', null, null, null, 1, 0, 'Creating', null, 0, _binary'ffc9fd4c-4778-427d-95ba-e17293bb145e', 2, 2, 1, 1, null, 2393, -32403456, null, _binary'6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource', _binary'hvm,snapshot', null, 1420267632, 20696084691758, 0, _binary'4.6.2', '2016-02-01 19:14:15')
2016-02-01 11:14:15,850 TRACE [c.c.u.n.Link] (AgentConnectTaskPool-1:ctx-370d8502) Sending packet of length 1837


Agent Logs :
2016-02-01 11:14:14,930 INFO [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) Trying to fetch storage pool 654eecc6-a2fd-468f-a725-6d41e9a6b875 from libvirt
2016-02-01 11:14:14,930 DEBUG [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) Looking for libvirtd connection at: qemu:///system
2016-02-01 11:14:14,955 DEBUG [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) Succesfully refreshed pool 654eecc6-a2fd-468f-a725-6d41e9a6b875 Capacity: 210186788864 Used: 5995126784 Available: 204191662080
2016-02-01 11:14:14,959 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Executing: hostname
2016-02-01 11:14:14,961 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Execution is successful.
2016-02-01 11:14:14,961 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Executing: hostname
2016-02-01 11:14:14,962 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Execution is successful.
2016-02-01 11:14:15,116 INFO [cloud.serializer.GsonHelper] (Agent-Handler-1:null) Default Builder inited.
2016-02-01 11:14:15,203 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Sending Startup: Seq 0-0: { Cmd , MgmtId: -1, via: 0, Ver: v1, Flags: 1, [{"com.cloud.agent.api.StartupRoutingCommand":{"cpuSockets":1,"cpus":1,"speed":2393,"memory":-32403456,"dom0MinMemory":1073741824,"poolSync":false,"caps":"hvm,snapshot","pool":"/root","hypervisorType":"KVM","hostDetails":{"com.cloud.network.Networks.RouterPrivateIpStrategy":"HostLocal","Host.OS":"Ubuntu","Host.OS.Kernel.Version":"3.19.0-15-generic","Host.OS.Version":"15.04"},"hostTags":[],"groupDetails":{},"type":"Routing","dataCenter":"2","pod":"2","cluster":"2","guid":"6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource","name":"cstest-virtual-machine","id":0,"version":"4.6.2","publicIpAddress":"10.25.1.89","publicNetmask":"255.255.252.0","publicMacAddress":"00:50:56:b3:1f:88","privateIpAddress":"10.25.1.89","privateMacAddress":"00:50:56:b3:1f:88","privateNetmask":"255.255.252.0","storageIpAddress":"10.25.1.89","storageNetmask":"255.255.252.0","storageMacAddress":"00:50:56:b3:1f:88","resourceName":"LibvirtComputingResource","gatewayIpAddress":"10.25.0.1","wait":0}},{"com.cloud.agent.api.StartupStorageCommand":{"totalSize":0,"poolInfo":{"uuid":"654eecc6-a2fd-468f-a725-6d41e9a6b875","host":"10.25.1.89","localPath":"/var/lib/libvirt/images","hostPath":"/var/lib/libvirt/images","poolType":"Filesystem","capacityBytes":210186788864,"availableBytes":204191662080},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"2","pod":"2","guid":"6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource","name":"cstest-virtual-machine","id":0,"version":"4.6.2","resourceName":"LibvirtComputingResource","wait":0}}] }
2016-02-01 11:14:15,203 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Startup task created
2016-02-01 11:14:15,396 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Received response: Seq 0-0: { Ans: , MgmtId: 20696084691758, via: -1, Ver: v1, Flags: 100000, [{"com.cloud.agent.api.StartupAnswer":{"hostId":0,"pingInterval":60,"result":true,"wait":0}}] }
2016-02-01 11:14:15,397 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Startup task cancelled
2016-02-01 11:14:15,397 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Proccess agent startup answer, agent id = 0
2016-02-01 11:14:15,397 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Set agent id 0
2016-02-01 11:14:15,422 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Adding a watch list
2016-02-01 11:14:15,423 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Startup Response Received: agent id = 0
2016-02-01 11:14:15,423 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-1:null) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms
2016-02-01 11:14:16,024 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Request:Seq -1--1: { Cmd , MgmtId: -1, via: -1, Ver: v1, Flags: 111, [{"com.cloud.agent.api.ReadyCommand":{"_details":"com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@5f47875e: 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'cstest-virtual-machine', 'Creating', 'Routing', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'255.255.252.0', _binary'255.255.252.0', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'10.25.1.89', 2, _binary'255.255.252.0', _binary'00:50:56:b3:1f:88', null, null, null, 'KVM', null, null, null, 1, 0, 'Creating', null, 0, _binary'ffc9fd4c-4778-427d-95ba-e17293bb145e', 2, 2, 1, 1, null, 2393, -32403456, null, _binary'6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource', _binary'hvm,snapshot', null, 1420267632, 20696084691758, 0, _binary'4.6.2', '2016-02-01 19:14:15')","wait":0}}] }
2016-02-01 11:14:16,028 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Processing command: com.cloud.agent.api.ReadyCommand
2016-02-01 11:14:16,028 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Not ready to connect to mgt server: com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@5f47875e: 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'cstest-virtual-machine', 'Creating', 'Routing', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'255.255.252.0', _binary'255.255.252.0', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'10.25.1.89', 2, _binary'255.255.252.0', _binary'00:50:56:b3:1f:88', null, null, null, 'KVM', null, null, null, 1, 0, 'Creating', null, 0, _binary'ffc9fd4c-4778-427d-95ba-e17293bb145e', 2, 2, 1, 1, null, 2393, -32403456, null, _binary'6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource', _binary'hvm,snapshot', null, 1420267632, 20696084691758, 0, _binary'4.6.2', '2016-02-01 19:14:15')
2016-02-01 11:14:16,030 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-1:null) Execution is successful.
2016-02-01 11:14:16,036 DEBUG [kvm.resource.LibvirtConnection] (UgentTask-1:null) Looking for libvirtd connection at: qemu:///system
2016-02-01 11:14:16,039 DEBUG [cloud.agent.Agent] (UgentTask-1:null) Sending ping: 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-02-01 11:14:16,042 INFO [cloud.agent.Agent] (AgentShutdownThread:null) Stopping the agent: Reason = sig.kill
2016-02-01 11:14:16,043 DEBUG [cloud.agent.Agent] (AgentShutdownThread:null) Sending shutdown to management server


Any pointers or help would be much appreciated.

Thanks,
Keyur Bhalerao

DISCLAIMER
==========
This e-mail may contain privileged and confidential information which is the property of Persistent Systems Ltd. It is intended only for the use of the individual or entity to which it is addressed. If you are not the intended recipient, you are not authorized to read, retain, copy, print, distribute or use this message. If you have received this communication in error, please notify the sender and delete all copies of this message. Persistent Systems Ltd. does not accept any liability for virus infected mails.

Find out more about ShapeBlue and our range of CloudStack related services:
IaaS Cloud Design & Build<http://shapeblue.com/iaas-cloud-design-and-build//> | CSForge – rapid IaaS deployment framework<http://shapeblue.com/csforge/>
CloudStack Consulting<http://shapeblue.com/cloudstack-consultancy/> | CloudStack Software Engineering<http://shapeblue.com/cloudstack-software-engineering/>
CloudStack Infrastructure Support<http://shapeblue.com/cloudstack-infrastructure-support/> | CloudStack Bootcamp Training Courses<http://shapeblue.com/cloudstack-training/>

RE: DB Exception while adding Host on Cloud stack 4.6 fresh installation (Ubuntu 15.04)

Posted by Keyur Bhalerao <ke...@persistent.com>.
Some things which are observed in the log while troubleshooting this issue - 

1. There some errors found in cloudstack-agent in setup.log

Feb 01 15:42:50 cstest-virtual-machine sudo[2772]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/grep InitiatorName= /etc/iscsi/initiatorname.iscsi
Feb 01 15:42:50 cstest-virtual-machine sudo[2772]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 01 15:42:50 cstest-virtual-machine sudo[2772]: pam_unix(sudo:session): session closed for user root
Feb 01 15:42:52 cstest-virtual-machine jsvc.exec[1348]: libvirt: Storage Driver error : Storage pool not found: no storage pool with matching uuid '654eecc6-a2fd-468f-a725-6d41e9a6b875'
Feb 01 15:42:52 cstest-virtual-machine jsvc.exec[1348]: 2016-02-01 15:42:52 1341 jsvc.exec error: Service exit with a return value of 1
Feb 01 15:43:00 cstest-virtual-machine systemd[1]: Stopping LSB: Start/stop Apache CloudStack Agent...
Feb 01 15:43:00 cstest-virtual-machine cloudstack-agent[2809]: * Stopping CloudStack Agent cloudstack-agent
Feb 01 15:43:00 cstest-virtual-machine cloudstack-agent[2809]: ...done.
Feb 01 15:43:00 cstest-virtual-machine systemd[1]: Stopped LSB: Start/stop Apache CloudStack Agent.
Feb 01 15:46:07 cstest-virtual-machine systemd[1]: Stopped LSB: Start/stop Apache CloudStack Agent.


2. Tried to create storage pool and it's also giving following error - 

2016-02-01 15:48:42,329 DEBUG [o.s.b.f.a.AutowiredAnnotationBeanPostProcessor] (catalina-exec-18:ctx-57983598 ctx-9c5f1bc3) Autowiring by type from bean name 'org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl' to bean named 'volumeDaoImpl'
2016-02-01 15:48:42,331 DEBUG [o.a.c.s.d.l.CloudStackPrimaryDataStoreLifeCycleImpl] (catalina-exec-18:ctx-57983598 ctx-9c5f1bc3) In createPool. Attaching the pool to each of the hosts.
2016-02-01 15:48:42,331 WARN  [o.a.c.s.d.l.CloudStackPrimaryDataStoreLifeCycleImpl] (catalina-exec-18:ctx-57983598 ctx-9c5f1bc3) No host can access storage pool org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@117bf3f8 in this zone.
2016-02-01 15:48:42,389 DEBUG [c.c.s.StorageManagerImpl] (catalina-exec-18:ctx-57983598 ctx-9c5f1bc3) Failed to add data store: Failed to create storage pool as it is not accessible to hosts.
com.cloud.utils.exception.CloudRuntimeException: Failed to create storage pool as it is not accessible to hosts.
        at org.apache.cloudstack.storage.datastore.lifecycle.CloudStackPrimaryDataStoreLifeCycleImpl.attachZone(CloudStackPrimaryDataStoreLifeCycleImpl.java:453)
        at com.cloud.storage.StorageManagerImpl.createPool(StorageManagerImpl.java:705)
        at com.cloud.storage.StorageManagerImpl.createPool(StorageManagerImpl.java:193)
        at org.apache.cloudstack.api.command.admin.storage.CreateStoragePoolCmd.execute(CreateStoragePoolCmd.java:163)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:150)
        at com.cloud.api.ApiServer.queueCommand(ApiServer.java:703)
        at com.cloud.api.ApiServer.handleRequest(ApiServer.java:528)
        at com.cloud.api.ApiServlet.processRequestInContext(ApiServlet.java:296)
        at com.cloud.api.ApiServlet$1.run(ApiServlet.java:127)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
        at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
        at com.cloud.api.ApiServlet.processRequest(ApiServlet.java:124)
        at com.cloud.api.ApiServlet.doGet(ApiServlet.java:86)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:723)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:615)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
        at org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java:891)
        at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:750)
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:2283)
        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)
2016-02-01 15:48:42,395 DEBUG [c.c.s.StorageManagerImpl] (catalina-exec-18:ctx-57983598 ctx-9c5f1bc3) Failed to clean up storage pool: null
2016-02-01 15:48:42,395 INFO  [c.c.a.ApiServer] (catalina-exec-18:ctx-57983598 ctx-9c5f1bc3) Failed to add data store: Failed to create storage pool as it is not accessible to hosts.

I have cross checked the storage from libvirt and its active. 

root@cstest-virtual-machine:/var/log/cloudstack/agent# virsh
Welcome to virsh, the virtualization interactive terminal.

Type:  'help' for help with commands
       'quit' to quit

virsh # pool-list
 Name                 State      Autostart
-------------------------------------------
 654eecc6-a2fd-468f-a725-6d41e9a6b875 active     no

virsh # exit

Thanks,
Keyur Bhalerao
-----Original Message-----
From: Keyur Bhalerao [mailto:keyur_bhalerao@persistent.com] 
Sent: Monday, February 01, 2016 11:40 AM
To: users@cloudstack.apache.org
Subject: DB Exception while adding Host on Cloud stack 4.6 fresh installation (Ubuntu 15.04)

Hi ,

I have installed Cloud stack version 4.6 to be more precise  - {"listcapabilitiesresponse":{"capability":{"securitygroupsenabled":false,"cloudstackversion":"4.6.2","userpublictemplateenabled":true,"supportELB":"false","projectinviterequired":false,"allowusercreateprojects":true,"customdiskofferingminsize":1,"customdiskofferingmaxsize":1024,"regionsecondaryenabled":false,"kvmsnapshotenabled":false,"allowuserviewdestroyedvm":true,"allowuserexpungerecovervm":true}}}

On Ubuntu 15.04 with following KVM details -

Compiled against library: libvirt 1.2.12 Using library: libvirt 1.2.12 Using API: QEMU 1.2.12 Running hypervisor: QEMU 2.2.0

It's a single VM installation where storage and management server are on same VM . I have followed all the required steps from the documentation provided in - http://www.shapeblue.com/deploying-cloudstack-with-kvm/
I am able to successfully login management console and create ZONE , POD , CLUSTER successfully. Its failing while adding the host . Here are the log details (Log level changed to TRACE). Cloud stack- Agent dies after we try to add host from the console. It says active (exited)

Management Logs :

2016-02-01 11:14:15,761 TRACE [c.c.u.d.T.Connection] (AgentConnectTaskPool-1:ctx-370d8502) Creating a DB connection with  txn:  for 0: dbconn78420063. Stack: -TransactionLegacy.prepareAutoCloseStatement:477-GenericDaoBase.persist:1368-HostDaoImpl.persist:797-HostDaoImpl.persist:69-NativeMethodAccessorImpl.invoke0:-2-NativeMethodAccessorImpl.invoke:57-DelegatingMethodAccessorImpl.invoke:43-Method.invoke:606-AopUtils.invokeJoinpointUsingReflection:317-ReflectiveMethodInvocation.invokeJoinpoint:183-ReflectiveMethodInvocation.proceed:150-TransactionContextInterceptor.invoke:34
2016-02-01 11:14:15,769 TRACE [c.c.u.d.T.Statement] (AgentConnectTaskPool-1:ctx-370d8502) Preparing: 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 (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2016-02-01 11:14:15,837 TRACE [c.c.u.d.T.Statement] (AgentConnectTaskPool-1:ctx-370d8502) Closing: com.mysql.jdbc.JDBC4PreparedStatement@5f47875e: 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'cstest-virtual-machine', 'Creating', 'Routing', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'255.255.252.0', _binary'255.255.252.0', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'10.25.1.89', 2, _binary'255.255.252.0', _binary'00:50:56:b3:1f:88', null, null, null, 'KVM', null, null, null, 1, 0, 'Creating', null, 0, _binary'ffc9fd4c-4778-427d-95ba-e17293bb145e', 2, 2, 1, 1, null, 2393, -32403456, null, _binary'6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource', _binary'hvm,snapshot', null, 1420267632, 20696084691758, 0, _binary'4.6.2', '2016-02-01 19:14:15')
2016-02-01 11:14:15,837 TRACE [c.c.u.d.T.Connection] (AgentConnectTaskPool-1:ctx-370d8502) txn: Not closing DB connection because we're still in a transaction.
2016-02-01 11:14:15,837 DEBUG [c.c.u.d.T.Transaction] (AgentConnectTaskPool-1:ctx-370d8502) Rolling back the transaction: Time = 77 Name =  AgentConnectTaskPool-1; 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-$Proxy59.persist:-1-ResourceManagerImpl.createHostVO:1701-ResourceManagerImpl.createHostVOForConnectedAgent:1952-NativeMethodAccessorImpl.invoke0:-2
2016-02-01 11:14:15,838 TRACE [c.c.u.d.T.Connection] (AgentConnectTaskPool-1:ctx-370d8502) Closing DB connection: dbconn78420063
2016-02-01 11:14:15,839 DEBUG [c.c.a.m.AgentManagerImpl] (AgentConnectTaskPool-1:ctx-370d8502) Failed to handle host connection: com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@5f47875e: 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'cstest-virtual-machine', 'Creating', 'Routing', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'255.255.252.0', _binary'255.255.252.0', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'10.25.1.89', 2, _binary'255.255.252.0', _binary'00:50:56:b3:1f:88', null, null, null, 'KVM', null, null, null, 1, 0, 'Creating', null, 0, _binary'ffc9fd4c-4778-427d-95ba-e17293bb145e', 2, 2, 1, 1, null, 2393, -32403456, null, _binary'6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource', _binary'hvm,snapshot', null, 1420267632, 20696084691758, 0, _binary'4.6.2', '2016-02-01 19:14:15')
2016-02-01 11:14:15,850 TRACE [c.c.u.n.Link] (AgentConnectTaskPool-1:ctx-370d8502) Sending packet of length 1837


Agent Logs :
2016-02-01 11:14:14,930 INFO  [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) Trying to fetch storage pool 654eecc6-a2fd-468f-a725-6d41e9a6b875 from libvirt
2016-02-01 11:14:14,930 DEBUG [kvm.resource.LibvirtConnection] (Agent-Handler-1:null) Looking for libvirtd connection at: qemu:///system
2016-02-01 11:14:14,955 DEBUG [kvm.storage.LibvirtStorageAdaptor] (Agent-Handler-1:null) Succesfully refreshed pool 654eecc6-a2fd-468f-a725-6d41e9a6b875 Capacity: 210186788864 Used: 5995126784 Available: 204191662080
2016-02-01 11:14:14,959 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Executing: hostname
2016-02-01 11:14:14,961 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Execution is successful.
2016-02-01 11:14:14,961 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Executing: hostname
2016-02-01 11:14:14,962 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Execution is successful.
2016-02-01 11:14:15,116 INFO  [cloud.serializer.GsonHelper] (Agent-Handler-1:null) Default Builder inited.
2016-02-01 11:14:15,203 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Sending Startup: Seq 0-0:  { Cmd , MgmtId: -1, via: 0, Ver: v1, Flags: 1, [{"com.cloud.agent.api.StartupRoutingCommand":{"cpuSockets":1,"cpus":1,"speed":2393,"memory":-32403456,"dom0MinMemory":1073741824,"poolSync":false,"caps":"hvm,snapshot","pool":"/root","hypervisorType":"KVM","hostDetails":{"com.cloud.network.Networks.RouterPrivateIpStrategy":"HostLocal","Host.OS":"Ubuntu","Host.OS.Kernel.Version":"3.19.0-15-generic","Host.OS.Version":"15.04"},"hostTags":[],"groupDetails":{},"type":"Routing","dataCenter":"2","pod":"2","cluster":"2","guid":"6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource","name":"cstest-virtual-machine","id":0,"version":"4.6.2","publicIpAddress":"10.25.1.89","publicNetmask":"255.255.252.0","publicMacAddress":"00:50:56:b3:1f:88","privateIpAddress":"10.25.1.89","privateMacAddress":"00:50:56:b3:1f:88","privateNetmask":"255.255.252.0","storageIpAddress":"10.25.1.89","storageNetmask":"255.255.252.0","storageMacAddress":"00:50:56:b3:1f:88","resourceName":"LibvirtComputingResource","gatewayIpAddress":"10.25.0.1","wait":0}},{"com.cloud.agent.api.StartupStorageCommand":{"totalSize":0,"poolInfo":{"uuid":"654eecc6-a2fd-468f-a725-6d41e9a6b875","host":"10.25.1.89","localPath":"/var/lib/libvirt/images","hostPath":"/var/lib/libvirt/images","poolType":"Filesystem","capacityBytes":210186788864,"availableBytes":204191662080},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"2","pod":"2","guid":"6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource","name":"cstest-virtual-machine","id":0,"version":"4.6.2","resourceName":"LibvirtComputingResource","wait":0}}] }
2016-02-01 11:14:15,203 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Startup task created
2016-02-01 11:14:15,396 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Received response: Seq 0-0:  { Ans: , MgmtId: 20696084691758, via: -1, Ver: v1, Flags: 100000, [{"com.cloud.agent.api.StartupAnswer":{"hostId":0,"pingInterval":60,"result":true,"wait":0}}] }
2016-02-01 11:14:15,397 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Startup task cancelled
2016-02-01 11:14:15,397 INFO  [cloud.agent.Agent] (Agent-Handler-2:null) Proccess agent startup answer, agent id = 0
2016-02-01 11:14:15,397 INFO  [cloud.agent.Agent] (Agent-Handler-2:null) Set agent id 0
2016-02-01 11:14:15,422 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Adding a watch list
2016-02-01 11:14:15,423 INFO  [cloud.agent.Agent] (Agent-Handler-2:null) Startup Response Received: agent id = 0
2016-02-01 11:14:15,423 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-1:null) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms
2016-02-01 11:14:16,024 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Request:Seq -1--1:  { Cmd , MgmtId: -1, via: -1, Ver: v1, Flags: 111, [{"com.cloud.agent.api.ReadyCommand":{"_details":"com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@5f47875e: 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'cstest-virtual-machine', 'Creating', 'Routing', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'255.255.252.0', _binary'255.255.252.0', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'10.25.1.89', 2, _binary'255.255.252.0', _binary'00:50:56:b3:1f:88', null, null, null, 'KVM', null, null, null, 1, 0, 'Creating', null, 0, _binary'ffc9fd4c-4778-427d-95ba-e17293bb145e', 2, 2, 1, 1, null, 2393, -32403456, null, _binary'6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource', _binary'hvm,snapshot', null, 1420267632, 20696084691758, 0, _binary'4.6.2', '2016-02-01 19:14:15')","wait":0}}] }
2016-02-01 11:14:16,028 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Processing command: com.cloud.agent.api.ReadyCommand
2016-02-01 11:14:16,028 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Not ready to connect to mgt server: com.cloud.utils.exception.CloudRuntimeException: DB Exception on: com.mysql.jdbc.JDBC4PreparedStatement@5f47875e: 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'cstest-virtual-machine', 'Creating', 'Routing', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'255.255.252.0', _binary'255.255.252.0', _binary'10.25.1.89', _binary'00:50:56:b3:1f:88', _binary'10.25.1.89', 2, _binary'255.255.252.0', _binary'00:50:56:b3:1f:88', null, null, null, 'KVM', null, null, null, 1, 0, 'Creating', null, 0, _binary'ffc9fd4c-4778-427d-95ba-e17293bb145e', 2, 2, 1, 1, null, 2393, -32403456, null, _binary'6f373eb2-fb89-31bf-85d7-ace20f4e5471-LibvirtComputingResource', _binary'hvm,snapshot', null, 1420267632, 20696084691758, 0, _binary'4.6.2', '2016-02-01 19:14:15')
2016-02-01 11:14:16,030 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-1:null) Execution is successful.
2016-02-01 11:14:16,036 DEBUG [kvm.resource.LibvirtConnection] (UgentTask-1:null) Looking for libvirtd connection at: qemu:///system
2016-02-01 11:14:16,039 DEBUG [cloud.agent.Agent] (UgentTask-1:null) Sending ping: 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-02-01 11:14:16,042 INFO  [cloud.agent.Agent] (AgentShutdownThread:null) Stopping the agent: Reason = sig.kill
2016-02-01 11:14:16,043 DEBUG [cloud.agent.Agent] (AgentShutdownThread:null) Sending shutdown to management server


Any pointers or help would be much appreciated.

Thanks,
Keyur Bhalerao

DISCLAIMER
==========
This e-mail may contain privileged and confidential information which is the property of Persistent Systems Ltd. It is intended only for the use of the individual or entity to which it is addressed. If you are not the intended recipient, you are not authorized to read, retain, copy, print, distribute or use this message. If you have received this communication in error, please notify the sender and delete all copies of this message. Persistent Systems Ltd. does not accept any liability for virus infected mails.


DISCLAIMER
==========
This e-mail may contain privileged and confidential information which is the property of Persistent Systems Ltd. It is intended only for the use of the individual or entity to which it is addressed. If you are not the intended recipient, you are not authorized to read, retain, copy, print, distribute or use this message. If you have received this communication in error, please notify the sender and delete all copies of this message. Persistent Systems Ltd. does not accept any liability for virus infected mails.