2125842 – Deadlock when starting neutron server

Bug 2125842 - Deadlock when starting neutron server

Summary: Deadlock when starting neutron server

Keywords:
Status:	CLOSED CURRENTRELEASE
Alias:	None
Product:	Red Hat OpenStack
Classification:	Red Hat
Component:	python-networking-ovn
Sub Component:
Version:	16.1 (Train)
Hardware:	Unspecified
OS:	Unspecified
Priority:	urgent
Severity:	urgent
Target Milestone:	z9
Target Release:	16.1 (Train on RHEL 8.2)
Assignee:	Lucas Alvares Gomes
QA Contact:	Eran Kuris
Docs Contact:
URL:
Whiteboard:
Depends On:	2134364
Blocks:
TreeView+	depends on / blocked

Reported:	2022-09-11 01:01 UTC by Jakub Libosvar
Modified:	2023-06-18 11:02 UTC (History)
CC List:	12 users (show)
Fixed In Version:
Doc Type:	If docs needed, set a value
Doc Text:
Clone Of:
Clones:	2134895 (view as bug list)
Environment:
Last Closed:	2023-06-16 14:37:54 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)

Links
System	ID	Priority	Status	Summary	Last Updated
Launchpad	1990174	None	None	None	2022-09-19 16:34:36 UTC
OpenStack gerrit	858542	None	MERGED	Move the "ovn_hash_ring" clean up to maintenance worker	2023-03-06 16:33:12 UTC
Red Hat Issue Tracker	OSP-18649	None	None	None	2022-09-11 01:06:48 UTC

Description Jakub Libosvar 2022-09-11 01:01:47 UTC

Description of problem:
Neutron server often fails to start and systemd needs to restart it. This is a problem at scale because all workers need to reconnect again to the OVN DBs.

Version-Release number of selected component (if applicable):
16.1.8

How reproducible:
50%

Steps to Reproduce:
1. Start neutron server
2.
3.

Actual results:


Expected results:


Additional info:

2022-09-11 00:41:23.235 8 ERROR neutron.service [req-e6045626-af1c-4915-b8de-8a90cfc71ba1 - - - - -] Unrecoverable error: please check log for details.: oslo_db.exception.DBDeadlock: (pymysql.err.InternalError) (1205, 'Lock wait timeout exceeded; try restarting transaction')
[SQL: DELETE FROM ovn_hash_ring WHERE ovn_hash_ring.hostname = %(hostname_1)s AND ovn_hash_ring.group_name = %(group_name_1)s]
[parameters: {'hostname_1': 'ctrl-net-d-02.localdomain', 'group_name_1': 'mechanism_driver'}]
(Background on this error at: http://sqlalche.me/e/2j85)
2022-09-11 00:41:23.235 8 ERROR neutron.service Traceback (most recent call last):
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1244, in _execute_context
2022-09-11 00:41:23.235 8 ERROR neutron.service     cursor, statement, parameters, context
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
2022-09-11 00:41:23.235 8 ERROR neutron.service     cursor.execute(statement, parameters)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/cursors.py", line 165, in execute
2022-09-11 00:41:23.235 8 ERROR neutron.service     result = self._query(query)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/cursors.py", line 321, in _query
2022-09-11 00:41:23.235 8 ERROR neutron.service     conn.query(q)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 860, in query
2022-09-11 00:41:23.235 8 ERROR neutron.service     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 1061, in _read_query_result
2022-09-11 00:41:23.235 8 ERROR neutron.service     result.read()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 1349, in read
2022-09-11 00:41:23.235 8 ERROR neutron.service     first_packet = self.connection._read_packet()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 1018, in _read_packet
2022-09-11 00:41:23.235 8 ERROR neutron.service     packet.check_error()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 384, in check_error
2022-09-11 00:41:23.235 8 ERROR neutron.service     err.raise_mysql_exception(self._data)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
2022-09-11 00:41:23.235 8 ERROR neutron.service     raise errorclass(errno, errval)
2022-09-11 00:41:23.235 8 ERROR neutron.service pymysql.err.InternalError: (1205, 'Lock wait timeout exceeded; try restarting transaction')
2022-09-11 00:41:23.235 8 ERROR neutron.service
2022-09-11 00:41:23.235 8 ERROR neutron.service The above exception was the direct cause of the following exception:
2022-09-11 00:41:23.235 8 ERROR neutron.service
2022-09-11 00:41:23.235 8 ERROR neutron.service Traceback (most recent call last):
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/service.py", line 88, in serve_wsgi
2022-09-11 00:41:23.235 8 ERROR neutron.service     service.start()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/service.py", line 64, in start
2022-09-11 00:41:23.235 8 ERROR neutron.service     self.wsgi_app = _run_wsgi(self.app_name)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/service.py", line 321, in _run_wsgi
2022-09-11 00:41:23.235 8 ERROR neutron.service     app = config.load_paste_app(app_name)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/common/config.py", line 134, in load_paste_app
2022-09-11 00:41:23.235 8 ERROR neutron.service     app = loader.load_app(app_name)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/oslo_service/wsgi.py", line 353, in load_app
2022-09-11 00:41:23.235 8 ERROR neutron.service     return deploy.loadapp("config:%s" % self.config_path, name=name)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/deploy/loadwsgi.py", line 247, in loadapp
2022-09-11 00:41:23.235 8 ERROR neutron.service     return loadobj(APP, uri, name=name, **kw)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/deploy/loadwsgi.py", line 272, in loadobj
2022-09-11 00:41:23.235 8 ERROR neutron.service     return context.create()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/deploy/loadwsgi.py", line 710, in create
2022-09-11 00:41:23.235 8 ERROR neutron.service     return self.object_type.invoke(self)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/deploy/loadwsgi.py", line 144, in invoke
2022-09-11 00:41:23.235 8 ERROR neutron.service     **context.local_conf)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/deploy/util.py", line 55, in fix_call
2022-09-11 00:41:23.235 8 ERROR neutron.service     val = callable(*args, **kw)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/urlmap.py", line 31, in urlmap_factory
2022-09-11 00:41:23.235 8 ERROR neutron.service     app = loader.get_app(app_name, global_conf=global_conf)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/deploy/loadwsgi.py", line 350, in get_app
2022-09-11 00:41:23.235 8 ERROR neutron.service     name=name, global_conf=global_conf).create()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/deploy/loadwsgi.py", line 710, in create
2022-09-11 00:41:23.235 8 ERROR neutron.service     return self.object_type.invoke(self)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/deploy/loadwsgi.py", line 144, in invoke
2022-09-11 00:41:23.235 8 ERROR neutron.service     **context.local_conf)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/deploy/util.py", line 55, in fix_call
2022-09-11 00:41:23.235 8 ERROR neutron.service     val = callable(*args, **kw)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/auth.py", line 47, in pipeline_factory
2022-09-11 00:41:23.235 8 ERROR neutron.service     app = loader.get_app(pipeline[-1])
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/deploy/loadwsgi.py", line 350, in get_app
2022-09-11 00:41:23.235 8 ERROR neutron.service     name=name, global_conf=global_conf).create()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/deploy/loadwsgi.py", line 710, in create
2022-09-11 00:41:23.235 8 ERROR neutron.service     return self.object_type.invoke(self)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/deploy/loadwsgi.py", line 146, in invoke
2022-09-11 00:41:23.235 8 ERROR neutron.service     return fix_call(context.object, context.global_conf, **context.local_conf)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/paste/deploy/util.py", line 55, in fix_call
2022-09-11 00:41:23.235 8 ERROR neutron.service     val = callable(*args, **kw)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/api/v2/router.py", line 25, in _factory
2022-09-11 00:41:23.235 8 ERROR neutron.service     return pecan_app.v2_factory(global_config, **local_config)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/pecan_wsgi/app.py", line 47, in v2_factory
2022-09-11 00:41:23.235 8 ERROR neutron.service     startup.initialize_all()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/pecan_wsgi/startup.py", line 39, in initialize_all
2022-09-11 00:41:23.235 8 ERROR neutron.service     manager.init()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/manager.py", line 297, in init
2022-09-11 00:41:23.235 8 ERROR neutron.service     NeutronManager.get_instance()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/manager.py", line 248, in get_instance
2022-09-11 00:41:23.235 8 ERROR neutron.service     cls._create_instance()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/oslo_concurrency/lockutils.py", line 328, in inner
2022-09-11 00:41:23.235 8 ERROR neutron.service     return f(*args, **kwargs)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/manager.py", line 234, in _create_instance
2022-09-11 00:41:23.235 8 ERROR neutron.service     cls._instance = cls()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/manager.py", line 123, in __init__
2022-09-11 00:41:23.235 8 ERROR neutron.service     plugin_provider)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/manager.py", line 158, in _get_plugin_instance
2022-09-11 00:41:23.235 8 ERROR neutron.service     plugin_inst = plugin_class()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/quota/resource_registry.py", line 123, in wrapper
2022-09-11 00:41:23.235 8 ERROR neutron.service     return f(*args, **kwargs)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/plugins/ml2/plugin.py", line 248, in __init__
2022-09-11 00:41:23.235 8 ERROR neutron.service     self.mechanism_manager.initialize()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/neutron/plugins/ml2/managers.py", line 443, in initialize
2022-09-11 00:41:23.235 8 ERROR neutron.service     driver.obj.initialize()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/networking_ovn/ml2/mech_driver.py", line 109, in initialize
2022-09-11 00:41:23.235 8 ERROR neutron.service     self._clean_hash_ring()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/networking_ovn/ml2/mech_driver.py", line 220, in _clean_hash_ring
2022-09-11 00:41:23.235 8 ERROR neutron.service     db_hash_ring.remove_nodes_from_host(self.hash_ring_group)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/networking_ovn/db/hash_ring.py", line 45, in remove_nodes_from_host
2022-09-11 00:41:23.235 8 ERROR neutron.service     models.OVNHashRing.group_name == group_name).delete()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/query.py", line 3683, in delete
2022-09-11 00:41:23.235 8 ERROR neutron.service     delete_op.exec_()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 1671, in exec_
2022-09-11 00:41:23.235 8 ERROR neutron.service     self._do_exec()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 1899, in _do_exec
2022-09-11 00:41:23.235 8 ERROR neutron.service     self._execute_stmt(delete_stmt)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 1676, in _execute_stmt
2022-09-11 00:41:23.235 8 ERROR neutron.service     self.result = self.query._execute_crud(stmt, self.mapper)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/query.py", line 3350, in _execute_crud
2022-09-11 00:41:23.235 8 ERROR neutron.service     return conn.execute(stmt, self._params)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 988, in execute
2022-09-11 00:41:23.235 8 ERROR neutron.service     return meth(self, multiparams, params)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/sql/elements.py", line 287, in _execute_on_connection
2022-09-11 00:41:23.235 8 ERROR neutron.service     return connection._execute_clauseelement(self, multiparams, params)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1107, in _execute_clauseelement
2022-09-11 00:41:23.235 8 ERROR neutron.service     distilled_params,
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1248, in _execute_context
2022-09-11 00:41:23.235 8 ERROR neutron.service     e, statement, parameters, cursor, context
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1464, in _handle_dbapi_exception
2022-09-11 00:41:23.235 8 ERROR neutron.service     util.raise_from_cause(newraise, exc_info)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 383, in raise_from_cause
2022-09-11 00:41:23.235 8 ERROR neutron.service     reraise(type(exception), exception, tb=exc_tb, cause=cause)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 128, in reraise
2022-09-11 00:41:23.235 8 ERROR neutron.service     raise value.with_traceback(tb)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1244, in _execute_context
2022-09-11 00:41:23.235 8 ERROR neutron.service     cursor, statement, parameters, context
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
2022-09-11 00:41:23.235 8 ERROR neutron.service     cursor.execute(statement, parameters)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/cursors.py", line 165, in execute
2022-09-11 00:41:23.235 8 ERROR neutron.service     result = self._query(query)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/cursors.py", line 321, in _query
2022-09-11 00:41:23.235 8 ERROR neutron.service     conn.query(q)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 860, in query
2022-09-11 00:41:23.235 8 ERROR neutron.service     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 1061, in _read_query_result
2022-09-11 00:41:23.235 8 ERROR neutron.service     result.read()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 1349, in read
2022-09-11 00:41:23.235 8 ERROR neutron.service     first_packet = self.connection._read_packet()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 1018, in _read_packet
2022-09-11 00:41:23.235 8 ERROR neutron.service     packet.check_error()
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 384, in check_error
2022-09-11 00:41:23.235 8 ERROR neutron.service     err.raise_mysql_exception(self._data)
2022-09-11 00:41:23.235 8 ERROR neutron.service   File "/usr/lib/python3.6/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
2022-09-11 00:41:23.235 8 ERROR neutron.service     raise errorclass(errno, errval)
2022-09-11 00:41:23.235 8 ERROR neutron.service oslo_db.exception.DBDeadlock: (pymysql.err.InternalError) (1205, 'Lock wait timeout exceeded; try restarting transaction')
2022-09-11 00:41:23.235 8 ERROR neutron.service [SQL: DELETE FROM ovn_hash_ring WHERE ovn_hash_ring.hostname = %(hostname_1)s AND ovn_hash_ring.group_name = %(group_name_1)s]
2022-09-11 00:41:23.235 8 ERROR neutron.service [parameters: {'hostname_1': 'ctrl-net-d-02.localdomain', 'group_name_1': 'mechanism_driver'}]
2022-09-11 00:41:23.235 8 ERROR neutron.service (Background on this error at: http://sqlalche.me/e/2j85)
2022-09-11 00:41:23.235 8 ERROR neutron.service
2022-09-11 00:41:23.244 8 CRITICAL neutron [req-e6045626-af1c-4915-b8de-8a90cfc71ba1 - - - - -] Unhandled error: oslo_db.exception.DBDeadlock: (pymysql.err.InternalError) (1205, 'Lock wait timeout exceeded; try restarting transaction')
[SQL: DELETE FROM ovn_hash_ring WHERE ovn_hash_ring.hostname = %(hostname_1)s AND ovn_hash_ring.group_name = %(group_name_1)s]
[parameters: {'hostname_1': 'ctrl-net-d-02.localdomain', 'group_name_1': 'mechanism_driver'}]
(Background on this error at: http://sqlalche.me/e/2j85)

Note You need to log in before you can comment on or make changes to this bug.