Hello,
We are experiencing a strange problem with Octavia API in an Openstack deployment. A bit of context: we have an Openstack Ussuri deployment (HA) on Ubuntu Focal. Most Openstack services are running on LXD containers on 3 baremetals. There are also two OVN-dedicated-chassis which act as gateways and nova-compute nodes. A couple of days ago we updated all the packages in the environment to the latest versions (baremetals and lxc containers). After the updates, we started seeing problems with the Octavia API. The API would randomly give an internal server error. Octavia API is running under Apache2 WSGI on 3 LXD containers on 3 separate nodes. Looking into one of the Octavia container under /var/log/apache2/octavia_error.log, we found the following error:
[Fri Apr 28 10:11:07.509268 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] mod_wsgi (pid=1312420): Failed to exec Python script file '/usr/bin/octavia-wsgi'. [Fri Apr 28 10:11:07.509455 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] mod_wsgi (pid=1312420): Exception occurred processing WSGI script '/usr/bin/octavia-wsgi'. [Fri Apr 28 10:11:07.511688 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] Traceback (most recent call last): [Fri Apr 28 10:11:07.511884 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "/usr/bin/octavia-wsgi", line 52, in <module> [Fri Apr 28 10:11:07.512260 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] application = setup_app() [Fri Apr 28 10:11:07.512343 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "/usr/lib/python3/dist-packages/octavia/api/app.py", line 59, in setup_app [Fri Apr 28 10:11:07.512435 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] pecan_config = get_pecan_config() [Fri Apr 28 10:11:07.512513 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "/usr/lib/python3/dist-packages/octavia/api/app.py", line 40, in get_pecan_config [Fri Apr 28 10:11:07.512529 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] return pecan_configuration.conf_from_file(filename) [Fri Apr 28 10:11:07.512543 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "/usr/lib/python3/dist-packages/pecan/configuration.py", line 176, in conf_from_file [Fri Apr 28 10:11:07.512553 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] SourceFileLoader(module_name, abspath).load_module(module_name) [Fri Apr 28 10:11:07.512567 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib._bootstrap_external>", line 522, in _check_name_wrapper [Fri Apr 28 10:11:07.512705 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib._bootstrap_external>", line 1027, in load_module [Fri Apr 28 10:11:07.512725 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib._bootstrap_external>", line 852, in load_module [Fri Apr 28 10:11:07.512737 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib._bootstrap>", line 265, in _load_module_shim [Fri Apr 28 10:11:07.512750 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib._bootstrap>", line 702, in _load [Fri Apr 28 10:11:07.512763 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib._bootstrap>", line 671, in _load_unlocked [Fri Apr 28 10:11:07.512775 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib._bootstrap_external>", line 844, in exec_module [Fri Apr 28 10:11:07.512788 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib._bootstrap_external>", line 981, in get_code [Fri Apr 28 10:11:07.512800 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib._bootstrap_external>", line 911, in source_to_code [Fri Apr 28 10:11:07.512839 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed [Fri Apr 28 10:11:07.512869 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "/usr/lib/python3/dist-packages/octavia/api/config.py", line 1 [Fri Apr 28 10:11:07.512893 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] Copyright 2014 Rackspace [Fri Apr 28 10:11:07.512921 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] ^ [Fri Apr 28 10:11:07.512938 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] IndentationError: unexpected indent
The original /usr/lib/python3/dist-packages/octavia/api/config.py file is added to the bug report. As seen in the file, the first line starts with a comment, but python is trying to run it as code. Removing the first 5 charactersin the file so that string above starts right after the comment yelds the following traceback:
[Wed Apr 26 17:08:22.609980 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] mod_wsgi (pid=330647): Failed to exec Python script file '/usr/bin/octavia-wsgi'. [Wed Apr 26 17:08:22.610114 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] mod_wsgi (pid=330647): Exception occurred processing WSGI script '/usr/bin/octavia-wsgi'. [Wed Apr 26 17:08:22.611039 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] Traceback (most recent call last): [Wed Apr 26 17:08:22.611097 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] File "/usr/bin/octavia-wsgi", line 52, in <module> [Wed Apr 26 17:08:22.611106 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] application = setup_app() [Wed Apr 26 17:08:22.611125 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] File "/usr/lib/python3/dist-packages/octavia/api/app.py", line 59, in setup_app [Wed Apr 26 17:08:22.611135 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] pecan_config = get_pecan_config() [Wed Apr 26 17:08:22.611152 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] File "/usr/lib/python3/dist-packages/octavia/api/app.py", line 40, in get_pecan_config [Wed Apr 26 17:08:22.611160 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] return pecan_configuration.conf_from_file(filename) [Wed Apr 26 17:08:22.611178 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] File "/usr/lib/python3/dist-packages/pecan/configuration.py", line 168, in conf_from_file [Wed Apr 26 17:08:22.611327 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] compiled = compile(f.read(), abspath, 'exec') [Wed Apr 26 17:08:22.611355 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] File "/usr/lib/python3/dist-packages/octavia/api/config.py", line 1 [Wed Apr 26 17:08:22.611381 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] right 2014 Rackspace [Wed Apr 26 17:08:22.611419 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] ^ [Wed Apr 26 17:08:22.611437 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] SyntaxError: invalid syntax
It seems that when the source file is read by python, the first 5 characters are skipped for some reason. Digging deeper, I see no reason for importlib to trim those characters. Internally it uses _io.open_code().read() which should return the entire file without trimming anything
If adding the comment after the 5th char on the first line, the file is read as is should but the error moves to a different file:
[Fri Apr 28 10:20:24.730194 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] mod_wsgi (pid=1316806): Failed to exec Python script file '/usr/bin/octavia-wsgi'. [Fri Apr 28 10:20:24.730379 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] mod_wsgi (pid=1316806): Exception occurred processing WSGI script '/usr/bin/octavia-wsgi'. [Fri Apr 28 10:20:24.732137 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] Traceback (most recent call last): [Fri Apr 28 10:20:24.732294 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] File "/usr/bin/octavia-wsgi", line 52, in <module> [Fri Apr 28 10:20:24.732316 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] application = setup_app() [Fri Apr 28 10:20:24.732340 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] File "/usr/lib/python3/dist-packages/octavia/api/app.py", line 62, in setup_app [Fri Apr 28 10:20:24.732353 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] return pecan_make_app( [Fri Apr 28 10:20:24.732381 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] File "/usr/lib/python3/dist-packages/pecan/__init__.py", line 86, in make_app [Fri Apr 28 10:20:24.732400 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] app = Pecan(root, **kw) [Fri Apr 28 10:20:24.732453 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] File "/usr/lib/python3/dist-packages/pecan/core.py", line 832, in __init__ [Fri Apr 28 10:20:24.732475 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] super(Pecan, self).__init__(*args, **kw) [Fri Apr 28 10:20:24.732516 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] File "/usr/lib/python3/dist-packages/pecan/core.py", line 240, in __init__ [Fri Apr 28 10:20:24.732536 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] root = self.__translate_root__(root) [Fri Apr 28 10:20:24.732582 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] File "/usr/lib/python3/dist-packages/pecan/core.py", line 275, in __translate_root__ [Fri Apr 28 10:20:24.732618 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] module = __import__(name, fromlist=fromlist) [Fri Apr 28 10:20:24.732645 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] File "/usr/lib/python3/dist-packages/octavia/api/root_controller.py", line 24, in <module> [Fri Apr 28 10:20:24.732716 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] from octavia.api.v2 import controllers as v2_controller [Fri Apr 28 10:20:24.732760 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] File "/usr/lib/python3/dist-packages/octavia/api/v2/controllers/__init__.py", line 19, in <module> [Fri Apr 28 10:20:24.732821 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] from octavia.api.v2.controllers import availability_zone_profiles [Fri Apr 28 10:20:24.732908 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] File "/usr/lib/python3/dist-packages/octavia/api/v2/controllers/availability_zone_profiles.py", line 1 [Fri Apr 28 10:20:24.732952 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] Copyright 2019 Verizon Media [Fri Apr 28 10:20:24.733024 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] ^ [Fri Apr 28 10:20:24.733107 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] SyntaxError: invalid syntax
As far as we can tell, this problem appears when importlib reads the file and hands it over incomplete (missing the first 5 chars). This issue only occurs on the Octavia containers and not on the other Openstack services. The other thing is that the fault is not consistent. It happens at Apache2 reload or restart but not everytime. Once in a few restarts. When the problem occurs, Octavia API is down.
Env details: OS: Ubuntu 20.04
Kernel: 5.4.0-147-generic
Openstack: Ussuri
Octavia: ii octavia-api 6.2.2-0ubuntu1 all OpenStack Load Balancer as a Service - API frontend ii octavia-common 6.2.2-0ubuntu1 all OpenStack Load Balancer as a Service - Common files ii octavia-driver-agent 6.2.2-0ubuntu1 all OpenStack Load Balancer Service - Driver Agent ii octavia-health-manager 6.2.2-0ubuntu1 all OpenStack Load Balancer Service - Health manager ii octavia-housekeeping 6.2.2-0ubuntu1 all OpenStack Load Balancer Service - Housekeeping manager ii octavia-worker 6.2.2-0ubuntu1 all OpenStack Load Balancer Service - Worker ii python3-octavia 6.2.2-0ubuntu1 all OpenStack Load Balancer as a Service - Python libraries ii python3-octavia-lib 2.0.0-0ubuntu1 all Library to support Octavia provider drivers ii python3-ovn-octavia-provider 0.1.0-0ubuntu1 all OpenStack Octavia Integration with OVN - Python 3 library
Python: Python 3.8.10
LXD: lxd 5.13-cea5ee2 24758 latest/stable canonical✓ -
A bug was filled on launchpad for this issue: https://bugs.launchpad.net/ubuntu/+source/importlib/+bug/2018011
Thanks! Bug #2018011 “python3 - importlib fails to read first 5 chars fr...” : Bugs : importlib package : Ubuntuhttps://bugs.launchpad.net/ubuntu/+source/importlib/+bug/2018011 A bit of context: we have an Openstack Ussuri deployment (HA) on Ubuntu Focal. Most Openstack services are running on LXD containers on 3 baremetals. There are also two OVN-dedicated-chassis which act as gateways and nova-compute nodes. A couple of days ago we updated all the packages in the environment to the latest versions (baremetals and lxc containers). After the updates, we started seeing problems with the Octavia API. The API would randomly give an internal server error. Octavia API is... bugs.launchpad.net