PortNotFound in DHCP agent logs

[Kevin Benton]

The DHCP agent can call update_dhcp_port, in which case a PortNotFound exception can be thrown. This currently goes uncaught and leads to lots of log noise.

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Remote%20error%3A%20PortNotFound%5C%22

2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server [req-cadd9638-976b-4c45-8a67-b8e027c31b07 - -] Exception during message handling
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/server.py", line 133, in _process_incoming
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 150, in dispatch
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 121, in _do_dispatch
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 151, in wrapper
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server ectxt.value = e.inner_exc
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server self.force_reraise()
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 139, in wrapper
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server return f(*args, **kwargs)
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/opt/stack/new/neutron/neutron/db/api.py", line 82, in wrapped
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server traceback.format_exc())
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server self.force_reraise()
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/opt/stack/new/neutron/neutron/db/api.py", line 77, in wrapped
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server return f(*args, **kwargs)
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/opt/stack/new/neutron/neutron/api/rpc/handlers/dhcp_rpc.py", line 274, in update_dhcp_port
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server return self._port_action(plugin, context, port, 'update_port')
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/opt/stack/new/neutron/neutron/api/rpc/handlers/dhcp_rpc.py", line 100, in _port_action
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server return plugin.update_port(context, port['id'], port)
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/opt/stack/new/neutron/neutron/common/utils.py", line 618, in inner
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server return f(self, context, *args, **kwargs)
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server File "/opt/stack/new/neutron/neutron/plugins/ml2/plugin.py", line 1364, in update_port
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server raise exc.PortNotFound(port_id=id)
2016-09-08 07:23:35.069 13627 ERROR oslo_messaging.rpc.server PortNotFound: Port 3671e6b0-b969-4949-a486-d708e43aa60c could not be found.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/367679
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=9d24490da8552542309dc7b9d6cbc695af4c6de6
Submitter: Jenkins
Branch: master

commit 9d24490da8552542309dc7b9d6cbc695af4c6de6
Author: Kevin Benton <email address hidden>
Date: Thu Sep 8 15:19:06 2016 -0700

    Handle racey teardowns in DHCP agent

    Capture port not found exceptions from port updates of DHCP ports
    that no longer exist. The DHCP agent already checks the return
    value for None in case any of the other things went missing
    (e.g. Subnet, Network), so checking for ports disappearing makes
    sense. The corresponding agent-side log message for this has also
    been downgraded to debug since this is a normal occurrence.

    This also cleans up log noise from calling reload_allocations on
    networks that have already been torn down due to all of the subnets
    being removed.

    Closes-Bug: #1621650
    Change-Id: I495401d225c664b8f1cf7b3d51747f3b47c24fc0

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/neutron 9.0.0.0rc1 release candidate.