yahoo-eng-team team mailing list archive

Thread
Date
[Bug 2073567] Re: [master][ml2-ovn] Multiple Unexpected exception in notify_loop: neutron_lib.exceptions.PortNotFound

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: OpenStack Infra <2073567@xxxxxxxxxxxxxxxxxx>
Date: Wed, 31 Jul 2024 08:18:02 -0000
Reply-to: Bug 2073567 <2073567@xxxxxxxxxxxxxxxxxx>
Sender: noreply@xxxxxxxxxxxxx
Reviewed:  https://review.opendev.org/c/openstack/neutron/+/925039
Committed: https://opendev.org/openstack/neutron/commit/c1b88fc5f52283380261f4fdc1562ff56ea06a29
Submitter: "Zuul (22348)"
Branch:    master

commit c1b88fc5f52283380261f4fdc1562ff56ea06a29
Author: Miro Tomaska <mtomaska@xxxxxxxxxx>
Date:   Fri Jul 26 10:50:40 2024 -0400

    Only query for port do not get directly
    
    It was observed in the tempest tests that the port could be already
    deleted by some other concurrent event when the `run` is called.
    This caused a flood of exception logs. Thus, with this patch we only
    query for the port and only update_router_port when the port was
    found.
    
    Closes-Bug: #2073567
    Change-Id: I54d027f7cb5014d296a99029cfa0a13a7800da0a


** Changed in: neutron
       Status: In Progress => Fix Released

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/2073567

Title:
  [master][ml2-ovn] Multiple Unexpected exception in notify_loop:
  neutron_lib.exceptions.PortNotFound

Status in neutron:
  Fix Released

Bug description:
  Multiple traces can be seen in ovn job like below:-
  Jul 18 19:35:46.623330 np0038010972 neutron-server[84540]: WARNING neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.ovn_client [None req-fbcd2914-d4f5-4f87-a685-96f16cc4f5f2 None None] No port found with ID 40c61c6b-8569-4bbd-a71d-4bf9a0917d19: RuntimeError: No port found with ID 40c61c6b-8569-4bbd-a71d-4bf9a0917d19
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event [None req-fbcd2914-d4f5-4f87-a685-96f16cc4f5f2 None None] Unexpected exception in notify_loop: neutron_lib.exceptions.PortNotFound: Port 40c61c6b-8569-4bbd-a71d-4bf9a0917d19 could not be found.
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event Traceback (most recent call last):
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/neutron/neutron/db/db_base_plugin_common.py", line 295, in _get_port
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     port = model_query.get_by_id(context, models_v2.Port, id,
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/model_query.py", line 178, in get_by_id
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return query.filter(model.id == object_id).one()
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/query.py", line 2778, in one
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return self._iter().one()  # type: ignore
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/engine/result.py", line 1810, in one
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return self._only_one_row(
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/engine/result.py", line 752, in _only_one_row
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     raise exc.NoResultFound(
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event sqlalchemy.exc.NoResultFound: No row was found when one was required
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event 
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event During handling of the above exception, another exception occurred:
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event 
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event Traceback (most recent call last):
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/ovsdbapp/event.py", line 177, in notify_loop
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     match.run(event, row, updates)
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovsdb_monitor.py", line 581, in run
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     port = self.driver._plugin.get_port(self.admin_context, row.name)
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 223, in wrapped
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return f_with_retry(*args, **kwargs,
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 137, in wrapped
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     with excutils.save_and_reraise_exception():
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 227, in __exit__
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     self.force_reraise()
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 200, in force_reraise
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     raise self.value
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 135, in wrapped
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return f(*args, **kwargs)
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/api.py", line 144, in wrapper
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     with excutils.save_and_reraise_exception() as ectxt:
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 227, in __exit__
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     self.force_reraise()
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 200, in force_reraise
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     raise self.value
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/api.py", line 142, in wrapper
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return f(*args, **kwargs)
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 183, in wrapped
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     with excutils.save_and_reraise_exception():
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 227, in __exit__
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     self.force_reraise()
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 200, in force_reraise
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     raise self.value
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 181, in wrapped
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return f(*dup_args, **dup_kwargs)
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 998, in wrapper
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return fn(*args, **kwargs)
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/neutron/neutron/db/db_base_plugin_v2.py", line 1626, in get_port
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     port = self._get_port(context, id, lazy_fields=lazy_fields)
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 998, in wrapper
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return fn(*args, **kwargs)
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/neutron/neutron/db/db_base_plugin_common.py", line 298, in _get_port
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     raise exceptions.PortNotFound(port_id=id)
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event neutron_lib.exceptions.PortNotFound: Port 40c61c6b-8569-4bbd-a71d-4bf9a0917d19 could not be found.
  Jul 18 19:35:46.630294 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event 
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event [None req-fbcd2914-d4f5-4f87-a685-96f16cc4f5f2 None None] Unexpected exception in notify_loop: neutron_lib.exceptions.PortNotFound: Port 40c61c6b-8569-4bbd-a71d-4bf9a0917d19 could not be found.
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event Traceback (most recent call last):
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/neutron/neutron/db/db_base_plugin_common.py", line 295, in _get_port
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     port = model_query.get_by_id(context, models_v2.Port, id,
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/model_query.py", line 178, in get_by_id
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return query.filter(model.id == object_id).one()
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/orm/query.py", line 2778, in one
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return self._iter().one()  # type: ignore
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/engine/result.py", line 1810, in one
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return self._only_one_row(
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/sqlalchemy/engine/result.py", line 752, in _only_one_row
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     raise exc.NoResultFound(
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event sqlalchemy.exc.NoResultFound: No row was found when one was required
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event 
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event During handling of the above exception, another exception occurred:
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event 
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event Traceback (most recent call last):
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/ovsdbapp/event.py", line 177, in notify_loop
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     match.run(event, row, updates)
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovsdb_monitor.py", line 581, in run
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     port = self.driver._plugin.get_port(self.admin_context, row.name)
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 223, in wrapped
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return f_with_retry(*args, **kwargs,
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 137, in wrapped
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     with excutils.save_and_reraise_exception():
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 227, in __exit__
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     self.force_reraise()
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 200, in force_reraise
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     raise self.value
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 135, in wrapped
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return f(*args, **kwargs)
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/api.py", line 144, in wrapper
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     with excutils.save_and_reraise_exception() as ectxt:
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 227, in __exit__
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     self.force_reraise()
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 200, in force_reraise
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     raise self.value
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/api.py", line 142, in wrapper
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return f(*args, **kwargs)
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 183, in wrapped
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     with excutils.save_and_reraise_exception():
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 227, in __exit__
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     self.force_reraise()
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 200, in force_reraise
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     raise self.value
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/neutron_lib/db/api.py", line 181, in wrapped
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return f(*dup_args, **dup_kwargs)
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 998, in wrapper
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return fn(*args, **kwargs)
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/neutron/neutron/db/db_base_plugin_v2.py", line 1626, in get_port
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     port = self._get_port(context, id, lazy_fields=lazy_fields)
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 998, in wrapper
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     return fn(*args, **kwargs)
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event   File "/opt/stack/neutron/neutron/db/db_base_plugin_common.py", line 298, in _get_port
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event     raise exceptions.PortNotFound(port_id=id)
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event neutron_lib.exceptions.PortNotFound: Port 40c61c6b-8569-4bbd-a71d-4bf9a0917d19 could not be found.
  Jul 18 19:35:46.637822 np0038010972 neutron-server[84540]: ERROR ovsdbapp.event 

  Sample Log:-
  https://f3720cbaa64e3cd59c51-f4d168cdb20f40841821e4b213645c0f.ssl.cf5.rackcdn.com/907313/25/check/neutron-
  tempest-plugin-ovn/9a6e468/controller/logs/screen-q-svc.txt

  Can be seen any run of job neutron-tempest-plugin-ovn

  
  Would be good to avoid polluting logs with such traces when port is no longer available. Only affects master as included as part of addition of new event in https://review.opendev.org/c/openstack/neutron/+/912349

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/2073567/+subscriptions
References

[Bug 2073567] [NEW] [master][ml2-ovn] Multiple Unexpected exception in notify_loop: neutron_lib.exceptions.PortNotFound
From: yatin, 2024-07-19