Description of problem: Issue reproduced by OSP16.1 OVN migration CI job: https://rhos-ci-jenkins.lab.eng.tlv2.redhat.com/job/DFG-network-networking-ovn-16.1_director-rhel-virthost-3cont_2comp-ipv4-vxlan-ml2ovs-to-ovn-migration/188/ The error happens during the execution of the post-migration create-migration-resources.sh script: http://rhos-ci-logs.lab.eng.tlv2.redhat.com/logs/rcj/DFG-network-networking-ovn-16.1_director-rhel-virthost-3cont_2comp-ipv4-vxlan-ml2ovs-to-ovn-migration/188/undercloud-0/home/stack/ovn_migration/post_migration_resources/create-migration-resources.sh.log.gz The log file shows that the server was successfully spawned, its status is ACTIVE and the following line was found in its console log output: ovn-migration-server-post login: That means, the server successfully contacted metadata to get its hostname. Then, the ping test fails for 60 retries (with a sleep 1 between them). We have not reproduced the issue locally yet. I have sent this patch upstream in order to obtain more information from the server when this happens again: https://review.opendev.org/c/openstack/neutron/+/829027 Version-Release number of selected component (if applicable): RHOS-16.1-RHEL-8-20220210.n.1 How reproducible: only once Steps to Reproduce: 1. run the CI migration job 2. 3.
The problem could be that OVS br-int has different openflow version set from the ml2/ovs era. http://rhos-ci-logs.lab.eng.tlv2.redhat.com/logs/rcj/DFG-network-networking-ovn-16.1_director-rhel-virthost-3cont_2comp-ipv4-vxlan-ml2ovs-to-ovn-migration/188/controller-0/var/log/containers/openvswitch/ovn-controller.log.gz 2022-02-12T19:07:16.829Z|00178|vconn(ovn_pinctrl0)|WARN|unix:/var/run/openvswitch/br-int.mgmt: version negotiation failed (we support version 0x06, peer supports versions 0x01, 0x04, 0x05) We used to re-set the bridge protocol versions in the past but I think we removed it and let the OVN figure out the version.
We still reset the protocols to [] but it didn't happen on controller-0 because of db-sync failure: TASK [migration : Sync neutron db with OVN db (container) - Run 1] ************* task path: /home/stack/ovn_migration/playbooks/roles/migration/tasks/sync-dbs.yml:7 Saturday 12 February 2022 18:22:36 +0000 (0:00:00.748) 0:39:49.166 ***** META: noop META: noop fatal: [controller-0]: FAILED! => {"changed": true, "cmd": ["podman", "exec", "f075d49879a8", "neutron-ovn-db-sync-util", "--config-file", "/etc/neutron/neutron.conf", "--config-file", "/etc/neutron/plugins/ml2/ml2_conf.ini", "--ovn-neutron_sync_mode", "migrate"], "delta": "0:00:25.994042", "end": "2022-02-12 18:23:03.058988", "msg": "non-zero return code", "rc": 1, "start": "2022-02-12 18:22:37.064946", "stderr": "Deprecated: Option \"vif_type\" from group \"ovn\" is deprecated for removal (The port VIF type is now determined based on the OVN chassis information when the port is bound to a host.). Its value may be silently ignored in the future.\nDeprecated: Option \"ovn_l3_mode\" from group \"ovn\" is deprecated for removal (This option is no longer used. Native L3 support in OVN is always used.). Its value may be silently ignored in the future.\nError: non zero exit code: 1: OCI runtime error", "stderr_lines": ["Deprecated: Option \"vif_type\" from group \"ovn\" is deprecated for removal (The port VIF type is now determined based on the OVN chassis information when the port is bound to a host.). Its value may be silently ignored in the future.", "Deprecated: Option \"ovn_l3_mode\" from group \"ovn\" is deprecated for removal (This option is no longer used. Native L3 support in OVN is always used.). Its value may be silently ignored in the future.", "Error: non zero exit code: 1: OCI runtime error"], "stdout": "", "stdout_lines": []}
This failed because of DB deadlock when migrating DBs 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
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory (Red Hat OpenStack Platform 16.1.9 bug fix and enhancement advisory), and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2022:8795