python3 - importlib fails to read first 5 chars from file
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
octavia |
Invalid
|
Undecided
|
Unassigned | ||
openvswitch |
New
|
Undecided
|
Unassigned | ||
importlib (Ubuntu) |
Incomplete
|
Undecided
|
Unassigned | ||
octavia (Ubuntu) |
Incomplete
|
Undecided
|
Unassigned | ||
openvswitch (Ubuntu) |
Incomplete
|
Undecided
|
Unassigned |
Bug Description
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-
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/
[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/
[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/
[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/
[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/
[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/
[Fri Apr 28 10:11:07.512529 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] return pecan_configura
[Fri Apr 28 10:11:07.512543 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "/usr/lib/
[Fri Apr 28 10:11:07.512553 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] SourceFileLoade
[Fri Apr 28 10:11:07.512567 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib.
[Fri Apr 28 10:11:07.512705 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib.
[Fri Apr 28 10:11:07.512725 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib.
[Fri Apr 28 10:11:07.512737 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib.
[Fri Apr 28 10:11:07.512750 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib.
[Fri Apr 28 10:11:07.512763 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib.
[Fri Apr 28 10:11:07.512775 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib.
[Fri Apr 28 10:11:07.512788 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib.
[Fri Apr 28 10:11:07.512800 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib.
[Fri Apr 28 10:11:07.512839 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "<frozen importlib.
[Fri Apr 28 10:11:07.512869 2023] [wsgi:error] [pid 1312420:tid 140012169602816] [remote 127.0.0.1:59914] File "/usr/lib/
[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/
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/
[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/
[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/
[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/
[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/
[Wed Apr 26 17:08:22.611160 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] return pecan_configura
[Wed Apr 26 17:08:22.611178 2023] [wsgi:error] [pid 330647:tid 140629468657408] [remote 127.0.0.1:55142] File "/usr/lib/
[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/
[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_
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/
[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/
[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/
[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/
[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/
[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/
[Fri Apr 28 10:20:24.732475 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] super(Pecan, self)._
[Fri Apr 28 10:20:24.732516 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] File "/usr/lib/
[Fri Apr 28 10:20:24.732536 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] root = self.__
[Fri Apr 28 10:20:24.732582 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] File "/usr/lib/
[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/
[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/
[Fri Apr 28 10:20:24.732821 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] from octavia.
[Fri Apr 28 10:20:24.732908 2023] [wsgi:error] [pid 1316806:tid 140384699016960] [remote 127.0.0.1:41802] File "/usr/lib/
[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-
ii octavia-
ii octavia-
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-
Python: Python 3.8.10
LXD:
lxd 5.13-cea5ee2 24758 latest/stable canonical✓ -
Status changed to 'Confirmed' because the bug affects multiple users.