yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1933638] [NEW] neutronclient returns Conflict on security group rules delete

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Gregory Thiemonge <1933638@xxxxxxxxxxxxxxxxxx>
Date: Fri, 25 Jun 2021 09:55:17 -0000
Reply-to: Bug 1933638 <1933638@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

This issue was caught in an Octavia CI job
(https://zuul.opendev.org/t/openstack/build/9cb24aa49cbb47e6abeb580e5d5ec6f0/logs)

During the deletion of a load balancer, Octavia deletes security group
rules in neutron. It seems that Octavia is trying to delete many times
the same security group rule, and it sometimes receives a Conflict
exception while the exception message explains that the security group
rule doesn't exist:


Jun 22 12:36:00.226969 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88368]: INFO neutron.wsgi [None req-e2baf119-3462-4af0-8b08-1e35cf0ba6d2 admin admin] 199.19.213.147,199.19.213.147 "DELETE /v2.0/security-group-rules/ec7d4cb6-a872-4709-854a-efaca7527822 HTTP/1.1" status: 204  len: 173 time: 0.0580175
Jun 22 12:36:00.228298 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88367]: INFO neutron.api.v2.resource [None req-42ecd2c1-85d8-4ea6-b9ec-b98af458a8aa admin admin] delete failed (client error): The resource could not be found.
Jun 22 12:36:00.229361 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88367]: INFO neutron.wsgi [None req-42ecd2c1-85d8-4ea6-b9ec-b98af458a8aa admin admin] 199.19.213.147,199.19.213.147 "DELETE /v2.0/security-group-rules/ec7d4cb6-a872-4709-854a-efaca7527822 HTTP/1.1" status: 404  len: 361 time: 0.0507255
Jun 22 12:36:00.230639 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88368]: DEBUG neutron.api.rpc.handlers.resources_rpc [None req-e2baf119-3462-4af0-8b08-1e35cf0ba6d2 admin admin] Pushing event deleted for resources: {'SecurityGroupRule': ['ID=ec7d4cb6-a872-4709-854a-efaca7527822,revision_number=None']} {{(pid=88368) push /opt/stack/neutron/neutron/api/rpc/handlers/resources_rpc.py:237}}
Jun 22 12:36:00.230973 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88367]: DEBUG neutron_lib.callbacks.manager [None req-92d0b84a-6fce-40e8-8c6c-f08c4c362481 admin admin] Callback neutron.plugins.ml2.drivers.ovn.mech_driver.mech_driver.OVNMechanismDriver._process_sg_rule_notification-750270 raised Security group rule ec7d4cb6-a872-4709-854a-efaca7527822 does not exist {{(pid=88367) _notify_loop /usr/local/lib/python3.8/dist-packages/neutron_lib/callbacks/manager.py:209}}
Jun 22 12:36:00.231248 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88367]: DEBUG neutron_lib.callbacks.manager [None req-92d0b84a-6fce-40e8-8c6c-f08c4c362481 admin admin] Notify callbacks [] for security_group_rule, abort_delete {{(pid=88367) _notify_loop /usr/local/lib/python3.8/dist-packages/neutron_lib/callbacks/manager.py:192}}
Jun 22 12:36:00.231444 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88368]: DEBUG oslo_concurrency.lockutils [None req-e2baf119-3462-4af0-8b08-1e35cf0ba6d2 admin admin] Lock "event-dispatch" released by "neutron.plugins.ml2.ovo_rpc._ObjectChangeHandler.dispatch_events" :: held 0.008s {{(pid=88368) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:367}}
Jun 22 12:36:00.231819 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88367]: INFO neutron.api.v2.resource [None req-92d0b84a-6fce-40e8-8c6c-f08c4c362481 admin admin] delete failed (client error): There was a conflict when trying to complete your request.
Jun 22 12:36:00.232958 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88367]: INFO neutron.wsgi [None req-92d0b84a-6fce-40e8-8c6c-f08c4c362481 admin admin] 199.19.213.147,199.19.213.147 "DELETE /v2.0/security-group-rules/ec7d4cb6-a872-4709-854a-efaca7527822 HTTP/1.1" status: 409  len: 588 time: 0.0547035


In the octavia logs, we received:

Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker Traceback (most recent call last):
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/taskflow/engines/action_engine/executor.py", line 53, in _execute_task
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     result = task.execute(**arguments)
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/opt/stack/octavia/octavia/controller/worker/v1/tasks/network_tasks.py", line 519, in execute
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     self.network_driver.update_vip(loadbalancer, for_delete=True)
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/opt/stack/octavia/octavia/network/drivers/neutron/allowed_address_pairs.py", line 622, in update_vip
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     self._update_security_group_rules(load_balancer,
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/opt/stack/octavia/octavia/network/drivers/neutron/allowed_address_pairs.py", line 207, in _update_security_group_rules
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     self.neutron_client.delete_security_group_rule(rule_id)
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/neutronclient/v2_0/client.py", line 1043, in delete_security_group_rule
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     return self.delete(self.security_group_rule_path %
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/neutronclient/v2_0/client.py", line 352, in delete
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     return self.retry_request("DELETE", action, body=body,
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/neutronclient/v2_0/client.py", line 333, in retry_request
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     return self.do_request(method, action, body=body,
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/neutronclient/v2_0/client.py", line 297, in do_request
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     self._handle_fault_response(status_code, replybody, resp)
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/neutronclient/v2_0/client.py", line 272, in _handle_fault_response
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     exception_handler_v20(status_code, error_body)
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/neutronclient/v2_0/client.py", line 90, in exception_handler_v20
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     raise client_exc(message=error_message,
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker neutronclient.common.exceptions.Conflict: Security Group Rule ec7d4cb6-a872-4709-854a-efaca7527822 cannot perform before_delete due to Callback neutron.plugins.ml2.drivers.ovn.mech_driver.mech_driver.OVNMechanismDriver._process_sg_rule_notification-750270 failed with "Security group rule ec7d4cb6-a872-4709-854a-efaca7527822 does not exist".
Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker Neutron server returns request_ids: ['req-92d0b84a-6fce-40e8-8c6c-f08c4c362481']


I think we should have received a NotFound exception (that we catch in Octavia) instead of this Conflict exception.


This issue has appeared after the switch to ML2/OVN.

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

Title:
  neutronclient returns Conflict on security group rules delete

Status in neutron:
  New

Bug description:
  This issue was caught in an Octavia CI job
  (https://zuul.opendev.org/t/openstack/build/9cb24aa49cbb47e6abeb580e5d5ec6f0/logs)

  During the deletion of a load balancer, Octavia deletes security group
  rules in neutron. It seems that Octavia is trying to delete many times
  the same security group rule, and it sometimes receives a Conflict
  exception while the exception message explains that the security group
  rule doesn't exist:

  
  Jun 22 12:36:00.226969 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88368]: INFO neutron.wsgi [None req-e2baf119-3462-4af0-8b08-1e35cf0ba6d2 admin admin] 199.19.213.147,199.19.213.147 "DELETE /v2.0/security-group-rules/ec7d4cb6-a872-4709-854a-efaca7527822 HTTP/1.1" status: 204  len: 173 time: 0.0580175
  Jun 22 12:36:00.228298 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88367]: INFO neutron.api.v2.resource [None req-42ecd2c1-85d8-4ea6-b9ec-b98af458a8aa admin admin] delete failed (client error): The resource could not be found.
  Jun 22 12:36:00.229361 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88367]: INFO neutron.wsgi [None req-42ecd2c1-85d8-4ea6-b9ec-b98af458a8aa admin admin] 199.19.213.147,199.19.213.147 "DELETE /v2.0/security-group-rules/ec7d4cb6-a872-4709-854a-efaca7527822 HTTP/1.1" status: 404  len: 361 time: 0.0507255
  Jun 22 12:36:00.230639 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88368]: DEBUG neutron.api.rpc.handlers.resources_rpc [None req-e2baf119-3462-4af0-8b08-1e35cf0ba6d2 admin admin] Pushing event deleted for resources: {'SecurityGroupRule': ['ID=ec7d4cb6-a872-4709-854a-efaca7527822,revision_number=None']} {{(pid=88368) push /opt/stack/neutron/neutron/api/rpc/handlers/resources_rpc.py:237}}
  Jun 22 12:36:00.230973 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88367]: DEBUG neutron_lib.callbacks.manager [None req-92d0b84a-6fce-40e8-8c6c-f08c4c362481 admin admin] Callback neutron.plugins.ml2.drivers.ovn.mech_driver.mech_driver.OVNMechanismDriver._process_sg_rule_notification-750270 raised Security group rule ec7d4cb6-a872-4709-854a-efaca7527822 does not exist {{(pid=88367) _notify_loop /usr/local/lib/python3.8/dist-packages/neutron_lib/callbacks/manager.py:209}}
  Jun 22 12:36:00.231248 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88367]: DEBUG neutron_lib.callbacks.manager [None req-92d0b84a-6fce-40e8-8c6c-f08c4c362481 admin admin] Notify callbacks [] for security_group_rule, abort_delete {{(pid=88367) _notify_loop /usr/local/lib/python3.8/dist-packages/neutron_lib/callbacks/manager.py:192}}
  Jun 22 12:36:00.231444 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88368]: DEBUG oslo_concurrency.lockutils [None req-e2baf119-3462-4af0-8b08-1e35cf0ba6d2 admin admin] Lock "event-dispatch" released by "neutron.plugins.ml2.ovo_rpc._ObjectChangeHandler.dispatch_events" :: held 0.008s {{(pid=88368) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:367}}
  Jun 22 12:36:00.231819 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88367]: INFO neutron.api.v2.resource [None req-92d0b84a-6fce-40e8-8c6c-f08c4c362481 admin admin] delete failed (client error): There was a conflict when trying to complete your request.
  Jun 22 12:36:00.232958 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 neutron-server[88367]: INFO neutron.wsgi [None req-92d0b84a-6fce-40e8-8c6c-f08c4c362481 admin admin] 199.19.213.147,199.19.213.147 "DELETE /v2.0/security-group-rules/ec7d4cb6-a872-4709-854a-efaca7527822 HTTP/1.1" status: 409  len: 588 time: 0.0547035


  In the octavia logs, we received:

  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker Traceback (most recent call last):
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/taskflow/engines/action_engine/executor.py", line 53, in _execute_task
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     result = task.execute(**arguments)
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/opt/stack/octavia/octavia/controller/worker/v1/tasks/network_tasks.py", line 519, in execute
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     self.network_driver.update_vip(loadbalancer, for_delete=True)
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/opt/stack/octavia/octavia/network/drivers/neutron/allowed_address_pairs.py", line 622, in update_vip
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     self._update_security_group_rules(load_balancer,
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/opt/stack/octavia/octavia/network/drivers/neutron/allowed_address_pairs.py", line 207, in _update_security_group_rules
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     self.neutron_client.delete_security_group_rule(rule_id)
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/neutronclient/v2_0/client.py", line 1043, in delete_security_group_rule
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     return self.delete(self.security_group_rule_path %
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/neutronclient/v2_0/client.py", line 352, in delete
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     return self.retry_request("DELETE", action, body=body,
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/neutronclient/v2_0/client.py", line 333, in retry_request
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     return self.do_request(method, action, body=body,
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/neutronclient/v2_0/client.py", line 297, in do_request
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     self._handle_fault_response(status_code, replybody, resp)
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/neutronclient/v2_0/client.py", line 272, in _handle_fault_response
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     exception_handler_v20(status_code, error_body)
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker   File "/usr/local/lib/python3.8/dist-packages/neutronclient/v2_0/client.py", line 90, in exception_handler_v20
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker     raise client_exc(message=error_message,
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker neutronclient.common.exceptions.Conflict: Security Group Rule ec7d4cb6-a872-4709-854a-efaca7527822 cannot perform before_delete due to Callback neutron.plugins.ml2.drivers.ovn.mech_driver.mech_driver.OVNMechanismDriver._process_sg_rule_notification-750270 failed with "Security group rule ec7d4cb6-a872-4709-854a-efaca7527822 does not exist".
  Jun 22 12:36:00.263676 nested-virt-ubuntu-focal-vexxhost-ca-ymq-1-0025224760 octavia-worker[127003]: ERROR octavia.controller.worker.v1.controller_worker Neutron server returns request_ids: ['req-92d0b84a-6fce-40e8-8c6c-f08c4c362481']

  
  I think we should have received a NotFound exception (that we catch in Octavia) instead of this Conflict exception.

  
  This issue has appeared after the switch to ML2/OVN.

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

[Bug 1933638] Re: neutron with ovn returns Conflict on security group rules delete
From: OpenStack Infra, 2021-06-30