neutron

Neutron Sync Repair Failed

Bug #2027931 reported by Adelia Nurlina on 2023-07-17

This bug affects 1 person

Affects		Status	Importance	Assigned to	Milestone
	neutron	New	Undecided	Unassigned

Bug Description

Openstack ussuri kolla-ansible 10.4.0

i have 3 controller openstack, but the network agent often 504 Gateway timeout. i checked the sync status of neutron `neutron-ovn-db-sync-util --config-file /etc/neutron/neutron.conf --config-file /etc/neutron/plugins/ml2/ml2_conf.ini
`. the logs looks like this :

2023-07-11 09:57:16.905 31504 INFO neutron.cmd.ovn.neutron_ovn_db_sync_util [req-077b1123-58ac-424b-90bd-9af09809d51e - - - - -] Sync for Northbound db started with mode : log
2023-07-11 09:57:45.263 31504 WARNING neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.ovn_db_sync [req-077b1123-58ac-424b-90bd-9af09809d51e - - - - -] Metadata port 59e422ea-dbcd-40c7-a458-235f42a9d8ad for network a111b028-569e-4ba4-9448-5f4c09685221 found in Neutron but not in OVN
2023-07-11 09:58:05.031 31504 WARNING neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.ovn_db_sync [req-077b1123-58ac-424b-90bd-9af09809d51e - - - - -] Port found in OVN but not in Neutron, port_id=9576db78-8fa9-462a-9b15-edcc07af31bc
2023-07-11 09:58:05.031 31504 WARNING neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.ovn_db_sync [req-077b1123-58ac-424b-90bd-9af09809d51e - - - - -] Port found in OVN but not in Neutron, port_id=8c5d7903-22f2-4a42-9dd7-53aa8018ab76
2023-07-11 10:00:07.003 31504 WARNING neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.ovn_db_sync [req-077b1123-58ac-424b-90bd-9af09809d51e - - - - -] Router found in Neutron but not in OVN DB, router id=012c65cd-ee98-4640-b515-f89abdf7639f

So i want to repair the neutron `/var/lib/kolla/venv/bin/neutron-ovn-db-sync-util --config-file /etc/neutron/neutron.conf --config-file /etc/neutron/plugins/ml2/ml2_conf.ini --ovn-neutron_sync_mode repair`. But the repair failed because timeout.

2023-07-14 19:51:09.322 65827 INFO neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.extensions.qos [req-04c202a4-3383-49eb-b9db-37ad0008da5e - - - - -] Starting OVNClientQosExtension
2023-07-14 19:51:09.323 65827 INFO neutron.cmd.ovn.neutron_ovn_db_sync_util [req-04c202a4-3383-49eb-b9db-37ad0008da5e - - - - -] Sync for Northbound db started with mode : repair
2023-07-14 19:51:55.957 65827 WARNING neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.ovn_db_sync [req-04c202a4-3383-49eb-b9db-37ad0008da5e - - - - -] Metadata port 59e422ea-dbcd-40c7-a458-235f42a9d8ad for network a111b028-569e-4ba4-9448-5f4c09685221 found in Neutron but not in OVN
2023-07-14 19:51:55.957 65827 WARNING neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.ovn_db_sync [req-04c202a4-3383-49eb-b9db-37ad0008da5e - - - - -] Creating metadata port 59e422ea-dbcd-40c7-a458-235f42a9d8ad for network a111b028-569e-4ba4-9448-5f4c09685221 in OVN
2023-07-14 19:56:19.289 65827 CRITICAL neutron_ovn_db_sync_util [req-04c202a4-3383-49eb-b9db-37ad0008da5e - - - - -] Unhandled error: ovsdbapp.exceptions.TimeoutException: Commands [<neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.commands.AddLSwitchPortCommand object at 0x7fed05ade9b0>, <ovsdbapp.schema.ovn_northbound.commands.QoSDelCommand object at 0x7fed05aec7f0>, <ovsdbapp.schema.ovn_northbound.commands.QoSDelCommand object at 0x7fed05aec828>] exceeded timeout 180 seconds
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util Traceback (most recent call last):
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/var/lib/kolla/venv/lib/python3.6/site-packages/ovsdbapp/backend/ovs_idl/transaction.py", line 55, in commit
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util result = self.results.get(timeout=self.timeout)
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/usr/lib/python3.6/queue.py", line 172, in get
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util raise Empty
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util queue.Empty
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util During handling of the above exception, another exception occurred:
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util Traceback (most recent call last):
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/var/lib/kolla/venv/bin/neutron-ovn-db-sync-util", line 8, in <module>
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util sys.exit(main())
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/cmd/ovn/neutron_ovn_db_sync_util.py", line 219, in main
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util synchronizer.do_sync()
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovn_db_sync.py", line 98, in do_sync
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util self.sync_networks_ports_and_dhcp_opts(ctx)
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovn_db_sync.py", line 869, in sync_networks_ports_and_dhcp_opts
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util self._sync_metadata_ports(ctx, db_ports)
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovn_db_sync.py", line 789, in _sync_metadata_ports
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util self._create_port_in_ovn(ctx, port)
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovn_db_sync.py", line 111, in _create_port_in_ovn
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util self._ovn_client.create_port(ctx, port)
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/ovn_client.py", line 440, in create_port
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util self._qos_driver.create_port(txn, port, port_type=port_info.type)
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/usr/lib/python3.6/contextlib.py", line 88, in __exit__
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util next(self.gen)
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/plugins/ml2/drivers/ovn/mech_driver/ovsdb/impl_idl_ovn.py", line 240, in transaction
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util yield t
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/usr/lib/python3.6/contextlib.py", line 88, in __exit__
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util next(self.gen)
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/var/lib/kolla/venv/lib/python3.6/site-packages/ovsdbapp/api.py", line 119, in transaction
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util del self._nested_txns_map[cur_thread_id]
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/var/lib/kolla/venv/lib/python3.6/site-packages/ovsdbapp/api.py", line 69, in __exit__
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util self.result = self.commit()
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util File "/var/lib/kolla/venv/lib/python3.6/site-packages/ovsdbapp/backend/ovs_idl/transaction.py", line 58, in commit
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util timeout=self.timeout)
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util ovsdbapp.exceptions.TimeoutException: Commands [<neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.commands.AddLSwitchPortCommand object at 0x7fed05ade9b0>, <ovsdbapp.schema.ovn_northbound.commands.QoSDelCommand object at 0x7fed05aec7f0>, <ovsdbapp.schema.ovn_northbound.commands.QoSDelCommand object at 0x7fed05aec828>] exceeded timeout 180 seconds
2023-07-14 19:56:19.289 65827 ERROR neutron_ovn_db_sync_util

I have tried to increase the timeout to 180s, but no luck.

See original description

Tags:

Adelia Nurlina (adelianurlinap) on 2023-07-17

description:

updated

Revision history for this message

Brian Haley (brian-haley) wrote on 2023-07-17:

Are there any other hints in any of the OVN log files?

Revision history for this message

Adelia Nurlina (adelianurlinap) wrote on 2023-07-18:

Download full text (11.6 KiB)

hello, the issue of timeout repair neutron has been solved by update the metadata port manually before repair. But after repair neutron, the network agent still not stable (often 504 gateway timeout).

$ openstack network agent list

"HttpException: 504: Server Error for url: https://xxxx/v2.0/agents, The server didn't respond in time.: 504 Gateway Time-out"

this log showed up in neutron-server.log :

$ openstack network agent list

"HttpException: 504: Server Error for url: https://xxxx/v2.0/agents, The server didn't respond in time.: 504 Gateway Time-out"

this log showed up in neutron-server.log :

2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource [req-84aa9a81-2eb9-45b4-9353-7f395134041d 3fe50ccef00f49e3b1b0bbd58705a930 c7d2001e7a2c4c32b9f2a3657f29b6b0 - default default] index failed: No details.: ovsdbapp.exceptions.TimeoutExcept
ion: Commands [<neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.commands.CheckLivenessCommand object at 0x7fa84597e630>] exceeded timeout 180 seconds                                                                                              
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource Traceback (most recent call last):                                                                                                                                                         
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/ovsdbapp/backend/ovs_idl/connection.py", line 153, in queue_txn                                                                    
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     self.txns.put(txn, timeout=self.timeout)                                                                                                                                               
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/ovsdbapp/backend/ovs_idl/connection.py", line 51, in put                                                                           
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     super(TransactionQueue, self).put(*args, **kwargs)                                                                                                                                     
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/queue.py", line 264, in put                                                                                               
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     result = waiter.wait()                                                                                                                                                                 
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/queue.py", line 141, in wait                                                                                              
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     return get_hub().switch()                                                                                                                                                              
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/hubs/hub.py", line 298, in switch                                                                                         
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     return self.greenlet.switch()                                                                                                                                                          
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource queue.Full                                                                                                                                                                                 
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource                                                                                                                                                                                            
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource During handling of the above exception, another exception occurred:                                                                                                                        
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource                                                                                                                                                                                            
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource Traceback (most recent call last):                                                                                                                                                         
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron/api/v2/resource.py", line 98, in resource                                                                                  
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     result = method(request=request, **args)
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron_lib/db/api.py", line 139, in wrapped
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     setattr(e, '_RETRY_EXCEEDED', True)
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     self.force_reraise()
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     six.reraise(self.type_, self.value, self.tb)
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.6/dist-packages/six.py", line 703, in reraise
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     raise value
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron_lib/db/api.py", line 135, in wrapped
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     return f(*args, **kwargs)
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_db/api.py", line 154, in wrapper
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     ectxt.value = e.inner_exc
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     self.force_reraise()
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     six.reraise(self.type_, self.value, self.tb)
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/usr/local/lib/python3.6/dist-packages/six.py", line 703, in reraise
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     raise value
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_db/api.py", line 142, in wrapper
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     return f(*args, **kwargs)
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/neutron_lib/db/api.py", line 183, in wrapped
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     LOG.debug("Retry wrapper got retriable exception: %s", e)
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     self.force_reraise()

2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/ovsdbapp/backend/ovs_idl/transaction.py", line 53, in commit
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     self.ovsdb_connection.queue_txn(self)
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource   File "/var/lib/kolla/venv/lib/python3.6/site-packages/ovsdbapp/backend/ovs_idl/connection.py", line 156, in queue_txn
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource     timeout=self.timeout)
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource ovsdbapp.exceptions.TimeoutException: Commands [<neutron.plugins.ml2.drivers.ovn.mech_driver.ovsdb.commands.CheckLivenessCommand object at 0x7fa84597e630>] exceeded timeout 180 seconds
2023-07-18 08:19:01.892 670 ERROR neutron.api.v2.resource
2023-07-18 08:19:01.894 670 INFO neutron.wsgi [req-84aa9a81-2eb9-45b4-9353-7f395134041d 3fe50ccef00f49e3b1b0bbd58705a930 c7d2001e7a2c4c32b9f2a3657f29b6b0 - default default] Traceback (most recent call last):
  File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/wsgi.py", line 604, in handle_one_response
    write(b''.join(towrite))
  File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/wsgi.py", line 538, in write
    wfile.flush()
  File "/usr/lib/python3.6/socket.py", line 604, in write
    return self._sock.send(b)
  File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/greenio/base.py", line 396, in send
    return self._send_loop(self.fd.send, data, flags)
  File "/var/lib/kolla/venv/lib/python3.6/site-packages/eventlet/greenio/base.py", line 383, in _send_loop
    return send_method(data, *args)
ConnectionResetError: [Errno 104] Connection reset by peer

this is the ovn-sb and ovn-nb log :

root@xxx:~# tail -f /var/log/kolla/openvswitch/ovn-nb-db.log 
2023-07-18T01:21:04.328Z|07042|reconnect|ERR|tcp:xxxx:49146: no response to inactivity probe after 5.29 seconds, disconnecting
2023-07-18T01:21:06.997Z|07043|reconnect|ERR|tcp:xxxx:49148: no response to inactivity probe after 5 seconds, disconnecting
2023-07-18T01:21:16.405Z|07044|reconnect|ERR|tcp:xxxx:32964: no response to inactivity probe after 5.08 seconds, disconnecting
2023-07-18T01:21:18.071Z|07045|reconnect|ERR|tcp:xxxx:55250: no response to inactivity probe after 5.08 seconds, disconnecting
2023-07-18T01:21:24.407Z|07046|reconnect|ERR|tcp:xxxx:55278: no response to inactivity probe after 5 seconds, disconnecting
2023-07-18T01:21:26.740Z|07047|reconnect|ERR|tcp:xxxx:55292: no response to inactivity probe after 5 seconds, disconnecting
2023-07-18T01:21:37.151Z|07048|reconnect|ERR|tcp:xxxx:41624: no response to inactivity probe after 5.08 seconds, disconnecting

root@xxxx:~# tail -f /var/log/kolla/openvswitch/ovn-sb-db.log 
2023-07-18T01:18:09.080Z|01544|reconnect|ERR|tcp:xxxx:48630: no response to inactivity probe after 5 seconds, disconnecting
2023-07-18T01:19:04.192Z|01545|reconnect|ERR|tcp:xxxx:44082: no response to inactivity probe after 5.29 seconds, disconnecting
2023-07-18T01:19:11.866Z|01546|reconnect|ERR|tcp:xxxx:44104: no response to inactivity probe after 5 seconds, disconnecting
2023-07-18T01:19:31.545Z|01547|reconnect|ERR|tcp:xxxx:55158: no response to inactivity probe after 5 seconds, disconnecting
2023-07-18T01:20:04.567Z|01548|reconnect|ERR|tcp:xxxx:57464: no response to inactivity probe after 5 seconds, disconnecting

i already set the interval but the inactivity probe logs still showed up.

ovs-vsctl set open . external_ids:ovn-remote-probe-interval="180000"
docker exec ovn_nb_db ovn-nbctl set NB_Global . options:northd_probe_interval=180000

Does the neutron logs and the ovn logs related which causes the network agent to frequently timeout?

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.