[ovn] NeutronNetworks.create_and_delete_subnets failing in concurrent scenario

Bug #1939924 reported by Krzysztof Klimonda
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
neutron
Confirmed
High
Unassigned

Bug Description

This seems to be basically the same bug as https://bugs.launchpad.net/neutron/+bug/1890432 but with https://review.opendev.org/c/openstack/neutron/+/774256 applied, this is why I'm reporting a new bug instead.

This test has been done with neutron stable/ussuri checkout from 20210721.

Tested via rally task:

--8<--8<--8<--
  NeutronNetworks.create_and_delete_subnets:
    -
      args:
        network_create_args: {}
        subnet_create_args: {}
        subnet_cidr_start: "1.1.0.0/30"
        subnets_per_network: 2
      runner:
        type: "constant"
        times: 100
        concurrency: 10
      context:
        network: {}
        users:
          tenants: 3
          users_per_tenant: 3
        quotas:
          neutron:
            network: -1
            subnet: -1
      sla:
        failure_rate:
          max: 0
--8<--8<--8<--

Received client error:

--8<--8<--8<--
Conflict: Unable to complete operation on subnet 40b18ea7-332a-4010-b28b-4629950c1018: This subnet is being modified by another concurrent operation.
Neutron server returns request_ids: ['req-81825765-e76e-4cc5-9341-1a0134dfb548']

Traceback (most recent call last):
  File "/home/kklimonda/rally/lib/python3.8/site-packages/rally/task/runner.py", line 69, in _run_scenario_once
    getattr(scenario_inst, method_name)(**scenario_kwargs)
  File "/home/kklimonda/rally/lib/python3.8/site-packages/rally_openstack/task/scenarios/neutron/network.py", line 287, in run
    self.neutron.create_subnet(
  File "/home/kklimonda/rally/lib/python3.8/site-packages/rally/task/service.py", line 114, in wrapper
    return func(instance, *args, **kwargs)
  File "/home/kklimonda/rally/lib/python3.8/site-packages/rally/task/atomic.py", line 91, in func_atomic_actions
    f = func(self, *args, **kwargs)
  File "/home/kklimonda/rally/lib/python3.8/site-packages/rally_openstack/common/services/network/neutron.py", line 500, in create_subnet
    subnet = self.client.create_subnet({"subnet": body})["subnet"]
  File "/home/kklimonda/rally/lib/python3.8/site-packages/neutronclient/v2_0/client.py", line 875, in create_subnet
    return self.post(self.subnets_path, body=body)
  File "/home/kklimonda/rally/lib/python3.8/site-packages/neutronclient/v2_0/client.py", line 357, in post
    return self.do_request("POST", action, body=body,
  File "/home/kklimonda/rally/lib/python3.8/site-packages/neutronclient/v2_0/client.py", line 293, in do_request
    self._handle_fault_response(status_code, replybody, resp)
  File "/home/kklimonda/rally/lib/python3.8/site-packages/neutronclient/v2_0/client.py", line 268, in _handle_fault_response
    exception_handler_v20(status_code, error_body)
  File "/home/kklimonda/rally/lib/python3.8/site-packages/neutronclient/v2_0/client.py", line 90, in exception_handler_v20
    raise client_exc(message=error_message,
neutronclient.common.exceptions.Conflict: Unable to complete operation on subnet 40b18ea7-332a-4010-b28b-4629950c1018: This subnet is being modified by another concurrent operation.
Neutron server returns request_ids: ['req-81825765-e76e-4cc5-9341-1a0134dfb548']
--8<--8<--8<--

A full traceback from the server (see patched codepath being used):

--8<--8<--8<--
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers [req-81825765-e76e-4cc5-9341-1a0134dfb548 51af4596cc71466e8cc1fadfb0bd40e9 ea4728cc4d874703bb024d49ea2472a6 - default default] Mechanism driver 'ovn' failed in create_subnet_postcommit: neutron_lib.exceptions.SubnetInUse: Unable to complete operation on subnet 40b18ea7-332a-4010-b28b-4629950c1018: This subnet is being modified by another concurrent operation.
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers Traceback (most recent call last):
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/plugins/ml2/managers.py", line 477, in _call_on_drivers
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers getattr(driver.obj, method_name)(context)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/plugins/ml2/drivers/ovn/mech_driver/mech_driver.py", line 504, in create_subnet_postcommit
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers context.network.current)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovn_client.py", line 1979, in create_subnet
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers subnet_id=subnet['id'])
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovn_client.py", line 2148, in update_metadata_port
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers update_metadata_port_fixed_ips(metadata_port, [subnet_id])
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovn_client.py", line 2128, in update_metadata_port_fixed_ips
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers metadata_port['id'], port)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/common/utils.py", line 681, in inner
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers return f(self, context, *args, **kwargs)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron_lib/db/api.py", line 233, in wrapped
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers return method(*args, **kwargs)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron_lib/db/api.py", line 139, in wrapped
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers setattr(e, '_RETRY_EXCEEDED', True)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers self.force_reraise()
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers six.reraise(self.type_, self.value, self.tb)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/six.py", line 703, in reraise
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers raise value
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron_lib/db/api.py", line 135, in wrapped
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers return f(*args, **kwargs)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_db/api.py", line 154, in wrapper
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers ectxt.value = e.inner_exc
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers self.force_reraise()
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers six.reraise(self.type_, self.value, self.tb)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/six.py", line 703, in reraise
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers raise value
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_db/api.py", line 142, in wrapper
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers return f(*args, **kwargs)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron_lib/db/api.py", line 183, in wrapped
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers LOG.debug("Retry wrapper got retriable exception: %s", e)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers self.force_reraise()
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers six.reraise(self.type_, self.value, self.tb)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/six.py", line 703, in reraise
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers raise value
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron_lib/db/api.py", line 179, in wrapped
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers return f(*dup_args, **dup_kwargs)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/plugins/ml2/plugin.py", line 1653, in update_port
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers db_port=port_db)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron_lib/db/api.py", line 233, in wrapped
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers return method(*args, **kwargs)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/db/db_base_plugin_v2.py", line 1495, in update_port
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers new_port=new_port)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/db/ipam_backend_mixin.py", line 716, in update_port
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers new_port.get('mac_address'))
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/db/ipam_pluggable_backend.py", line 431, in update_port_with_ips
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers new_mac)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/db/ipam_pluggable_backend.py", line 354, in _update_ips_for_port
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers distributed_service=self._is_distributed_service(port))
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/db/ipam_backend_mixin.py", line 671, in _ipam_get_subnets
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers id=subnet.id)
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/db/models_v2.py", line 55, in lock_register
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers raise exception
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers neutron_lib.exceptions.SubnetInUse: Unable to complete operation on subnet 40b18ea7-332a-4010-b28b-4629950c1018: This subnet is being modified by another concurrent operation.
2021-08-13 21:39:44.465 698 ERROR neutron.plugins.ml2.managers
2021-08-13 21:39:44.469 698 ERROR neutron.plugins.ml2.plugin [req-81825765-e76e-4cc5-9341-1a0134dfb548 51af4596cc71466e8cc1fadfb0bd40e9 ea4728cc4d874703bb024d49ea2472a6 - default default] mechanism_manager.create_subnet_postcommit failed, deleting subnet 'ff7564ee-2fd5-47f4-98f7-d2848dbff3cc': neutron.plugins.ml2.common.exceptions.MechanismDriverError
--8<--8<--8<--

Revision history for this message
Krzysztof Klimonda (kklimonda) wrote :

Interestingly, when reading https://bugs.launchpad.net/neutron/+bug/1890432 there is seemingly no actual validation that the proposed fix works: Comment #14 asks for the test of the (currently merged) review https://review.opendev.org/745330 but comment #15 is explicit that with this patch applied the failure is still present, but this comment is seemingly lost in the subsequent discussion of merges and backports. I'm assuming it wasn't actually fixed at all, and so the original High priority bug should be re-opened instead, or this bug's priority should be set to High to match it?

Miguel Lavalle (minsel)
Changed in neutron:
importance: Undecided → Medium
importance: Medium → High
status: New → Confirmed
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.