yahoo-eng-team team mailing list archive

Thread
Date
[Bug 2067588] [NEW] [ML2/OVS] Agent RPC loop delay when disconnected from OVS

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Sahid Orentino <2067588@xxxxxxxxxxxxxxxxxx>
Date: Thu, 30 May 2024 09:39:11 -0000
Reply-to: Bug 2067588 <2067588@xxxxxxxxxxxxxxxxxx>
Sender: noreply@xxxxxxxxxxxxx
Public bug reported:

When the Neutron agent loses its connection to OVS, the RPC loop takes a
path that leads to the recreation of bridges and the reapplication of
flows, as if OVS had been restarted. This process introduces a
significant delay, causing the agent to respond too late to Nova when it
is waiting for the network to be allocated to start a virtual machine on
a compute node.

When the agent loses its connection to OVS it is different than a OVS
restart. We should not lost bridges or consider new flow as the process
is waiting until to get the connection again.

We can notice in the log that when the Agent lost it's connection a
delay happening then that delay disappears when the agent finished that
process of recreating and fixing flows.


Some workaround has been proposed to delay when we consider the OVS as dead, which would allow to reduce the chance of falling down this situation that by configuring a larger inactivity_probe. But this is probably just a limited workaround.

https://docs.mirantis.com/mcp/q4-18/mcp-operations-guide/tshooting/tshoot-mcp-openstack/ovs-timeouts.html
https://www.ibm.com/docs/en/cic/1.1.6?topic=kvm-build-instance-aborts-due-failing-allocate-networks

2024-05-29 01:16:50.813 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963936 - ports processed. Elapsed:77.404
2024-05-29 01:17:28.032 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963937 - ports processed. Elapsed:37.218
2024-05-29 01:17:55.342 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963938 - ports processed. Elapsed:27.310
2024-05-29 01:18:18.930 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963939 - ports processed. Elapsed:23.587
2024-05-29 01:18:44.199 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963940 - ports processed. Elapsed:25.269
2024-05-29 01:20:07.888 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963941 - ports processed. Elapsed:83.688
2024-05-29 01:21:31.750 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963942 - ports processed. Elapsed:83.861
2024-05-29 01:22:56.710 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963943 - ports processed. Elapsed:84.959
2024-05-29 01:30:20.300 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963944 - ports processed. Elapsed:443.589
2024-05-29 01:37:36.641 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963945 - ports processed. Elapsed:381.505
2024-05-29 01:44:43.234 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963946 - ports processed. Elapsed:391.519
2024-05-29 01:51:11.738 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963947 - ports processed. Elapsed:357.517
2024-05-29 01:57:00.397 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963948 - ports processed. Elapsed:319.566
2024-05-29 02:02:54.979 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963949 - ports processed. Elapsed:325.568
2024-05-29 02:09:17.268 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963950 - ports processed. Elapsed:355.564
2024-05-29 02:15:23.856 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963951 - ports processed. Elapsed:338.542
2024-05-29 02:16:29.553 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963952 - ports processed. Elapsed:40.702
2024-05-29 02:21:30.288 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963953 - ports processed. Elapsed:300.735
2024-05-29 02:27:19.488 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963954 - ports processed. Elapsed:321.350
2024-05-29 02:32:40.259 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963955 - ports processed. Elapsed:295.150
2024-05-29 02:33:20.829 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963956 - ports processed. Elapsed:13.110
2024-05-29 02:33:23.012 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963957 - ports processed. Elapsed:2.183
2024-05-29 02:33:24.989 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963958 - ports processed. Elapsed:1.976
2024-05-29 02:33:30.940 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963961 - ports processed. Elapsed:1.925
2024-05-29 02:33:34.983 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963963 - ports processed. Elapsed:1.967
2024-05-29 02:33:44.949 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963968 - ports processed. Elapsed:1.930
2024-05-29 02:33:47.092 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963969 - ports processed. Elapsed:2.072
2024-05-29 02:34:09.054 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963980 - ports processed. Elapsed:1.953
2024-05-29 02:34:13.075 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963982 - ports processed. Elapsed:1.967
2024-05-29 02:34:25.390 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963988 - ports processed. Elapsed:2.277
2024-05-29 02:34:27.249 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963989 - ports processed. Elapsed:1.859
2024-05-29 02:34:53.430 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1964002 - ports processed. Elapsed:2.030
2024-05-29 02:34:55.391 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1964003 - ports processed. Elapsed:1.961
2024-05-29 02:35:17.374 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1964014 - ports processed. Elapsed:1.934
2024-05-29 02:35:19.598 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1964015 - ports processed. Elapsed:2.158
2024-05-29 02:35:31.698 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1964021 - ports processed. Elapsed:2.095

** Affects: neutron
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/2067588

Title:
  [ML2/OVS] Agent RPC loop delay when disconnected from OVS

Status in neutron:
  New

Bug description:
  When the Neutron agent loses its connection to OVS, the RPC loop takes
  a path that leads to the recreation of bridges and the reapplication
  of flows, as if OVS had been restarted. This process introduces a
  significant delay, causing the agent to respond too late to Nova when
  it is waiting for the network to be allocated to start a virtual
  machine on a compute node.

  When the agent loses its connection to OVS it is different than a OVS
  restart. We should not lost bridges or consider new flow as the
  process is waiting until to get the connection again.

  We can notice in the log that when the Agent lost it's connection a
  delay happening then that delay disappears when the agent finished
  that process of recreating and fixing flows.

  
  Some workaround has been proposed to delay when we consider the OVS as dead, which would allow to reduce the chance of falling down this situation that by configuring a larger inactivity_probe. But this is probably just a limited workaround.

  https://docs.mirantis.com/mcp/q4-18/mcp-operations-guide/tshooting/tshoot-mcp-openstack/ovs-timeouts.html
  https://www.ibm.com/docs/en/cic/1.1.6?topic=kvm-build-instance-aborts-due-failing-allocate-networks

  2024-05-29 01:16:50.813 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963936 - ports processed. Elapsed:77.404
  2024-05-29 01:17:28.032 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963937 - ports processed. Elapsed:37.218
  2024-05-29 01:17:55.342 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963938 - ports processed. Elapsed:27.310
  2024-05-29 01:18:18.930 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963939 - ports processed. Elapsed:23.587
  2024-05-29 01:18:44.199 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963940 - ports processed. Elapsed:25.269
  2024-05-29 01:20:07.888 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963941 - ports processed. Elapsed:83.688
  2024-05-29 01:21:31.750 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963942 - ports processed. Elapsed:83.861
  2024-05-29 01:22:56.710 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963943 - ports processed. Elapsed:84.959
  2024-05-29 01:30:20.300 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963944 - ports processed. Elapsed:443.589
  2024-05-29 01:37:36.641 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963945 - ports processed. Elapsed:381.505
  2024-05-29 01:44:43.234 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963946 - ports processed. Elapsed:391.519
  2024-05-29 01:51:11.738 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963947 - ports processed. Elapsed:357.517
  2024-05-29 01:57:00.397 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963948 - ports processed. Elapsed:319.566
  2024-05-29 02:02:54.979 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963949 - ports processed. Elapsed:325.568
  2024-05-29 02:09:17.268 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963950 - ports processed. Elapsed:355.564
  2024-05-29 02:15:23.856 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963951 - ports processed. Elapsed:338.542
  2024-05-29 02:16:29.553 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963952 - ports processed. Elapsed:40.702
  2024-05-29 02:21:30.288 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963953 - ports processed. Elapsed:300.735
  2024-05-29 02:27:19.488 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963954 - ports processed. Elapsed:321.350
  2024-05-29 02:32:40.259 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963955 - ports processed. Elapsed:295.150
  2024-05-29 02:33:20.829 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963956 - ports processed. Elapsed:13.110
  2024-05-29 02:33:23.012 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963957 - ports processed. Elapsed:2.183
  2024-05-29 02:33:24.989 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963958 - ports processed. Elapsed:1.976
  2024-05-29 02:33:30.940 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963961 - ports processed. Elapsed:1.925
  2024-05-29 02:33:34.983 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963963 - ports processed. Elapsed:1.967
  2024-05-29 02:33:44.949 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963968 - ports processed. Elapsed:1.930
  2024-05-29 02:33:47.092 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963969 - ports processed. Elapsed:2.072
  2024-05-29 02:34:09.054 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963980 - ports processed. Elapsed:1.953
  2024-05-29 02:34:13.075 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963982 - ports processed. Elapsed:1.967
  2024-05-29 02:34:25.390 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963988 - ports processed. Elapsed:2.277
  2024-05-29 02:34:27.249 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1963989 - ports processed. Elapsed:1.859
  2024-05-29 02:34:53.430 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1964002 - ports processed. Elapsed:2.030
  2024-05-29 02:34:55.391 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1964003 - ports processed. Elapsed:1.961
  2024-05-29 02:35:17.374 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1964014 - ports processed. Elapsed:1.934
  2024-05-29 02:35:19.598 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1964015 - ports processed. Elapsed:2.158
  2024-05-29 02:35:31.698 7 INFO neutron.plugins.ml2.drivers.openvswitch.agent.ovs_neutron_agent [req-7ca02ba8-4471-40d8-b341-65a3117f7116 - - - - -] Agent rpc_loop - iteration:1964021 - ports processed. Elapsed:2.095

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/2067588/+subscriptions