dhcp dnsmasq lost port in host config file

[Wu Wenxiang]

Version: Stable/Grizzly

In sometimes, If start up 5 vm, and each one has 2 nics, some of their nics could got a IP address from dhcp-agent.
Run dhclient or ipconfig /renew couldn't work around.
And I found there's no related port MAC in their dnsmasq config file => host, that caused this issue.

And the work around method is delete the VM, create again.
Or, kill all of the dnsmasq processes and dhcp-agent, then start them again.

[Wu Wenxiang (wu-wenxiang)]

With debug, I found the funciton port_update_end() didn't be called when quantum is busy, which caused the cache didn't updated when a port created with creating a VM, so that the host file (used for dnsmasq) didn't contain the new VM's MAC & IP address.

And I made a change, in dhcp-agent, I run a period thread to modify the sync flag to True every 10 mins.
Then the cache updated every 10 mins. Any VM who didn't get the IP from DHCP-agent then could got IP in 10 mins.

My solution couldn't fix this issue graceful but improvement.

[Mark McClain (markmcclain)]

Is there a set of reproducible steps to trigger this bug?

[Wu Wenxiang (wu-wenxiang)]

This issue not always happened but very often in our production environment.
I describe our production environment here:
1. Quantum with GRE Mode. DHCP use dnsmasq.
2. One L3 node(24 cores, 32G), DHCP-agent, Metadata-agent, L3-agent, OVS-plugin running on it.
3. Three Compute nodes(24Core, 96G), Nova-compute, OVS-plugin running on it.
4. VM has alreay more than 50, both VM has 2 nics belong to 2 networks.
5. 10 tenants, 2 networks for each tenant.

Then,
6. Boot 5 VMs with 2 NIC, and repeat 10 times. Check all the 50 new VMs, you will found some of them didn't got the IP from dnsmasq. Then check the related host file, you will found MAC/IP address missed here.

 I think it's absolutely a bug for quantum.

[Mark McClain (markmcclain)]

Might have been a function of refresh speed in Grizzly. Need to look at the changes in stable/havana and compare against Icehouse.

[Maru Newby (maru)]

I can reproduce the bug on icehouse with devstack:

- get the tenant id of the demo user (keystone tenant-list)
- update the cores and instances quota to 50+ for that user (nova-manage project quota [tenant-id] --key=cores --value=50)
- boot 50+ nano (64mb) instances (will need lots of ram - 4gb+), e.g.

for i in $(seq 1 50); do
  nova boot --flavor 42 --image cirros-0.3.1-x86_64-disk stress-$i &
done

- check the line count of the leases file ('ps aux | grep dnsmasq' and get the argument to dns-hostsfile)
  - the number of lines should be the same as the number of vm's booted

I see anywhere from 5-10 missing leases and the vm's for those missing leases are not assigned an ip address. Restarting the agent will ensure the leases are created, but by then it is too late for the vm's.

This issue has also been reported in RHOS 3.0: https://bugzilla.redhat.com/show_bug.cgi?id=1023818

[Maru Newby (maru)]

I instrumented the dhcp notifier and found that under high cpu load a call to _get_dhcp_agents() (https://github.com/openstack/neutron/blob/master/neutron/api/rpc/agentnotifiers/dhcp_rpc_agent_api.py#L79) was returning no agents, preventing port_create_end notifications being sent to the agent. _get_dhcp_agents() filters by active=True, so a failure to deliver any results indicated that the agent heartbeat was not being received by the neutron service in a timely fashion. Since the notification of port creation was never sent to the agent, the dnsmasq instance for the network was not updated with the port's ip assignment and the VM associated with the port was unable to configure itself for connectivity.

Reproduction is as per the instructions in the previous comment, booting 75 VMs instead of 50 to ensure consistent failure. This required setting the quota for cores and instances accordingly. Many of the VMs had multiple ports allocated for them (as per https://bugs.launchpad.net/neutron/+bug/1160442) up to the neutron port quota of 100. A example result was that 59 notifications were sent to the agent, and 41 were not sent due to the agent not being reported as 'active'. Of the 59 notifications sent, 43 resulted in host entries in the dhcp server, and 16 notifications were part of VM creation that failed due to Neutron timeouts. Out of the 75 boot attempts, 54 reported as successful but many of the successful VMs were subsequently unable to configure connectivity due to missing entries in the dhcp hosts file (only 43 ip addresses were configured).

The clear result of this testing is that the current approach of 'spray and pray' notification is not sufficient to ensure reliable operation. If a notification that triggers a necessary action cannot be sent or delivered in a timely fashion, an error would ideally be propagated or at least logged. This bug also suggests that there needs to be better coordination between Nova and Neutron so that VM error state can be more accurately reported (and perhaps remedied).

[Snow Cherry (tuhongj)]

It seems with agent_down_time twice as report_interval, the problem does not occur. For example, agent_down_time = 120, report_interval = 60, the dhcp-agent will not be regarded as dead easily.

[Sreedhar Nathani (sreedhar-nathani)]

Hi Maru, Here are the details about the issues which i was facing after installing Havana compared to Grizzly

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 with out any errors
Initially on Grizzly also seen the same behaviour 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+ insatnces. 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 continously

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
https://review.openstack.org/#/c/37131/

After this patch and starting 8 neutron-server worker threads, during the batch crea...

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/61168

[Maru Newby (maru)]

The committed fix serves is intended to serve as a stop-gap until the dhcp agent is updated to be eventual consistency. That effort will be tracked by the following blueprint: https://blueprints.launchpad.net/neutron/+spec/eventually-consistent-dhcp-agent

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/havana
Review: https://review.openstack.org/65590

[Roey Dekel (rdekel)]

Tried to check on Havana with:
openstack-neutron-2013.2.2-1.el6ost.noarch

First Try:
=======

Reproduce Steps:
----------------
1. Setup environment with tenant-network (internal VLAN) and update qoutas for:
    instances - 100
    cores - 100
    ports - 150
2. Boot a vm to verify working setup
3. Boot 90 vms parallely:
    # for i in $(seq 1 90); do nova boot stress-${i} --flavor 1 --image cirros-0.3.1 --nic net-id=`neutron net-list | grep netInt | cut -d" " -f2` & done
4. Verify working VM's with non-identical IP's
5. Delete 90 vms parallely:
    # for i in $(seq 1 90); do nova delete boot stress-${i} & done

Expected Results:
-----------------
Environment return to same status before stress boot.

Results:
--------
26 VM's at ERROR
3 VM's at ACTIVE

Comments:
---------
1. Step 4 - verified with the next cmd which showed 92 (91 VM'S + DHCP):
    # cat /var/lib/neutron/dhcp/cef6f793-0b5f-429f-9e4b-f9e4e70dbca3/host | cut -d"," -f3 | sort -n | uniq | wc -l
2. Attached is a moment after sending the deletion cmd (step 5) - attachment 866663 [details].
3. Attached is log for nova compute which indicates a problem with deleted port - probably it was deleted before the vm was deleted.

Secound Try:
==========
Cleared the not deleted VM's and tried to clear again, sequentialy this time.

Reproduce Steps:
----------------
1. Boot 90 vms parallely:
    # for i in $(seq 1 90); do nova boot stress-${i} --flavor 1 --image cirros-0.3.1 --nic net-id=`neutron net-list | grep netInt | cut -d" " -f2` & done
2. Delete 90 vms sequently:
    # for i in $(seq 1 90); do nova delete boot stress-${i} ; done

Expected Results:
-----------------
1. 90 new ACTIVE VM's with valid IP's.
2. Deleted 90 VM's

Results:
--------
1. 3 VM's stuck on BUILD.
2. 3 VM's on BUILD - weren't deleted.
   1 VM - ERROR
   1 VM - ACTIVE (as nothing happend)