While updating fixed_ip attribute of neutron port, get rabbit error

[Sridhar Venkat]

While attempting to update fixed_ip attribute of neutron port, get this error:
2017-06-29 02:55:58.856 37283 ERROR oslo.messaging._drivers.impl_rabbit [req-2ea397ae-d5fd-4860-aca6-e633bba0d84a 0688b01e6439ca32d698d20789d52169126fb41fb1a4ddafcebb97d854e836c9 2d374653dc914c2e877fb6900ef28ccd - - -] Failed to publish message to topic 'q-agent-notifier-l2population-update_fanout': Basic.publish: (404) NOT_FOUND - no exchange 'q-agent-notifier-l2population-update_fanout' in vhost '/'

Stack trace from neutron server log :
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers [req-2ea397ae-d5fd-4860-aca6-e633bba0d84a 0688b01e6439ca32d698d20789d52169126fb41fb1a4ddafcebb97d854e836c9 2d374653dc914c2e877fb6900ef28ccd - - -] Mechanism driver 'l2population' failed in update_port_postcommit
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers Traceback (most recent call last):
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/managers.py", line 408, in _call_on_drivers
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers getattr(driver.obj, method_name)(context)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/l2pop/mech_driver.py", line 156, in update_port_postcommit
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers self._fixed_ips_changed(context, orig, port, diff_ips)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/l2pop/mech_driver.py", line 134, in _fixed_ips_changed
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers self.rpc_ctx, {'chg_ip': upd_fdb_entries})
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/l2pop/rpc.py", line 87, in update_fdb_entries
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers fdb_entries)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/l2pop/rpc.py", line 49, in _notification_fanout
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers cctxt.cast(context, method, fdb_entries=fdb_entries)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 147, in cast
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers self.transport._send(self.target, msg_ctxt, msg, retry=self.retry)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 97, in _send
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers timeout=timeout, retry=retry)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 458, in send
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers retry=retry)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 432, in _send
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers conn.fanout_send(target.topic, msg, retry=retry)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_rabbit.py", line 1295, in fanout_send
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers self._ensure_publishing(self._publish, exchange, msg, retry=retry)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_rabbit.py", line 1170, in _ensure_publishing
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers self.ensure(method, retry=retry, error_callback=_error_callback)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_rabbit.py", line 817, in ensure
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers ret, channel = autoretry_method()
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/kombu/connection.py", line 436, in _ensured
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers return fun(*args, **kwargs)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/kombu/connection.py", line 508, in __call__
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers return fun(*args, channel=channels[0], **kwargs), channels[0]
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_rabbit.py", line 793, in execute_method
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers method()
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_rabbit.py", line 1201, in _publish
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers compression=self.kombu_compression)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/kombu/messaging.py", line 172, in publish
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers routing_key, mandatory, immediate, exchange, declare)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/kombu/messaging.py", line 188, in _publish
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers mandatory=mandatory, immediate=immediate,
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/amqp/channel.py", line 2130, in basic_publish_confirm
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers self.wait([(60, 80)])
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/amqp/abstract_channel.py", line 69, in wait
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers return self.dispatch_method(method_sig, args, content)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/amqp/abstract_channel.py", line 87, in dispatch_method
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers return amqp_method(self, args)
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers File "/usr/lib/python2.7/site-packages/amqp/channel.py", line 241, in _close
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers reply_code, reply_text, (class_id, method_id), ChannelError,
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers NotFound: Basic.publish: (404) NOT_FOUND - no exchange 'q-agent-notifier-l2population-update_fanout' in vhost '/'
2017-06-29 02:55:58.858 37283 ERROR neutron.plugins.ml2.managers
2017-06-29 02:55:58.903 37283 ERROR neutron.plugins.ml2.plugin [req-2ea397ae-d5fd-4860-aca6-e633bba0d84a 0688b01e6439ca32d698d20789d52169126fb41fb1a4ddafcebb97d854e836c9 2d374653dc914c2e877fb6900ef28ccd - - -] mechanism_manager.update_port_postcommit failed for port 799abd6f-c1d7-4fd3-8a77-65f1b0bf9515

In rabbitmq log
=ERROR REPORT==== 29-Jun-2017::04:21:48 ===
Channel error on connection <0.14694.1> (127.0.0.1:52206 -> 127.0.0.1:5671, vhost: '/', user: 'powervc_mq'), channel 1:
operation basic.publish caused a channel exception not_found: "no exchange 'q-agent-notifier-l2population-update_fanout' in vhost '/'"

Version :

This is happening in Openstack ocata level environment. Two out of three attempts result in this error. One of them went through succesfully later on.

[Anusha K (anusha25)]

Hi Sridhar, Please find my analysis :

From the error "no exchange 'q-agent-notifier-l2population-update_fanout' in vhost '/'" , I suspect that l2_population = True is not defined in ml2_conf.ini as below:

[agent]
l2_population = True

As "q-agent-notifier-l2population-update" queue will be created only if l2_population is set true. Please find the code flow for the same

In ovs_neutron_agent.py:
    def setup_rpc(self):
        .................

        if self.l2_pop:
            consumers.append([topics.L2POPULATION, topics.UPDATE])
        self.connection = agent_rpc.create_consumers([self],
                                                     topics.AGENT,
                                                     consumers,
                                                     start_listening=False)
I tried updating fixed-ip for port in ocata, the issue was not raised.
Could you please confirm whether l2_population = True (in ml2_conf.ini) is placed in your setup.

[Sridhar Venkat (svenkat)]

Hi Anusha, thanks for looking into this problem.

In our environment, l2_population is not set at all, it is left with its default value. I also noticed that the fixed_ip attribute of neutron port works fine in majority of the cases, above mentioned error occurs in one out of many attempts.

[Anusha K (anusha25)]

Hi Sridhar, From the logs in the bug description, it is clear that l2population mechanism driver is invoked to notify agent on port update. So I thought l2population mechnanism driver is set in your setup, so that agent notification is invoked for each specified mechanism driver in ml2_conf.ini.

Could you please check the mechanism_drivers defined in your setup, if l2population is enabled by default.

[Sridhar Venkat (svenkat)]

l2population mechanism driver is enabled in plugin.ini
mechanism_drivers = openvswitch,l2population,<other mechanism drivers>

[Anusha K (anusha25)]

Could you please enable l2_population = True in ml2_conf.ini as specified below and repeat the test steps. Because 'q-agent-notifier-l2population-update_fanout' queue is used by l2population mechanism driver to notify agent on port update and this queue is created if l2_population is set under agent section.

[agent]
l2_population = True

[Sridhar Venkat (svenkat)]

Anusha, I did not look into right file, l2_population is set to true in the environment:

[AGENT]
tunnel_types = vxlan
extensions = qos
l2_population = True

It is in /etc/neutron/plugins/ml2/openvswitch_agent.ini file.

Sorry about this confusion.

[Luvella McFadden (lmcfadden)]

Anusha, are you able to make any progress?

[Anusha K (anusha25)]

I am still debugging, for now I don't have any findings on these issue.
I have issued port-update continuously and didn't observe this error on ocata setup.

@Sridhar will it be possible to reproduce the issue again? If yes, can you please provide the output of 'rabbitmqctl list_queues' at the time of error and also the neutron server and agent logs.

[Sridhar Venkat (svenkat)]

Anusha, this problem does not occur all the time, only one in few attempts. I will work to get you logs.