neutron

neutron-loki job fails tests with ORM session: SQL execution without transaction in progress

Bug #2017131 reported by yatin on 2023-04-20

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	neutron	Fix Released	Medium	Rodolfo Alonso

Bug Description

Job(neutron-ovn-tempest-with-uwsgi-loki) running neutron-loki service[1] fails tempest tests randomly with Tracebacks like below:-

ORM session: SQL execution without transaction in progress, traceback:
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/eventlet/greenthread.py", line 221, in main
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: result = function(*args, **kwargs)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/eventlet/wsgi.py", line 837, in process_request
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: proto.__init__(conn_state, self)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/eventlet/wsgi.py", line 350, in __init__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: self.handle()
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/eventlet/wsgi.py", line 383, in handle
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: self.handle_one_request()
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/eventlet/wsgi.py", line 459, in handle_one_request
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: self.handle_one_response()
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/eventlet/wsgi.py", line 569, in handle_one_response
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: result = self.application(self.environ, start_response)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/paste/urlmap.py", line 216, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: return app(environ, start_response)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 129, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: resp = self.call_func(req, *args, **kw)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 193, in call_func
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: return self.func(req, *args, **kwargs)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/oslo_middleware/base.py", line 124, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: response = req.get_response(self.application)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/request.py", line 1313, in send
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: status, headers, app_iter = self.call_application(
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/request.py", line 1278, in call_application
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: app_iter = application(self.environ, start_response)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 129, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: resp = self.call_func(req, *args, **kw)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 193, in call_func
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: return self.func(req, *args, **kwargs)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/oslo_middleware/base.py", line 124, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: response = req.get_response(self.application)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/request.py", line 1313, in send
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: status, headers, app_iter = self.call_application(
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/request.py", line 1278, in call_application
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: app_iter = application(self.environ, start_response)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 129, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: resp = self.call_func(req, *args, **kw)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 193, in call_func
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: return self.func(req, *args, **kwargs)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/oslo_middleware/request_id.py", line 58, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: response = req.get_response(self.application)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/request.py", line 1313, in send
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: status, headers, app_iter = self.call_application(
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/request.py", line 1278, in call_application
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: app_iter = application(self.environ, start_response)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 129, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: resp = self.call_func(req, *args, **kw)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 193, in call_func
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: return self.func(req, *args, **kwargs)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/oslo_middleware/catch_errors.py", line 40, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: response = req.get_response(self.application)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/request.py", line 1313, in send
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: status, headers, app_iter = self.call_application(
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/request.py", line 1278, in call_application
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: app_iter = application(self.environ, start_response)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 129, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: resp = self.call_func(req, *args, **kw)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 193, in call_func
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: return self.func(req, *args, **kwargs)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/osprofiler/web.py", line 111, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: return request.get_response(self.application)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/request.py", line 1313, in send
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: status, headers, app_iter = self.call_application(
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/request.py", line 1278, in call_application
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: app_iter = application(self.environ, start_response)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 129, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: resp = self.call_func(req, *args, **kw)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 193, in call_func
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: return self.func(req, *args, **kwargs)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/keystonemiddleware/auth_token/__init__.py", line 340, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: response = req.get_response(self._app)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/request.py", line 1313, in send
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: status, headers, app_iter = self.call_application(
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/request.py", line 1278, in call_application
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: app_iter = application(self.environ, start_response)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 143, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: return resp(environ, start_response)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 143, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: return resp(environ, start_response)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/routes/middleware.py", line 153, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: response = self.app(environ, start_response)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 143, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: return resp(environ, start_response)
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 129, in __call__
Apr 17 12:12:44.386611 np0033759257 neutron-server[57996]: resp = self.call_func(req, *args, **kw)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/webob/dec.py", line 193, in call_func
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return self.func(req, *args, **kwargs)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/opt/stack/neutron/neutron/api/v2/resource.py", line 98, in resource
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: result = method(request=request, **args)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/opt/stack/neutron/neutron/api/v2/base.py", line 438, in create
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return self._create(request, body, **kwargs)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/neutron_lib/db/api.py", line 138, in wrapped
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return f(*args, **kwargs)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/oslo_db/api.py", line 142, in wrapper
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return f(*args, **kwargs)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/neutron_lib/db/api.py", line 184, in wrapped
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return f(*dup_args, **dup_kwargs)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/opt/stack/neutron/neutron/api/v2/base.py", line 563, in _create
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: obj = do_create(body)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/opt/stack/neutron/neutron/api/v2/base.py", line 537, in do_create
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return obj_creator(request.context, **kwargs)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/opt/stack/neutron/neutron/services/ovn_l3/plugin.py", line 181, in create_router
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: router = super(OVNL3RouterPlugin, self).create_router(context, router)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/opt/stack/neutron/neutron/db/l3_db.py", line 2182, in create_router
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: router_dict = super(L3_NAT_db_mixin, self).create_router(context,
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/neutron_lib/db/api.py", line 226, in wrapped
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return f_with_retry(*args, **kwargs,
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/neutron_lib/db/api.py", line 138, in wrapped
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return f(*args, **kwargs)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/oslo_db/api.py", line 142, in wrapper
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return f(*args, **kwargs)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/neutron_lib/db/api.py", line 184, in wrapped
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return f(*dup_args, **dup_kwargs)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/opt/stack/neutron/neutron/db/l3_db.py", line 296, in create_router
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: router_db, _unused = db_utils.safe_creation(context, create,
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/opt/stack/neutron/neutron/db/_utils.py", line 67, in safe_creation
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: obj = create_fn()
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/opt/stack/neutron/neutron/db/l3_db.py", line 255, in _create_router_db
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: registry.publish(resources.ROUTER, events.PRECOMMIT_CREATE, self,
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/neutron_lib/callbacks/registry.py", line 54, in publish
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: _get_callback_manager().publish(resource, event, trigger, payload=payload)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/neutron_lib/db/utils.py", line 104, in _wrapped
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return function(*args, **kwargs)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/neutron_lib/callbacks/manager.py", line 150, in publish
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: errors = self._notify_loop(resource, event, trigger, payload)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/neutron_lib/callbacks/manager.py", line 181, in _notify_loop
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: callback(resource, event, trigger, payload=payload)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/opt/stack/neutron/neutron/services/ovn_l3/plugin.py", line 176, in create_router_precommit
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: db_rev.create_initial_revision(
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/neutron_lib/db/api.py", line 226, in wrapped
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return f_with_retry(*args, **kwargs,
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/neutron_lib/db/api.py", line 138, in wrapped
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return f(*args, **kwargs)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/oslo_db/api.py", line 142, in wrapper
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return f(*args, **kwargs)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/neutron_lib/db/api.py", line 184, in wrapped
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return f(*dup_args, **dup_kwargs)
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/opt/stack/neutron/neutron/db/ovn_revision_numbers_db.py", line 112, in create_initial_revision
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: std_attr_id = std_attr_id or _get_standard_attr_id(
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/opt/stack/neutron/neutron/db/ovn_revision_numbers_db.py", line 98, in _get_standard_attr_id
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: id=resource_uuid).one()
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/query.py", line 2869, in one
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: return self._iter().one()
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/query.py", line 2907, in _iter
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: result = self.session.execute(
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: File "/usr/local/lib/python3.10/dist-packages/sqlalchemy/orm/session.py", line 1693, in execute
Apr 17 12:12:44.402712 np0033759257 neutron-server[57996]: result = fn(orm_exec_state)

The job is not running from last couple of releases due to missconfig caused in [2], the issue noticed when the job was reenabled[3], also looking previous build history it was not green since 08-12-2020[4]. The issue is seen in ovs job too[5]

The bug is to track the issue fix.

[1] https://docs.openstack.org/neutron/latest//contributor/testing/db_transient_failure_injection.html
[2] https://review.opendev.org/c/openstack/neutron/+/797051
[3] https://review.opendev.org/c/openstack/neutron/+/880586
[4] https://zuul.openstack.org/builds?job_name=neutron-tempest-with-uwsgi-loki&result=SUCCESS&skip=0
[5] https://zuul.opendev.org/t/openstack/build/78c1dc4eff424b0c8bdc8b6d1f7dcfc4

Revision history for this message

Rodolfo Alonso (rodolfo-alonso-hernandez) wrote on 2023-04-24:

Related patch: https://review.opendev.org/c/openstack/neutron/+/881395

In a future patch, the exception raised by "_get_standard_attr_id", should be added to the "is_retriable" list. If the resource is not created, neither is the standard attribute register thus this method will fail. However, this exception is not covered in this list.

Rodolfo Alonso (rodolfo-alonso-hernandez) on 2023-04-25

Changed in neutron:
assignee:	nobody → Rodolfo Alonso (rodolfo-alonso-hernandez)
importance:	Undecided → Medium

yatin (yatinkarel) on 2023-04-25

Changed in neutron:
status:	New → Confirmed

OpenStack Infra (hudson-openstack) on 2023-04-25

Changed in neutron:
status:	Confirmed → In Progress

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-05-04: Fix merged to neutron (master)

Reviewed: https://review.opendev.org/c/openstack/neutron/+/881459
Committed: https://opendev.org/openstack/neutron/commit/dd184c5c10e3311ceaffd2cde8d66f76aadaebac
Submitter: "Zuul (22348)"
Branch: master

commit dd184c5c10e3311ceaffd2cde8d66f76aadaebac
Author: Rodolfo Alonso Hernandez <email address hidden>
Date: Sat Apr 22 04:09:18 2023 +0200

Fix Loki tempest jobs

    This patch fixes the issues reported in the
    "neutron-ovn-tempest-with-uwsgi-loki" job:
    * The missing retry decorators in some ``TapPlugin`` methods.
    * Added a session flush in
      ``OVNL3RouterPlugin.create_router_precommit``. In case the router
      creation fails before the creation of the initial
      ``OVNRevisionNumbers`` register, the transaction is retried.
      That will prevent from trying to retrieve a router standard
      attribute that doesn't exist, due to a previous error.

Closes-Bug: #2017131

Change-Id: Idbf7ea6018146b67387f2ff99e281e32170ba039

Changed in neutron:
status:	In Progress → Fix Released

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2023-05-17: Fix included in openstack/neutron 23.0.0.0b2

This issue was fixed in the openstack/neutron 23.0.0.0b2 development milestone.

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

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