yahoo-eng-team team mailing list archive

Thread
Date
[Bug 2024630] [NEW] Neutron server log full of Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]: WARNING neutron.objects.base [-] ORM session: SQL execution without transaction in progress, traceback:

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Miguel Lavalle <2024630@xxxxxxxxxxxxxxxxxx>
Date: Thu, 22 Jun 2023 00:25:10 -0000
Reply-to: Bug 2024630 <2024630@xxxxxxxxxxxxxxxxxx>
Sender: noreply@xxxxxxxxxxxxx
Public bug reported:

In the neutron-tempest-plugin-ovn job, the neutron server log is full of
the following error:

Jun 16 12:44:13.388278 np0034319125 neutron-server[83462]: DEBUG neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.ovsdb_monitor [None req-7cbd9fa8-94fb-4740-b7e9-afa577da1f57 None None] ChassisMetadataAgentWriteEvent : Matched Chassis_Private, update, None None {{(pid=83462) matches /opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovsdb_monitor.py:63}}
Jun 16 12:44:13.388451 np0034319125 neutron-server[83463]: DEBUG neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.ovsdb_monitor [None req-d2439ba0-25a6-419e-a0a4-c213f125a947 None None] ChassisMetadataAgentWriteEvent : Matched Chassis_Private, update, None None {{(pid=83463) matches /opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovsdb_monitor.py:63}}
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]: WARNING neutron.objects.base [-] ORM session: SQL execution without transaction in progress, traceback:
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/eventlet/green/thread.py", line 43, in __thread_body
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     func(*args, **kwargs)
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/lib/python3.10/threading.py", line 973, in _bootstrap
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self._bootstrap_inner()
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/eventlet/green/thread.py", line 64, in wrap_bootstrap_inner
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     bootstrap_inner()
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self.run()
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/lib/python3.10/threading.py", line 953, in run 
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self._target(*self._args, **self._kwargs)
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/ovsdbapp/backend/ovs_idl/connection.py", line 107, in run 
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self.idl.run()
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/ovs/db/idl.py", line 464, in run 
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self.__parse_update(msg.params[2], OVSDB_UPDATE3)
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/ovs/db/idl.py", line 891, in __parse_update
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self.__do_parse_update(update, version, self.tables)
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/ovs/db/idl.py", line 951, in __do_parse_update
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self.notify(*notice)
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovsdb_monitor.py", line 727, in notify 
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     target_node = self._hash_ring.get_node(str(row.uuid))
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/opt/stack/neutron/neutron/common/ovn/hash_ring_manager.py", line 106, in get_node
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self._load_hash_ring()
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/opt/stack/neutron/neutron/common/ovn/hash_ring_manager.py", line 90, in _load_hash_ring
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     nodes = db_hash_ring.get_active_nodes(
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/opt/stack/neutron/neutron/db/ovn_hash_ring_db.py", line 88, in get_active_nodes
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     return query.all()
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/query.py", line 2772, in all 
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     return self._iter().all()
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/query.py", line 2907, in _iter
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     result = self.session.execute(
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/session.py", line 1693, in execute
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     result = fn(orm_exec_state)
Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]: 


It seems the problem starts showing with the merge of https://review.opendev.org/c/openstack/neutron/+/886005. The next change to merge was https://review.opendev.org/c/openstack/neutron/+/885744 and also shows the problem

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

Title:
  Neutron server log full of Jun 16 12:44:13.388637 np0034319125
  neutron-server[83465]: WARNING neutron.objects.base [-] ORM session:
  SQL execution without transaction in progress, traceback:

Status in neutron:
  New

Bug description:
  In the neutron-tempest-plugin-ovn job, the neutron server log is full
  of the following error:

  Jun 16 12:44:13.388278 np0034319125 neutron-server[83462]: DEBUG neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.ovsdb_monitor [None req-7cbd9fa8-94fb-4740-b7e9-afa577da1f57 None None] ChassisMetadataAgentWriteEvent : Matched Chassis_Private, update, None None {{(pid=83462) matches /opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovsdb_monitor.py:63}}
  Jun 16 12:44:13.388451 np0034319125 neutron-server[83463]: DEBUG neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.ovsdb_monitor [None req-d2439ba0-25a6-419e-a0a4-c213f125a947 None None] ChassisMetadataAgentWriteEvent : Matched Chassis_Private, update, None None {{(pid=83463) matches /opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovsdb_monitor.py:63}}
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]: WARNING neutron.objects.base [-] ORM session: SQL execution without transaction in progress, traceback:
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/eventlet/green/thread.py", line 43, in __thread_body
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     func(*args, **kwargs)
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/lib/python3.10/threading.py", line 973, in _bootstrap
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self._bootstrap_inner()
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/eventlet/green/thread.py", line 64, in wrap_bootstrap_inner
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     bootstrap_inner()
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self.run()
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/lib/python3.10/threading.py", line 953, in run 
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self._target(*self._args, **self._kwargs)
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/ovsdbapp/backend/ovs_idl/connection.py", line 107, in run 
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self.idl.run()
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/ovs/db/idl.py", line 464, in run 
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self.__parse_update(msg.params[2], OVSDB_UPDATE3)
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/ovs/db/idl.py", line 891, in __parse_update
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self.__do_parse_update(update, version, self.tables)
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/ovs/db/idl.py", line 951, in __do_parse_update
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self.notify(*notice)
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/opt/stack/neutron/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovsdb_monitor.py", line 727, in notify 
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     target_node = self._hash_ring.get_node(str(row.uuid))
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/opt/stack/neutron/neutron/common/ovn/hash_ring_manager.py", line 106, in get_node
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     self._load_hash_ring()
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/opt/stack/neutron/neutron/common/ovn/hash_ring_manager.py", line 90, in _load_hash_ring
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     nodes = db_hash_ring.get_active_nodes(
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/opt/stack/neutron/neutron/db/ovn_hash_ring_db.py", line 88, in get_active_nodes
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     return query.all()
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/query.py", line 2772, in all 
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     return self._iter().all()
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/query.py", line 2907, in _iter
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     result = self.session.execute(
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:   File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/session.py", line 1693, in execute
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]:     result = fn(orm_exec_state)
  Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]: 

  
  It seems the problem starts showing with the merge of https://review.opendev.org/c/openstack/neutron/+/886005. The next change to merge was https://review.opendev.org/c/openstack/neutron/+/885744 and also shows the problem

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

[Bug 2024630] Re: Neutron server log full of Jun 16 12:44:13.388637 np0034319125 neutron-server[83465]: WARNING neutron.objects.base [-] ORM session: SQL execution without transaction in progress, traceback:
From: Miguel Lavalle, 2023-06-22