Hello Marun, Please find the details about my setup and tests which i have done so far
Setup - One Physical Box with 16c, 256G memory. 2 VMs created on this Box - One for Controller and One for Network Node - 16x compute nodes (each has 16c, 256G memory) - All the systems are installed with Ubuntu Precise + Havana Bits from Ubuntu Cloud Archive Steps to simulate the issue 1) Concurrently create 30 Instances (m1.small) using REST API with mincount=30 2) sleep for 20min and repeat the step (1) Issue 1 In Havana, once we cross 150 instances (5 batches x 30) during 6th batch some instances are going into ERROR state due to network port not able to create and some instances are getting duplicate IP address Per Maru Newby this issue might related to this bug https://bugs.launchpad.net/bugs/1192381 I have done the similar with Grizzly on the same environment 2 months back, where I could able to deploy close to 240 instances without any errors Initially on Grizzly also seen the same behavior but with these tunings based on this bug https://bugs.launchpad.net/neutron/+bug/1160442, never had issues (tested more than 10 times) sqlalchemy_pool_size = 60 sqlalchemy_max_overflow = 120 sqlalchemy_pool_timeout = 2 agent_down_time = 60 report_internval = 20 In Havana, I have tuned the same tunables but I could never get past 150+ instances. Without the tunables I could not able to get past 100 instances. We are getting many timeout errors from the DHCP agent and neutron clients NOTE: After tuning the agent_down_time to 60 and report_interval to 20, we no longer getting these error messages 2013-12-02 11:44:43.421 28201 WARNING neutron.scheduler.dhcp_agent_scheduler [-] No more DHCP agents 2013-12-02 11:44:43.439 28201 WARNING neutron.scheduler.dhcp_agent_scheduler [-] No more DHCP agents 2013-12-02 11:44:43.452 28201 WARNING neutron.scheduler.dhcp_agent_scheduler [-] No more DHCP agents In the compute node openvswitch agent logs, we see these errors repeating continuously 2013-12-04 06:46:02.081 3546 TRACE neutron.plugins.openvswitch.agent.ovs_neutron_agent Timeout: Timeout while waiting on RPC response - topic: "q-plugin", RPC method: "security_group_rules_for_devices" info: "<unknown>" and WARNING neutron.openstack.common.rpc.amqp [-] No calling threads waiting for msg_id DHCP agent has below errors 2013-12-02 15:35:19.557 22125 ERROR neutron.agent.dhcp_agent [-] Unable to reload_allocations dhcp. 2013-12-02 15:35:19.557 22125 TRACE neutron.agent.dhcp_agent Timeout: Timeout while waiting on RPC response - topic: "q-plugin", RPC method: "get_dhcp_port" info: "<unknown>" 2013-12-02 15:35:34.266 22125 ERROR neutron.agent.dhcp_agent [-] Unable to sync network state. 2013-12-02 15:35:34.266 22125 TRACE neutron.agent.dhcp_agent Timeout: Timeout while waiting on RPC response - topic: "q-plugin", RPC method: "get_active_networks_info" info: "<unknown>" In Havana, I have merged the code from this patch and set api_workers to 8 (My Controller VM has 8cores/16Hyperthreads) https://review.openstack.org/#/c/37131/ After this patch and starting 8 neutron-server worker threads, during the batch creation of 240 instances with 30 concurrent requests during each batch, 238 instances became active and 2 instances went into error. Interesting these 2 instances which went into error state are from the same compute node. Unlike earlier this time, the errors are due to 'Too Many Connections' to the MySQL database. 2013-12-04 17:07:59.877 21286 AUDIT nova.compute.manager [req-26d64693-d1ef-40f3-8350-659e34d5b1d7 c4d609870d4447c684858216da2f8041 9b073211dd5c4988993341cc955e200b] [instance: c14596fd-13d5-482b-85af-e87077d4ed9b] Terminating instance 2013-12-04 17:08:00.578 21286 ERROR nova.compute.manager [req-26d64693-d1ef-40f3-8350-659e34d5b1d7 c4d609870d4447c684858216da2f8041 9b073211dd5c4988993341cc955e200b] [instance: c14596fd-13d5-482b-85af-e87077d4ed9b] Error: Remote error: OperationalError (OperationalError) (1040, 'Too many connections') None None Need to back port the patch 'https://review.openstack.org/#/c/37131/' to address the Neutron Scaling issues in Havana. Carl already back porting this patch into Havana https://review.openstack.org/#/c/60082/ which is good. Issue 2 Grizzly : During the concurrent instance creation in Grizzly, once we cross 210 instances, during subsequent 30 instance creation some of the instances could not get their IP address during the first boot with in first few min. Instance MAC and IP Address details were updated in the dnsmasq host file but with a delay. Instances are able to get their IP address with a delay eventually. If we reboot the instance using 'nova reboot' instance used to get IP Address. * Amount of delay is depending on number of network ports and delay is in the range of 8seconds to 2min Havana : But in Havana only 81 instances could get the IP during the first boot. Port is getting created and IP address are getting allocated very fast, but by the time port is UP its taking quite lot of time. Once the port is UP, Instances are able to send the DHCP Request and get the IP address. During the network port create and network port update, there are lot of 'security_group_rules_for_devices' messages. OVS Agents in the compute nodes are getting Timeouts during "security_group_rules_for_devices" Even though this issue exist in Grizzly but we observed this issue only after 200+ active instances (200 network ports), but in Havana We are having these issues with less than 100 active ports. In Havana, if we reboot the instance it's not able to get the IP Address even though its network port entry is already exist in dnsmasq hosts file. We can't even ping the IP Address now which we were able to ping before the instance reboot. After restarting the 'neutron-dhcp-agent' service which will restart the 'dnsmasq' and reboot of the instance could get the IP This clear shows we have performance regression in neutron/havana compared to quantum/grizzly FYI, I attached the my notes for one of the instance which could not get IP during first boot with this email I am happy to share the results of my grizzly tests and logs during recent havana tests Thanks & Regards, Sreedhar Nathani
For example - Instance 2ba403d2-71f8-4ee6-a746-2e398bda9404 could not get IP address intime so cloud-init cloud not finish its configuration Instance is created at 2013-12-04 15:23:20 and launched at 2013-12-04 15:23:45 instance id,created at,booted at,boot (seconds) 2ba403d2-71f8-4ee6-a746-2e398bda9404,2013-12-04T15:23:20,??,?? console-log of this instance 2ba403d2-71f8-4ee6-a746-2e398bda9404 [ 0.000000] Initializing cgroup subsys cpuset [ 0.000000] Initializing cgroup subsys cpu [ 0.000000] Linux version 3.2.0-53-virtual (buildd@allspice) (gcc version 4.6.3 (Ubuntu/Linaro 4.6.3-1ubuntu5) ) #81-Ubuntu SMP Thu Aug 22 21:21:26 UTC 2013 (Ubuntu 3.2.0-53.81-virtual 3.2.50) ... cloud-init start-local running: Wed, 04 Dec 2013 15:23:52 +0000. up 1.59 seconds no instance data found in start-local cloud-init-nonet waiting 120 seconds for a network device. cloud-init-nonet gave up waiting for a network device. ci-info: lo : 1 127.0.0.1 255.0.0.0 . ci-info: eth0 : 1 . . fa:16:3e:39:68:82 route_info failed // From the console log, cloud-init waited till Wed, 04 Dec 2013 15:26:02 (cloud-init actually waits for 130 seconds here) but eth0 could get get IP # grep 2ba403d2-71f8-4ee6-a746-2e398bda9404 neutronportlist_frommysql 9b073211dd5c4988993341cc955e200b 92a508d4-d664-47d7-8933-5a9826eabe3b fb4fd94f-9d44-4f22-a347-ffdf8476c148 fa:16:3e:39:68:82 1 ACTIVE2ba403d2-71f8-4ee6-a746-2e398bda9404 compute:None # grep fa:16:3e:39:68:82 neutronportlist_fromcommand | 92a508d4-d664-47d7-8933-5a9826eabe3b | | fa:16:3e:39:68:82 | {"subnet_id": "50918af5-70eb-4cf7-a50e-276334738793", "ip_address": "192.168.32.64"} | // But IP Allocated from DHCP At this time (A delay of close to 7 seconds after instance cloud-init gave up on networking) Dec 4 15:26:09 osnetworknode dnsmasq-dhcp[10597]: DHCPDISCOVER(tap0f63c330-de) fa:16:3e:39:68:82 Dec 4 15:26:09 osnetworknode dnsmasq-dhcp[10597]: DHCPOFFER(tap0f63c330-de) 192.168.32.64 fa:16:3e:39:68:82 Dec 4 15:26:09 osnetworknode dnsmasq-dhcp[10597]: DHCPREQUEST(tap0f63c330-de) 192.168.32.64 fa:16:3e:39:68:82 Dec 4 15:26:09 osnetworknode dnsmasq-dhcp[10597]: DHCPACK(tap0f63c330-de) 192.168.32.64 fa:16:3e:39:68:82 host-192-168-32-64 NOTE: This delay will increased if the number of active ports are high even though instance could not get IP during the first boot, we could ping the IP after some time without doing any changes # ip netns exec qdhcp-fb4fd94f-9d44-4f22-a347-ffdf8476c148 ping 192.168.32.64 PING 192.168.32.64 (192.168.32.64) 56(84) bytes of data. 64 bytes from 192.168.32.64: icmp_req=1 ttl=64 time=3.16 ms 64 bytes from 192.168.32.64: icmp_req=2 ttl=64 time=0.808 ms 64 bytes from 192.168.32.64: icmp_req=3 ttl=64 time=0.651 ms 64 bytes from 192.168.32.64: icmp_req=4 ttl=64 time=0.848 ms 64 bytes from 192.168.32.64: icmp_req=5 ttl=64 time=0.688 ms 64 bytes from 192.168.32.64: icmp_req=6 ttl=64 time=0.824 ms ^C --- 192.168.32.64 ping statistics --- 6 packets transmitted, 6 received, 0% packet loss, time 5001ms rtt min/avg/max/mdev = 0.651/1.164/3.167/0.898 ms Can't connect via SSH since ssh server was not started during the first boot due to unavailabily of network # ip netns exec qdhcp-fb4fd94f-9d44-4f22-a347-ffdf8476c148 ssh 192.168.32.64 Read from socket failed: Connection reset by peer From the server log - port is created and IP allocated at 2013-12-04 15:23:31 but port is UP only at 2013-12-04 15:26:03 (a gap of 152 seconds) 2013-12-04 15:23:31.982 17798 DEBUG neutron.db.db_base_plugin_v2 [-] Allocated IP 192.168.32.64 (fb4fd94f-9d44-4f22-a347-ffdf8476c148/50918af5-70eb-4cf7-a50e-276334738793/92a508d4-d664-47d7-8933-5a9826eabe3b) create_port /usr/lib/python2.7/dist-packages/neutron/db/db_base_plugin_v2.py:1360 2013-12-04 15:25:38.592 17784 DEBUG neutron.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin'], u'_msg_id': u'e18b6849e0bf4ba38350c3e470bb089e', u'_context_read_deleted': u'no', u'_reply_q': u'reply_e9aab6015394494792574c917fb89490', u'_context_tenant_id': None, u'args': {u'devices': [u'0ecc4e80-b071-4695-95ca-4382e9d9e281', u'92a508d4-d664-47d7-8933-5a9826eabe3b']}, u'namespace': None, u'_unique_id': u'8ffdfc64acb241d094ff3f94c18490db', u'_context_is_admin': True, u'version': u'1.1', u'_context_project_id': None, u'_context_timestamp': u'2013-12-04 09:57:50.353613', u'_context_user_id': None, u'method': u'security_group_rules_for_devices'} _safe_log /usr/lib/python2.7/dist-packages/neutron/openstack/common/rpc/common.py:276 2013-12-04 15:25:39.865 17784 DEBUG neutron.plugins.openvswitch.ovs_db_v2 [-] get_port_with_securitygroups() called:port_id=92a508d4-d664-47d7-8933-5a9826eabe3b get_port_from_device /usr/lib/python2.7/dist-packages/neutron/plugins/openvswitch/ovs_db_v2.py:322 2013-12-04 15:25:58.739 17784 DEBUG neutron.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin'], u'_msg_id': u'73f2ecc5f46b4516b3fe3fba58413096', u'_context_read_deleted': u'no', u'_reply_q': u'reply_e9aab6015394494792574c917fb89490', u'_context_tenant_id': None, u'args': {u'devices': [u'5c7ba334-4581-480c-ad91-5b95ff299a82', u'0ecc4e80-b071-4695-95ca-4382e9d9e281', u'92a508d4-d664-47d7-8933-5a9826eabe3b', u'26a5efd1-0855-40c7-8730-f1098518055d', u'2eb1f35e-873a-460a-806b-700cc1969289']}, u'namespace': None, u'_unique_id': u'a7755a2207b84379941aaa68f0258384', u'_context_is_admin': True, u'version': u'1.1', u'_context_project_id': None, u'_context_timestamp': u'2013-12-04 09:57:50.353613', u'_context_user_id': None, u'method': u'security_group_rules_for_devices'} _safe_log /usr/lib/python2.7/dist-packages/neutron/openstack/common/rpc/common.py:276 2013-12-04 15:25:58.804 17784 DEBUG neutron.plugins.openvswitch.ovs_db_v2 [-] get_port_with_securitygroups() called:port_id=92a508d4-d664-47d7-8933-5a9826eabe3b get_port_from_device /usr/lib/python2.7/dist-packages/neutron/plugins/openvswitch/ovs_db_v2.py:322 2013-12-04 15:26:02.942 17784 DEBUG neutron.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin'], u'_msg_id': u'b6b1639a8304448db0cf6a7c585cfc65', u'_context_read_deleted': u'no', u'_reply_q': u'reply_e9aab6015394494792574c917fb89490', u'_context_tenant_id': None, u'args': {u'device': u'92a508d4-d664-47d7-8933-5a9826eabe3b', u'agent_id': u'ovs4a5403c4074e'}, u'namespace': None, u'_unique_id': u'e3f3078be0974f83aa8c58b726bfbd5e', u'_context_is_admin': True, u'version': u'1.1', u'_context_project_id': None, u'_context_timestamp': u'2013-12-04 09:57:50.353613', u'_context_user_id': None, u'method': u'get_device_details'} _safe_log /usr/lib/python2.7/dist-packages/neutron/openstack/common/rpc/common.py:276 2013-12-04 15:26:02.943 17784 DEBUG neutron.plugins.openvswitch.ovs_neutron_plugin [-] Device 92a508d4-d664-47d7-8933-5a9826eabe3b details requested from ovs4a5403c4074e get_device_details /usr/lib/python2.7/dist-packages/neutron/plugins/openvswitch/ovs_neutron_plugin.py:105 2013-12-04 15:26:03.207 17784 DEBUG neutron.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin'], u'_msg_id': u'034caefaa4d0414a912cfb2a35c8c6b0', u'_context_read_deleted': u'no', u'_reply_q': u'reply_e9aab6015394494792574c917fb89490', u'_context_tenant_id': None, u'args': {u'device': u'92a508d4-d664-47d7-8933-5a9826eabe3b', u'host': u'oscompute11', u'agent_id': u'ovs4a5403c4074e'}, u'namespace': None, u'_unique_id': u'21dfb81aa7234320a7bdcfedef593e25', u'_context_is_admin': True, u'version': u'1.1', u'_context_project_id': None, u'_context_timestamp': u'2013-12-04 09:57:50.353613', u'_context_user_id': None, u'method': u'update_device_up'} _safe_log /usr/lib/python2.7/dist-packages/neutron/openstack/common/rpc/common.py:276 2013-12-04 15:26:03.253 17784 DEBUG neutron.plugins.openvswitch.ovs_neutron_plugin [-] Device 92a508d4-d664-47d7-8933-5a9826eabe3b up on ovs4a5403c4074e update_device_up /usr/lib/python2.7/dist-packages/neutron/plugins/openvswitch/ovs_neutron_plugin.py:159 DHCP Agent log 2013-12-04 15:23:32.054 30756 DEBUG neutron.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'_member_', u'admin'], u'_context_read_deleted': u'no', u'_context_tenant_id': u'9b073211dd5c4988993341cc955e200b', u'args': {u'payload': {u'port': {u'status': u'DOWN', u'binding:host_id': u'oscompute11', u'name': u'', u'allowed_address_pairs': [], u'admin_state_up': True, u'network_id': u'fb4fd94f-9d44-4f22-a347-ffdf8476c148', u'tenant_id': u'9b073211dd5c4988993341cc955e200b', u'binding:vif_type': u'ovs', u'device_owner': u'compute:None', u'binding:capabilities': {u'port_filter': True}, u'mac_address': u'fa:16:3e:39:68:82', u'fixed_ips': [{u'subnet_id': u'50918af5-70eb-4cf7-a50e-276334738793', u'ip_address': u'192.168.32.64'}], u'id': u'92a508d4-d664-47d7-8933-5a9826eabe3b', u'security_groups': [u'7823d4f4-24fa-4434-816d-ed839d69a5b6'], u'device_id': u'2ba403d2-71f8-4ee6-a746-2e398bda9404'}}}, u'namespace': None, u'_unique_id': u'7b2ad87e6e8440408a5c506467c2f4ca', u'_context_is_admin': True, u'version': u'1.0', u'_context_project_id': u'9b073211dd5c4988993341cc955e200b', u'_context_timestamp': u'2013-12-04 15:23:31.922971', u'_context_user_id': u'add03b5664694d99b151392a615c602b', u'method': u'port_create_end'} _safe_log /usr/lib/python2.7/dist-packages/neutron/openstack/common/rpc/common.py:276 Still getting below errors in DHCP agent log 2013-12-04 17:13:58.479 30756 ERROR neutron.agent.dhcp_agent [-] Unable to reload_allocations dhcp. 2013-12-04 17:13:58.479 30756 TRACE neutron.agent.dhcp_agent Traceback (most recent call last): .. 2013-12-04 17:13:58.479 30756 TRACE neutron.agent.dhcp_agent File "/usr/lib/python2.7/dist-packages/neutron/openstack/common/rpc/proxy.py", line 130, in call 2013-12-04 17:13:58.479 30756 TRACE neutron.agent.dhcp_agent exc.info, real_topic, msg.get('method')) 2013-12-04 17:13:58.479 30756 TRACE neutron.agent.dhcp_agent Timeout: Timeout while waiting on RPC response - topic: "q-plugin", RPC method: "get_dhcp_port" info: "<unknown>" 2013-12-04 17:14:22.166 30756 ERROR neutron.agent.dhcp_agent [-] Unable to sync network state. 2013-12-04 17:14:22.166 30756 TRACE neutron.agent.dhcp_agent Traceback (most recent call last): ... 2013-12-04 17:14:22.166 30756 TRACE neutron.agent.dhcp_agent File "/usr/lib/python2.7/dist-packages/neutron/openstack/common/rpc/proxy.py", line 130, in call 2013-12-04 17:14:22.166 30756 TRACE neutron.agent.dhcp_agent exc.info, real_topic, msg.get('method')) 2013-12-04 17:14:22.166 30756 TRACE neutron.agent.dhcp_agent Timeout: Timeout while waiting on RPC response - topic: "q-plugin", RPC method: "get_active_networks_info" info: "<unknown>" In Compute Node openvswitchagent log getting many of these kind of errors 2013-12-04 15:24:47.996 34067 TRACE neutron.plugins.openvswitch.agent.ovs_neutron_agent Timeout: Timeout while waiting on RPC response - topic: "q-plugin", RPC method: "security_group_rules_for_devices" info: "<unknown>"
_______________________________________________ OpenStack-dev mailing list OpenStack-dev@lists.openstack.org http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev