Mechanism driver 'l2population' failed in update_port_postcommit

[James Page]

OpenStack Juno, Ubuntu 14.04, 3 x neutron-server's with 32 API workers each, rally/boot-and-delete with a concurrency level of 150:

2014-10-21 16:37:04.615 16312 ERROR neutron.plugins.ml2.managers [req-c4cdefd5-b2d9-46fa-a031-bddd03d981e6 None] Mechanism driver 'l2population' failed in update_port_postcommit
2014-10-21 16:37:04.615 16312 TRACE neutron.plugins.ml2.managers Traceback (most recent call last):
2014-10-21 16:37:04.615 16312 TRACE neutron.plugins.ml2.managers File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/managers.py", line 291, in _call_on_drivers
2014-10-21 16:37:04.615 16312 TRACE neutron.plugins.ml2.managers getattr(driver.obj, method_name)(context)
2014-10-21 16:37:04.615 16312 TRACE neutron.plugins.ml2.managers File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/drivers/l2pop/mech_driver.py", line 135, in update_port_postcommit
2014-10-21 16:37:04.615 16312 TRACE neutron.plugins.ml2.managers self._update_port_up(context)
2014-10-21 16:37:04.615 16312 TRACE neutron.plugins.ml2.managers File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/drivers/l2pop/mech_driver.py", line 228, in _update_port_up
2014-10-21 16:37:04.615 16312 TRACE neutron.plugins.ml2.managers agent_ports += self._get_port_fdb_entries(binding.port)
2014-10-21 16:37:04.615 16312 TRACE neutron.plugins.ml2.managers File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/drivers/l2pop/mech_driver.py", line 45, in _get_port_fdb_entries
2014-10-21 16:37:04.615 16312 TRACE neutron.plugins.ml2.managers ip['ip_address']] for ip in port['fixed_ips']]
2014-10-21 16:37:04.615 16312 TRACE neutron.plugins.ml2.managers TypeError: 'NoneType' object has no attribute '__getitem__'
2014-10-21 16:37:04.615 16312 TRACE neutron.plugins.ml2.managers
2014-10-21 16:37:04.618 16312 ERROR oslo.messaging.rpc.dispatcher [req-c4cdefd5-b2d9-46fa-a031-bddd03d981e6 ] Exception during message handling: update_port_postcommit failed.
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher incoming.message))
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher return self._do_dispatch(endpoint, method, ctxt, args)
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher result = getattr(endpoint, method)(ctxt, **new_args)
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/rpc.py", line 161, in update_device_up
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher host)
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/plugin.py", line 1136, in update_port_status
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher self.mechanism_manager.update_port_postcommit(mech_context)
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/managers.py", line 527, in update_port_postcommit
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher continue_on_failure=True)
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/managers.py", line 302, in _call_on_drivers
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher method=method_name
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher MechanismDriverError: update_port_postcommit failed.
2014-10-21 16:37:04.618 16312 TRACE oslo.messaging.rpc.dispatcher
2014-10-21 16:37:04.620 16312 ERROR oslo.messaging._drivers.common [req-c4cdefd5-b2d9-46fa-a031-bddd03d981e6 ] Returning exception update_port_postcommit failed. to caller
2014-10-21 16:37:04.621 16312 ERROR oslo.messaging._drivers.common [req-c4cdefd5-b2d9-46fa-a031-bddd03d981e6 ] ['Traceback (most recent call last):\n', ' File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply\n incoming.message))\n', ' File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch\n return self._do_dispatch(endpoint, method, ctxt, args)\n', ' File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch\n result = getattr(endpoint, method)(ctxt, **new_args)\n', ' File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/rpc.py", line 161, in update_device_up\n host)\n', ' File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/plugin.py", line 1136, in update_port_status\n self.mechanism_manager.update_port_postcommit(mech_context)\n', ' File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/managers.py", line 527, in update_port_postcommit\n continue_on_failure=True)\n', ' File "/usr/lib/python2.7/dist-packages/neutron/plugins/ml2/managers.py", line 302, in _call_on_drivers\n method=method_name\n', 'MechanismDriverError: update_port_postcommit failed.\n']

[James Page (james-page)]

Some debug later reveals that in:

                agent_ports += self._get_port_fdb_entries(binding.port)

binding.port == None

looking at how this gets into this state.

[James Page (james-page)]

I guess its possible that due to the level of concurrency, there are ports in the tenant network that are not fully bound at the point where this call is made.

[Eugene Nikanorov (enikanorov)]

I guess this issue might be a manifestation of bug 1370570

[Eugene Nikanorov (enikanorov)]

I would ask to attach neutron-server logs for this issue, if it's possible.

I don't think this bug has many chances to be fixed unless someone could investigate it further on scale and provide debug-level logs.

[James Page (james-page)]

Eugene

Will try to get more in-depth log data when we next undertake some scale testing.

[Launchpad Janitor (janitor)]

[Expired for neutron (Ubuntu) because there has been no activity for 60 days.]

[Launchpad Janitor (janitor)]

[Expired for neutron because there has been no activity for 60 days.]

[Thiago Martins (martinx)]

I'm seeing this error message when with Networking OVN.

[Thiago Martins (martinx)]

Ubuntu 16.04 + Ocata from Cloud Archive.