yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1964640] Re: db-sync script port binding deadlock when migrating to OVN

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: OpenStack Infra <1964640@xxxxxxxxxxxxxxxxxx>
Date: Mon, 14 Mar 2022 21:34:30 -0000
Reply-to: Bug 1964640 <1964640@xxxxxxxxxxxxxxxxxx>
Sender: noreply@xxxxxxxxxxxxx
Reviewed:  https://review.opendev.org/c/openstack/neutron/+/833469
Committed: https://opendev.org/openstack/neutron/commit/0ec523aac11c31d9d8d2f0e7169332b876a61391
Submitter: "Zuul (22348)"
Branch:    master

commit 0ec523aac11c31d9d8d2f0e7169332b876a61391
Author: Jakub Libosvar <libosvar@xxxxxxxxxx>
Date:   Fri Mar 11 16:32:18 2022 -0500

    ovn: Retry port binding on deadlock when migrating to ovn
    
    If the port binding is being changed while Neutron keeps changing
    the port binding because ovn controller starts claiming the port
    bindings then the db sync script may fail.
    
    The patch adds DBDeadLock to the re-try mechanism when running db sync
    script in migration mode.
    
    Change-Id: I912c3145383e9a18dfd46b8e4dbb0cf927ca76e4
    Closes-bug: #1964640
    Signed-off-by: Jakub Libosvar <libosvar@xxxxxxxxxx>


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

Title:
  db-sync script port binding deadlock when migrating to OVN

Status in neutron:
  Fix Released

Bug description:
  If the port binding is being changed while Neutron keeps changing the
  port binding because ovn controller starts claiming the port bindings
  then the db sync script may fail:

  2022-02-12 18:23:02.332 47 CRITICAL neutron_ovn_db_sync_util [req-d5fae5a9-4fc8-4d2d-94fd-988625c45b09 - - - - -] Unhandled error: oslo_db.exception.DBDeadlock: (pymysql.err.InternalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction')
  [SQL: UPDATE standardattributes SET revision_number=(standardattributes.revision_number + %(revision_number_1)s), updated_at=%(updated_at)s WHERE standardattributes.id IN (%(id_1)s)]
  [parameters: {'revision_number_1': 1, 'updated_at': datetime.datetime(2022, 2, 12, 18, 23, 2), 'id_1': 356}]
  (Background on this error at: http://sqlalche.me/e/2j85)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util Traceback (most recent call last):
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1244, in _execute_context
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     cursor, statement, parameters, context
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     cursor.execute(statement, parameters)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/cursors.py", line 165, in execute
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     result = self._query(query)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/cursors.py", line 321, in _query
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     conn.query(q)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 860, in query
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 1061, in _read_query_result
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     result.read()
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 1349, in read
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     first_packet = self.connection._read_packet()
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 1018, in _read_packet
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     packet.check_error()
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 384, in check_error
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     err.raise_mysql_exception(self._data)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     raise errorclass(errno, errval)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util pymysql.err.InternalError: (1213, 'Deadlock found when trying to get lock; try restarting transaction')
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util 
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util The above exception was the direct cause of the following exception:
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util 
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util Traceback (most recent call last):
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/bin/neutron-ovn-db-sync-util", line 10, in <module>
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     sys.exit(main())
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/networking_ovn/cmd/neutron_ovn_db_sync_util.py", line 233, in main
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     db_migration.migrate_neutron_database_to_ovn(core_plugin)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/networking_ovn/ml2/db_migration.py", line 93, in migrate_neutron_database_to_ovn
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     pb.update()
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/neutron/objects/base.py", line 337, in decorator
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     return func(self, *args, **kwargs)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/neutron/objects/base.py", line 906, in update
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     self._get_composite_keys()))
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/neutron/objects/db/api.py", line 88, in update_object
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     db_obj.save(session=context.session)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/oslo_db/sqlalchemy/models.py", line 50, in save
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     session.flush()
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 2451, in flush
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     self._flush(objects)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 2589, in _flush
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     transaction.rollback(_capture_exception=True)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/langhelpers.py", line 68, in __exit__
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     compat.reraise(exc_type, exc_value, exc_tb)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 129, in reraise
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     raise value
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 2583, in _flush
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     self.dispatch.after_flush_postexec(self, flush_context)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/event/attr.py", line 259, in __call__
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     fn(*args, **kw)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/neutron/services/revisions/revision_plugin.py", line 85, in _emit_related_revision_bumps
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     session, collected, version_check=False)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/neutron/services/revisions/revision_plugin.py", line 189, in _bump_obj_revisions
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     synchronize_session=False)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/query.py", line 3818, in update
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     update_op.exec_()
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 1671, in exec_
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     self._do_exec()
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 1864, in _do_exec
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     self._execute_stmt(update_stmt)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 1676, in _execute_stmt
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     self.result = self.query._execute_crud(stmt, self.mapper)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/orm/query.py", line 3350, in _execute_crud
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     return conn.execute(stmt, self._params)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 988, in execute
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     return meth(self, multiparams, params)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/sql/elements.py", line 287, in _execute_on_connection
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     return connection._execute_clauseelement(self, multiparams, params)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1107, in _execute_clauseelement
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     distilled_params,
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1248, in _execute_context
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     e, statement, parameters, cursor, context
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1464, in _handle_dbapi_exception
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     util.raise_from_cause(newraise, exc_info)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 383, in raise_from_cause
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     reraise(type(exception), exception, tb=exc_tb, cause=cause)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 128, in reraise
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     raise value.with_traceback(tb)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/base.py", line 1244, in _execute_context
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     cursor, statement, parameters, context
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib64/python3.6/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     cursor.execute(statement, parameters)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/cursors.py", line 165, in execute
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     result = self._query(query)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/cursors.py", line 321, in _query
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     conn.query(q)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 860, in query
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     self._affected_rows = self._read_query_result(unbuffered=unbuffered)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 1061, in _read_query_result
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     result.read()
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 1349, in read
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     first_packet = self.connection._read_packet()
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 1018, in _read_packet
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     packet.check_error()
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/connections.py", line 384, in check_error
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     err.raise_mysql_exception(self._data)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util   File "/usr/lib/python3.6/site-packages/pymysql/err.py", line 107, in raise_mysql_exception
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util     raise errorclass(errno, errval)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util oslo_db.exception.DBDeadlock: (pymysql.err.InternalError) (1213, 'Deadlock found when trying to get lock; try restarting transaction')
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util [SQL: UPDATE standardattributes SET revision_number=(standardattributes.revision_number + %(revision_number_1)s), updated_at=%(updated_at)s WHERE standardattributes.id IN (%(id_1)s)]
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util [parameters: {'revision_number_1': 1, 'updated_at': datetime.datetime(2022, 2, 12, 18, 23, 2), 'id_1': 356}]
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util (Background on this error at: http://sqlalche.me/e/2j85)
  2022-02-12 18:23:02.332 47 ERROR neutron_ovn_db_sync_util

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

[Bug 1964640] [NEW] db-sync script port binding deadlock when migrating to OVN
From: Jakub Libosvar, 2022-03-11