yahoo-eng-team team mailing list archive
-
yahoo-eng-team team
-
Mailing list archive
-
Message #87164
[Bug 1943714] [NEW] DB session commit error in resource_registry.set_resources_dirty
Public bug reported:
It seems that patch
https://review.opendev.org/c/openstack/neutron/+/805031 introduced some
new error during call of resource_registry.set_resources_dirty() in
https://github.com/openstack/neutron/blob/6db261962894b1667dd213b116e89246a3e54386/neutron/api/v2/base.py#L506
I didn't saw that issue in our CI jobs on master branch but we noticed
them in the d/s jobs on OSP-16 which is based on Train. Error is like:
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb) [731/1883]
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource raise value
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_db/api.py", line 142, in wrapper
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource return f(*args, **kwargs)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/neutron_lib/db/api.py", line 183, in wrapped
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource LOG.debug("Retry wrapper got retriable exception: %s", e)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource self.force_reraise()
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource raise value
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/neutron_lib/db/api.py", line 179, in wrapped
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource return f(*dup_args, **dup_kwargs)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/neutron/api/v2/base.py", line 558, in _create
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource obj)})
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/neutron/api/v2/base.py", line 500, in notify
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource resource_registry.set_resources_dirty(request.context)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib64/python3.6/contextlib.py", line 88, in __exit__
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource next(self.gen)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 1065, in _transaction_scope
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource yield resource
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib64/python3.6/contextlib.py", line 88, in __exit__
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource next(self.gen)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 667, in _session
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource self.session.rollback()
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource self.force_reraise()
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource raise value
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 664, in _session
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource self._end_session_transaction(self.session)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 692, in _end_session_transaction
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource session.commit()
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 1026, in commit
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource self.transaction.commit()
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 491, in commit
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource self._assert_active(prepared_ok=True)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 294, in _assert_active
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource % self._rollback_exception
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource sqlalchemy.exc.InvalidRequestError: This Session's transaction has been rolled back due to a previous exception during flush. To begin a new transaction with this Session, first issue Session.rollback(). Original ex$
eption was: (pymysql.err.OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction')
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource [SQL: DELETE FROM reservations WHERE reservations.id = %(id)s]
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource [parameters: {'id': '3644bc07-a2b6-47b2-9767-bbf89f9606e2'}]
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource (Background on this error at: http://sqlalche.me/e/e3q8)
I guess that this may be some race condition which can be hit under
specific conditions and IMHO it can happend also in master branch as
well.
** Affects: neutron
Importance: High
Assignee: Slawek Kaplonski (slaweq)
Status: New
** Tags: db
** Changed in: neutron
Assignee: (unassigned) => Slawek Kaplonski (slaweq)
--
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1943714
Title:
DB session commit error in resource_registry.set_resources_dirty
Status in neutron:
New
Bug description:
It seems that patch
https://review.opendev.org/c/openstack/neutron/+/805031 introduced
some new error during call of resource_registry.set_resources_dirty()
in
https://github.com/openstack/neutron/blob/6db261962894b1667dd213b116e89246a3e54386/neutron/api/v2/base.py#L506
I didn't saw that issue in our CI jobs on master branch but we noticed
them in the d/s jobs on OSP-16 which is based on Train. Error is like:
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb) [731/1883]
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource raise value
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_db/api.py", line 142, in wrapper
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource return f(*args, **kwargs)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/neutron_lib/db/api.py", line 183, in wrapped
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource LOG.debug("Retry wrapper got retriable exception: %s", e)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource self.force_reraise()
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource raise value
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/neutron_lib/db/api.py", line 179, in wrapped
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource return f(*dup_args, **dup_kwargs)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/neutron/api/v2/base.py", line 558, in _create
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource obj)})
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/neutron/api/v2/base.py", line 500, in notify
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource resource_registry.set_resources_dirty(request.context)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib64/python3.6/contextlib.py", line 88, in __exit__
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource next(self.gen)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 1065, in _transaction_scope
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource yield resource
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib64/python3.6/contextlib.py", line 88, in __exit__
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource next(self.gen)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 667, in _session
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource self.session.rollback()
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource self.force_reraise()
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource six.reraise(self.type_, self.value, self.tb)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/six.py", line 675, in reraise
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource raise value
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 664, in _session
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource self._end_session_transaction(self.session)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/enginefacade.py", line 692, in _end_session_transaction
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource session.commit()
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 1026, in commit
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource self.transaction.commit()
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 491, in commit
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource self._assert_active(prepared_ok=True)
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 294, in _assert_active
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource % self._rollback_exception
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource sqlalchemy.exc.InvalidRequestError: This Session's transaction has been rolled back due to a previous exception during flush. To begin a new transaction with this Session, first issue Session.rollback(). Original ex$
eption was: (pymysql.err.OperationalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction')
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource [SQL: DELETE FROM reservations WHERE reservations.id = %(id)s]
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource [parameters: {'id': '3644bc07-a2b6-47b2-9767-bbf89f9606e2'}]
2021-09-15 09:50:09.540 15 ERROR neutron.api.v2.resource (Background on this error at: http://sqlalche.me/e/e3q8)
I guess that this may be some race condition which can be hit under
specific conditions and IMHO it can happend also in master branch as
well.
To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1943714/+subscriptions
Follow ups