[OVN Octavia Provider] OVN provider fails during listener delete

[Michael Johnson]

The OVN provider is consistently failing during a listener delete as part of the member API tempest test tear down with a 'filedescriptor out of range in select()' error.

o-api logs snippet:

Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn [None req-9201aee8-9a5b-460c-bf8b-c6408d20aec7 tempest-MemberAPITest-903346660 tempest-MemberAPITest-903346660] OVS database connection to OVN_Northbound failed with error: 'filedescriptor out of range in select()'. Verify that the OVS and OVN services are available and that the 'ovn_nb_connection' and 'ovn_sb_connection' configuration options are correct.: ValueError: filedescriptor out of range in select()
Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn Traceback (most recent call last):
Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn File "/opt/stack/ovn-octavia-provider/ovn_octavia_provider/ovsdb/impl_idl_ovn.py", line 61, in start_connection
Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn self.ovsdb_connection.start()
Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn File "/usr/local/lib/python3.6/dist-packages/ovsdbapp/backend/ovs_idl/connection.py", line 79, in start
Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn idlutils.wait_for_change(self.idl, self.timeout)
Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn File "/usr/local/lib/python3.6/dist-packages/ovsdbapp/backend/ovs_idl/idlutils.py", line 201, in wait_for_change
Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn ovs_poller.block()
Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn File "/usr/local/lib/python3.6/dist-packages/ovs/poller.py", line 231, in block
Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn events = self.poll.poll(self.timeout)
Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn File "/usr/local/lib/python3.6/dist-packages/ovs/poller.py", line 140, in poll
Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn timeout)
Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn ValueError: filedescriptor out of range in select()
Sep 03 15:44:05.171297 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR ovn_octavia_provider.ovsdb.impl_idl_ovn
Sep 03 15:44:05.172746 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR octavia.api.drivers.driver_factory [None req-9201aee8-9a5b-460c-bf8b-c6408d20aec7 tempest-MemberAPITest-903346660 tempest-MemberAPITest-903346660] Unable to load provider driver ovn due to: OVS database connection to OVN_Northbound failed with error: 'filedescriptor out of range in select()'. Verify that the OVS and OVN services are available and that the 'ovn_nb_connection' and 'ovn_sb_connection' configuration options are correct.: ovn_octavia_provider.ovsdb.impl_idl_ovn.OvsdbConnectionUnavailable: OVS database connection to OVN_Northbound failed with error: 'filedescriptor out of range in select()'. Verify that the OVS and OVN services are available and that the 'ovn_nb_connection' and 'ovn_sb_connection' configuration options are correct.
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ERROR wsme.api [None req-9201aee8-9a5b-460c-bf8b-c6408d20aec7 tempest-MemberAPITest-903346660 tempest-MemberAPITest-903346660] Server-side error: "Provider 'ovn' was not found.". Detail:
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: Traceback (most recent call last):
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/opt/stack/ovn-octavia-provider/ovn_octavia_provider/ovsdb/impl_idl_ovn.py", line 61, in start_connection
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: self.ovsdb_connection.start()
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/usr/local/lib/python3.6/dist-packages/ovsdbapp/backend/ovs_idl/connection.py", line 79, in start
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: idlutils.wait_for_change(self.idl, self.timeout)
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/usr/local/lib/python3.6/dist-packages/ovsdbapp/backend/ovs_idl/idlutils.py", line 201, in wait_for_change
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ovs_poller.block()
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/usr/local/lib/python3.6/dist-packages/ovs/poller.py", line 231, in block
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: events = self.poll.poll(self.timeout)
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/usr/local/lib/python3.6/dist-packages/ovs/poller.py", line 140, in poll
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: timeout)
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ValueError: filedescriptor out of range in select()
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: During handling of the above exception, another exception occurred:
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: Traceback (most recent call last):
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/opt/stack/octavia/octavia/api/drivers/driver_factory.py", line 44, in get_driver
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: invoke_on_load=True).driver
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/usr/local/lib/python3.6/dist-packages/stevedore/driver.py", line 61, in __init__
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: warn_on_missing_entrypoint=warn_on_missing_entrypoint
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/usr/local/lib/python3.6/dist-packages/stevedore/named.py", line 81, in __init__
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: verify_requirements)
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/usr/local/lib/python3.6/dist-packages/stevedore/extension.py", line 233, in _load_plugins
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: self._on_load_failure_callback(self, ep, err)
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/usr/local/lib/python3.6/dist-packages/stevedore/extension.py", line 225, in _load_plugins
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: verify_requirements,
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/usr/local/lib/python3.6/dist-packages/stevedore/named.py", line 158, in _load_one_plugin
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: verify_requirements,
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/usr/local/lib/python3.6/dist-packages/stevedore/extension.py", line 257, in _load_one_plugin
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: obj = plugin(*invoke_args, **invoke_kwds)
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/opt/stack/ovn-octavia-provider/ovn_octavia_provider/driver.py", line 42, in __init__
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: self._ovn_helper = ovn_helper.OvnProviderHelper()
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/opt/stack/ovn-octavia-provider/ovn_octavia_provider/helper.py", line 60, in __init__
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: self.ovn_nbdb_api = self.ovn_nbdb.start()
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/opt/stack/ovn-octavia-provider/ovn_octavia_provider/ovsdb/impl_idl_ovn.py", line 174, in start
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: return impl_idl_ovn.OvsdbNbOvnIdl(self.conn)
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/opt/stack/ovn-octavia-provider/ovn_octavia_provider/ovsdb/impl_idl_ovn.py", line 118, in __init__
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: super(OvsdbNbOvnIdl, self).__init__(connection)
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/opt/stack/ovn-octavia-provider/ovn_octavia_provider/ovsdb/impl_idl_ovn.py", line 57, in __init__
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: super(Backend, self).__init__(connection)
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/usr/local/lib/python3.6/dist-packages/ovsdbapp/backend/ovs_idl/__init__.py", line 35, in __init__
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: self.start_connection(connection)
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/opt/stack/ovn-octavia-provider/ovn_octavia_provider/ovsdb/impl_idl_ovn.py", line 66, in start_connection
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: raise connection_exception
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: ovn_octavia_provider.ovsdb.impl_idl_ovn.OvsdbConnectionUnavailable: OVS database connection to OVN_Northbound failed with error: 'filedescriptor out of range in select()'. Verify that the OVS and OVN services are available and that the 'ovn_nb_connection' and 'ovn_sb_connection' configuration options are correct.
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: During handling of the above exception, another exception occurred:
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: Traceback (most recent call last):
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/usr/local/lib/python3.6/dist-packages/wsmeext/pecan.py", line 84, in callfunction
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: result = f(self, *args, **kwargs)
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/opt/stack/octavia/octavia/api/v2/controllers/listener.py", line 632, in delete
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: driver = driver_factory.get_driver(provider)
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: File "/opt/stack/octavia/octavia/api/drivers/driver_factory.py", line 49, in get_driver
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: raise exceptions.ProviderNotFound(prov=provider)
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: octavia.common.exceptions.ProviderNotFound: Provider 'ovn' was not found.
Sep 03 15:44:05.175074 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: : octavia.common.exceptions.ProviderNotFound: Provider 'ovn' was not found.
Sep 03 15:44:05.178879 ubuntu-bionic-inap-mtl01-0019624710 <email address hidden>[10087]: [pid: 10089|app: 0|req: 1109/2281] 198.72.124.16 () {56 vars in 1234 bytes} [Thu Sep 3 15:44:04 2020] DELETE /load-balancer/v2.0/lbaas/listeners/3537f411-5ab3-48c8-9669-c9fa1f40fee9 => generated 90 bytes in 447 msecs (HTTP/1.1 501) 4 headers in 169 bytes (1 switches on core 0)

[Michael Johnson (johnsom)]

The test run logs are here: https://storage.bhs.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_4de/744805/16/check/neutron-ovn-provider-v2-api/4de2648/ until they aren't.

[Brian Haley (brian-haley)]

So it looks like there's a file descriptor leak, I was able to reproduce this running a script in a loop, I'll attach it. Seems the same failure Michael saw:

Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: ERROR octavia.api.drivers.driver_factory [None req-a656a825-06cb-4e85-9215-42ac0c9f2af7 demo demo] Unable to load provider driver ovn due to: OVS database connection to OVN_Northbound failed with error: 'filedescriptor out of range in select()'. Verify that the OVS and OVN services are available and that the 'ovn_nb_connection' and 'ovn_sb_connection' configuration options are correct.: ovn_octavia_provider.ovsdb.impl_idl_ovn.OvsdbConnectionUnavailable: OVS database connection to OVN_Northbound failed with error: 'filedescriptor out of range in select()'. Verify that the OVS and OVN services are available and that the 'ovn_nb_connection' and 'ovn_sb_connection' configuration options are correct.
Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: ERROR wsme.api [None req-a656a825-06cb-4e85-9215-42ac0c9f2af7 demo demo] Server-side error: "Provider 'ovn' was not found.". Detail:
Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: Traceback (most recent call last):
Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: File "/opt/stack/ovn-octavia-provider/ovn_octavia_provider/ovsdb/impl_idl_ovn.py", line 61, in start_connection
Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: self.ovsdb_connection.start()
Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/connection.py", line 79, in start
Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: idlutils.wait_for_change(self.idl, self.timeout)
Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: File "/usr/local/lib/python3.8/dist-packages/ovsdbapp/backend/ovs_idl/idlutils.py", line 217, in wait_for_change
Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: ovs_poller.block()
Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: File "/usr/lib/python3/dist-packages/ovs/poller.py", line 231, in block
Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: events = self.poll.poll(self.timeout)
Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: File "/usr/lib/python3/dist-packages/ovs/poller.py", line 137, in poll
Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: rlist, wlist, xlist = select.select(self.rlist,
Oct 13 11:20:09 devstack-20 <email address hidden>[1007326]: ValueError: filedescriptor out of range in select()

[Brian Haley (brian-haley)]

Don't know why the review wasn't automatically added:

https://review.opendev.org/#/c/758154/

[OpenStack Infra (hudson-openstack)]

Change abandoned by Terry Wilson (<email address hidden>) on branch: master
Review: https://review.opendev.org/758154
Reason: Abandoning for now as it looks like we can just delete connection/api objects in ovn-octavia-provider. Gets a bit complicated here as we need to be able to queue transactions while connection is stopped.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.opendev.org/758472

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.opendev.org/758472
Committed: https://git.openstack.org/cgit/openstack/ovn-octavia-provider/commit/?id=5b0715d96700d1c288f601b3ecb2cad507c2c134
Submitter: Zuul
Branch: master

commit 5b0715d96700d1c288f601b3ecb2cad507c2c134
Author: Terry Wilson <email address hidden>
Date: Thu Oct 15 12:53:36 2020 -0500

    Fix leaked file descriptors by cleaning up objects

    A reference to the ovsdbapp Connection object is stored on the the
    API impl class and it is causing the object to stick around and
    its pipe fds to never close. Ultimately, python-ovs's call to
    select() is limited to 1024 file descriptors and will eventually
    error out. This deletes the connection and api objects explicitly
    when we are done with them.

    Change-Id: I97b27eaa293fb161724d34da88b4398f8b590c33
    Co-authored-by: Brian Haley <email address hidden>
    Closes-Bug: #1894136

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/networking-ovn 7.4.0 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/ovn-octavia-provider 1.0.0 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/ovn-octavia-provider 0.4.0 release.

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/ovn-octavia-provider 0.1.3 release.