In kilo or icehouse release: multiple deletes in firewall tempest case: "test_create_show_delete_firewall" cause l3-agent throws unexpected exception: "FirewallNotFound".
I am running tempest against kilo release, after running the neutron case: "test_create_show_delete_firewall", my l3-agent reports the following errors and exceptions:
In this tempest case:
I found delete firewall will be called twice, the second delete_firewall(in the method addCleanup), will be called immediately after the first(self.client.delete_firewall).
This looks like an async call locking problem, I don't know if the current log/implementation/behavior is expected or unexpected.
==
Tempest test case in the file: tempest/api/network/test_fwaas_extensions.py:
==
def test_create_show_delete_firewall(self):
...
self.addCleanup(self._try_delete_firewall, firewall_id)
...
self.client.delete_firewall(firewall_id)
==
my l3-agent log:
==
2015-08-25 08:34:00.420 31255 INFO neutron.wsgi [req-9cc36e3b-e209-4d95-bb40-9e1012a89621 ] 10.133.5.167 - - [25/Aug/2015 08:34:00] "DELETE /v2.0/fw/firewalls/2b3102d9-1925-47b3-bca3-a8cd0296cc8c HTTP/1.1" 204 168 0.237354 <- First Delete FW call
...
2015-08-25 08:34:00.725 31255 INFO neutron.wsgi [req-795bcbcf-5fde-43d6-8a66-5e2b3fdad44f ] 10.133.5.167 - - [25/Aug/2015 08:34:00] "DELETE /v2.0/fw/firewalls/2b3102d9-1925-47b3-bca3-a8cd0296cc8c HTTP/1.1" 204 168 0.299331 <- Second Delete FW call
...
2015-08-25 08:34:01.069 31255 DEBUG neutron_fwaas.db.firewall.firewall_db [req-9cc36e3b-e209-4d95-bb40-9e1012a89621 ] delete_firewall() called delete_firewall /usr/lib/python2.7/site-packages/neutron_fwaas/db/firewall/firewall_db.py:318 <- First Delete FW database operation
...
2015-08-25 08:34:01.098 31255 ERROR oslo_messaging.rpc.dispatcher [req-9cc36e3b-e209-4d95-bb40-9e1012a89621 ] Exception during message handling: Firewall 2b3102d9-1925-47b3-bca3-a8cd0296cc8c could not be found. <-- Second Delete FW throw exception
2015-08-25 08:34:01.098 31255 TRACE oslo_messaging.rpc.dispatcher Traceback (most recent call last):
2015-08-25 08:34:01.098 31255 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply
2015-08-25 08:34:01.098 31255 TRACE oslo_messaging.rpc.dispatcher executor_callback))
2015-08-25 08:34:01.098 31255 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch
2015-08-25 08:34:01.098 31255 TRACE oslo_messaging.rpc.dispatcher executor_callback)
2015-08-25 08:34:01.098 31255 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 130, in _do_dispatch
2015-08-25 08:34:01.098 31255 TRACE oslo_messaging.rpc.dispatcher result = func(ctxt, **new_args)
2015-08-25 08:34:01.098 31255 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron_fwaas/services/firewall/fwaas_plugin.py", line 67, in firewall_deleted
2015-08-25 08:34:01.098 31255 TRACE oslo_messaging.rpc.dispatcher fw_db = self.plugin._get_firewall(context, firewall_id)
2015-08-25 08:34:01.098 31255 TRACE oslo_messaging.rpc.dispatcher File "/usr/lib/python2.7/site-packages/neutron_fwaas/db/firewall/firewall_db.py", line 101, in _get_firewall
2015-08-25 08:34:01.098 31255 TRACE oslo_messaging.rpc.dispatcher raise fw_ext.FirewallNotFound(firewall_id=id)
2015-08-25 08:34:01.098 31255 TRACE oslo_messaging.rpc.dispatcher FirewallNotFound: Firewall 2b3102d9-1925-47b3-bca3-a8cd0296cc8c could not be found.
2015-08-25 08:34:01.098 31255 TRACE oslo_messaging.rpc.dispatcher
2015-08-25 08:34:01.098 31255 ERROR oslo_messaging._drivers.common [req-9cc36e3b-e209-4d95-bb40-9e1012a89621 ] Returning exception Firewall 2b3102d9-1925-47b3-bca3-a8cd0296cc8c could not be found. to caller
2015-08-25 08:34:01.099 31255 ERROR oslo_messaging._drivers.common [req-9cc36e3b-e209-4d95-bb40-9e1012a89621 ] ['Traceback (most recent call last):\n', ' File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply\n executor_callback))\n', ' File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch\n executor_callback)\n', ' File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 130, in _do_dispatch\n result = func(ctxt, **new_args)\n', ' File "/usr/lib/python2.7/site-packages/neutron_fwaas/services/firewall/fwaas_plugin.py", line 67, in firewall_deleted\n fw_db = self.plugin._get_firewall(context, firewall_id)\n', ' File "/usr/lib/python2.7/site-packages/neutron_fwaas/db/firewall/firewall_db.py", line 101, in _get_firewall\n raise fw_ext.FirewallNotFound(firewall_id=id)\n', 'FirewallNotFound: Firewall 2b3102d9-1925-47b3-bca3-a8cd0296cc8c could not be found.\n']
This bug is > 240 days without activity. We are unsetting assignee and milestone and setting status to Incomplete in order to allow its expiry in 60 days.
If the bug is still valid, then update the bug status.