yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1547563] [NEW] Liberty Neutron server RPC worker threads loses endpoints

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Rachappa B Goni <grachapp@xxxxxxxxxx>
Date: Fri, 19 Feb 2016 15:43:17 -0000
Reply-to: Bug 1547563 <1547563@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

High level description:

When we restart the DHCP agent, we see the RPC exceptions. However,
further RPC retries are successful.

The cause for the problem found to be that the RPC worker threads keep
losing endpoints at neutron server. This also causes DHCP port creation
failure intermittently and increased latency.

DHCP Agent logs:
2016-02-19 09:20:25.721 46335 INFO neutron.agent.dhcp.agent [-] Synchronizing state
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent [-] Unable to sync network state.
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent Traceback (most recent call last):
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent   File "/opt/neutron/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py", line 157, in sync_state
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent     active_networks = self.plugin_rpc.get_active_networks_info()
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent   File "/opt/neutron/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py", line 421, in get_active_networks_info
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent     host=self.host)
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent   File "/opt/neutron/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 158, in call
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent     retry=self.retry)
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent   File "/opt/neutron/lib/python2.7/site-packages/oslo_messaging/transport.py", line 90, in _send
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent     timeout=timeout, retry=retry)
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent   File "/opt/neutron/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 466, in send
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent     retry=retry)
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent   File "/opt/neutron/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 457, in _send
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent     raise result
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent RemoteError: Remote error: UnsupportedVersion Endpoint does not support RPC version 1.1. Attempted method: get_active_networks_info
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent [u'Traceback (most recent call last):\n', u'  File "/opt/neutron/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 143, in _dispatch_and_reply\n    executor_callback))\n', u'  File "/opt/neutron/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 198, in _dispatch\n    raise UnsupportedVersion(version, method=method)\n', u'UnsupportedVersion: Endpoint does not support RPC version 1.1. Attempted method: get_active_networks_info\n'].
2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent 
2016-02-19 09:20:30.731 46335 INFO neutron.agent.dhcp.agent [-] Synchronizing state
2016-02-19 09:20:30.798 46335 INFO neutron.agent.dhcp.agent [-] Synchronizing state complete


Neutron Server side RPC threads endpoints dump:
2016-02-19 12:42:43.445 20786 DEBUG oslo_messaging.rpc.dispatcher [-] endpoints= ([<neutron.db.agents_db.AgentExtRpcCallback object at 0x148519d0>]) _dispatch /opt/neutron/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py:174

2016-02-19 12:42:43.508 20785 DEBUG oslo_messaging.rpc.dispatcher [-]
endpoints= ([<neutron.db.agents_db.AgentExtRpcCallback object at
0x14849990>]) _dispatch /opt/neutron/lib/python2.7/site-
packages/oslo_messaging/rpc/dispatcher.py:174

2016-02-19 12:42:48.520 20786 DEBUG oslo_messaging.rpc.dispatcher [-]
endpoints= ([<neutron.api.rpc.handlers.dhcp_rpc.DhcpRpcCallback object
at 0x488ec50>, <neutron.db.agents_db.AgentExtRpcCallback object at
0x4892410>, <neutron.api.rpc.handlers.metadata_rpc.MetadataRpcCallback
object at 0x14851650>]) _dispatch /opt/neutron/lib/python2.7/site-
packages/oslo_messaging/rpc/dispatcher.py:174


Packages info:
    neutron (7.0.3)
    oslo.concurrency (3.4.0)
    oslo.config (3.6.0)
    oslo.context (2.0.0)
    oslo.db (4.3.1)
    oslo.messaging (4.1.0)
    oslo.middleware (3.5.0)
    oslo.serialization (2.3.0)
    oslo.utils (3.5.0)

Neutron Server Configuration:
   RPC worker threads = 2
   API worker threads = 4

** 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/1547563

Title:
  Liberty Neutron server RPC worker threads loses endpoints

Status in neutron:
  New

Bug description:
  High level description:

  When we restart the DHCP agent, we see the RPC exceptions. However,
  further RPC retries are successful.

  The cause for the problem found to be that the RPC worker threads keep
  losing endpoints at neutron server. This also causes DHCP port
  creation failure intermittently and increased latency.

  DHCP Agent logs:
  2016-02-19 09:20:25.721 46335 INFO neutron.agent.dhcp.agent [-] Synchronizing state
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent [-] Unable to sync network state.
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent Traceback (most recent call last):
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent   File "/opt/neutron/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py", line 157, in sync_state
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent     active_networks = self.plugin_rpc.get_active_networks_info()
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent   File "/opt/neutron/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py", line 421, in get_active_networks_info
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent     host=self.host)
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent   File "/opt/neutron/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 158, in call
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent     retry=self.retry)
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent   File "/opt/neutron/lib/python2.7/site-packages/oslo_messaging/transport.py", line 90, in _send
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent     timeout=timeout, retry=retry)
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent   File "/opt/neutron/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 466, in send
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent     retry=retry)
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent   File "/opt/neutron/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 457, in _send
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent     raise result
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent RemoteError: Remote error: UnsupportedVersion Endpoint does not support RPC version 1.1. Attempted method: get_active_networks_info
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent [u'Traceback (most recent call last):\n', u'  File "/opt/neutron/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 143, in _dispatch_and_reply\n    executor_callback))\n', u'  File "/opt/neutron/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 198, in _dispatch\n    raise UnsupportedVersion(version, method=method)\n', u'UnsupportedVersion: Endpoint does not support RPC version 1.1. Attempted method: get_active_networks_info\n'].
  2016-02-19 09:20:25.730 46335 ERROR neutron.agent.dhcp.agent 
  2016-02-19 09:20:30.731 46335 INFO neutron.agent.dhcp.agent [-] Synchronizing state
  2016-02-19 09:20:30.798 46335 INFO neutron.agent.dhcp.agent [-] Synchronizing state complete


  
  Neutron Server side RPC threads endpoints dump:
  2016-02-19 12:42:43.445 20786 DEBUG oslo_messaging.rpc.dispatcher [-] endpoints= ([<neutron.db.agents_db.AgentExtRpcCallback object at 0x148519d0>]) _dispatch /opt/neutron/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py:174

  2016-02-19 12:42:43.508 20785 DEBUG oslo_messaging.rpc.dispatcher [-]
  endpoints= ([<neutron.db.agents_db.AgentExtRpcCallback object at
  0x14849990>]) _dispatch /opt/neutron/lib/python2.7/site-
  packages/oslo_messaging/rpc/dispatcher.py:174

  2016-02-19 12:42:48.520 20786 DEBUG oslo_messaging.rpc.dispatcher [-]
  endpoints= ([<neutron.api.rpc.handlers.dhcp_rpc.DhcpRpcCallback object
  at 0x488ec50>, <neutron.db.agents_db.AgentExtRpcCallback object at
  0x4892410>, <neutron.api.rpc.handlers.metadata_rpc.MetadataRpcCallback
  object at 0x14851650>]) _dispatch /opt/neutron/lib/python2.7/site-
  packages/oslo_messaging/rpc/dispatcher.py:174

  
  Packages info:
      neutron (7.0.3)
      oslo.concurrency (3.4.0)
      oslo.config (3.6.0)
      oslo.context (2.0.0)
      oslo.db (4.3.1)
      oslo.messaging (4.1.0)
      oslo.middleware (3.5.0)
      oslo.serialization (2.3.0)
      oslo.utils (3.5.0)

  Neutron Server Configuration:
     RPC worker threads = 2
     API worker threads = 4

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

[Bug 1547563] Re: Liberty Neutron server RPC worker threads loses endpoints
From: Amitabha Biswas, 2016-02-25