cloud-init startup failure with Python 3.9.5, Ubuntu Focal

[Rilindo Foster]

---- Summary -----

Ubuntu Release:

Distributor ID: Ubuntu
Description: Ubuntu 20.04.6 LTS
Release: 20.04
Codename: focal

Package Version: 24.1.3-0ubuntu1~20.04.1

Expected behavior: cloud-init should (re)start up successfully after an update.

Actual behavior: cloud-init did not (re)start up successfully after an update.

---- Summary -----

The details.

It appears that is a breaking change with 24.1.3-0ubuntu1~20.04.1 if you have Python 3.9.5 install on Ubuntu Focal (20.04)

To reproduce:

Verify that you have python 3.9.5 and a previously working copy of cloud-init:

root@ip-SOME-IP-ADDRESS:~# python --version
Python 3.9.5
root@ip-SOME-IP-ADDRESS:~# dpkg --list | grep cloud-init
ii cloud-init 23.4.4-0ubuntu0~20.04.1 all initialization and customization tool for cloud instances
ii cloud-initramfs-copymods 0.45ubuntu2 all copy initramfs modules into root filesystem for later use
ii cloud-initramfs-dyn-netconf 0.45ubuntu2 all write a network interface file in /run for BOOTIF

Restart service to confirm it can persist:

root@ip-SOME-IP-ADDRESS:~# systemctl restart cloud-init
root@ip-SOME-IP-ADDRESS:~# systemctl status cloud-init
● cloud-init.service - Initial cloud-init job (metadata service crawler)
     Loaded: loaded (/lib/systemd/system/cloud-init.service; enabled; vendor preset: enabled)
     Active: active (exited) since Thu 2024-05-16 22:31:38 EDT; 4s ago
    Process: 412986 ExecStart=/usr/bin/cloud-init init (code=exited, status=0/SUCCESS)
   Main PID: 412986 (code=exited, status=0/SUCCESS)
      Tasks: 0 (limit: 18814)
     Memory: 168.0K
     CGroup: /system.slice/cloud-init.service

May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: +-------+-------------+-------------+-----------------+-----------+-------+
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: +-------+-------------+---------+-----------+-------+
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: | Route | Destination | Gateway | Interface | Flags |
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: +-------+-------------+---------+-----------+-------+
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: | 1 | fe80::/64 | :: | ens5 | U |
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: | 3 | local | :: | ens5 | U |
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: | 4 | multicast | :: | ens5 | U |
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: +-------+-------------+---------+-----------+-------+
May 16 22:31:38 ip-SOME-IP-ADDRESS systemd[1]: Finished Initial cloud-init job (metadata service crawler).

Then upgrade:

root@ip-SOME-IP-ADDRESS:~# apt install cloud-init
Reading package lists... Done
Building dependency tree
Reading state information... Done
The following packages will be upgraded:
  cloud-init
1 upgraded, 0 newly installed, 0 to remove and 40 not upgraded.
Need to get 563 kB of archives.
After this operation, 55.3 kB of additional disk space will be used.
Get:1 https://deb.MYCOMPANYREPO.com/REPOPROVIDER/MYCOMPANYREPO-ubuntu-release-virtual focal-updates/main amd64 cloud-init all 24.1.3-0ubuntu1~20.04.1 [563 kB]
Fetched 563 kB in 0s (1603 kB/s)
Preconfiguring packages ...
(Reading database ... 170522 files and directories currently installed.)
Preparing to unpack .../cloud-init_24.1.3-0ubuntu1~20.04.1_all.deb ...
Unpacking cloud-init (24.1.3-0ubuntu1~20.04.1) over (23.4.4-0ubuntu0~20.04.1) ...
Setting up cloud-init (24.1.3-0ubuntu1~20.04.1) ...

Configuration file '/etc/cloud/cloud.cfg'
 ==> Modified (by you or by a script) since installation.
 ==> Package distributor has shipped an updated version.
   What would you like to do about it ? Your options are:
    Y or I : install the package maintainer's version
    N or O : keep your currently-installed version
      D : show the differences between the versions
      Z : start a shell to examine the situation
 The default action is to keep your current version.
*** cloud.cfg (Y/I/N/O/D/Z) [default=N] ?
Installing new version of config file /etc/cloud/cloud.cfg.d/05_logging.cfg ...
Installing new version of config file /etc/cloud/templates/chrony.conf.cos.tmpl ...
Installing new version of config file /etc/cloud/templates/chrony.conf.debian.tmpl ...
Installing new version of config file /etc/cloud/templates/chrony.conf.ubuntu.tmpl ...
Installing new version of config file /etc/cloud/templates/hosts.alpine.tmpl ...
Installing new version of config file /etc/cloud/templates/hosts.mariner.tmpl ...
Installing new version of config file /etc/cloud/templates/ntp.conf.ubuntu.tmpl ...
Installing new version of config file /etc/cloud/templates/sources.list.ubuntu.deb822.tmpl ...
Installing new version of config file /etc/profile.d/Z99-cloud-locale-test.sh ...
Removing obsolete conffile /etc/cloud/clean.d/README ...
Processing triggers for man-db (2.9.1-1) ...
Processing triggers for rsyslog (8.2001.0-1ubuntu1.3) ...
root@ip-SOME-IP-ADDRESS:~# systemctl status cloud-init
● cloud-init.service - Initial cloud-init job (metadata service crawler)
     Loaded: loaded (/lib/systemd/system/cloud-init.service; enabled; vendor preset: enabled)
     Active: active (exited) since Thu 2024-05-16 22:31:38 EDT; 35s ago
   Main PID: 412986 (code=exited, status=0/SUCCESS)
      Tasks: 0 (limit: 18814)
     Memory: 168.0K
     CGroup: /system.slice/cloud-init.service

May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: +-------+-------------+---------+-----------+-------+
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: | Route | Destination | Gateway | Interface | Flags |
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: +-------+-------------+---------+-----------+-------+
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: | 1 | fe80::/64 | :: | ens5 | U |
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: | 3 | local | :: | ens5 | U |
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: | 4 | multicast | :: | ens5 | U |
May 16 22:31:38 ip-SOME-IP-ADDRESS cloud-init[412990]: ci-info: +-------+-------------+---------+-----------+-------+
May 16 22:31:38 ip-SOME-IP-ADDRESS systemd[1]: Finished Initial cloud-init job (metadata service crawler).
May 16 22:31:52 ip-SOME-IP-ADDRESS systemd[1]: /lib/systemd/system/cloud-init.service:19: Unknown key name 'ConditionEnvironment' in section 'Unit', ignoring.
May 16 22:32:05 ip-SOME-IP-ADDRESS systemd[1]: /lib/systemd/system/cloud-init.service:19: Unknown key name 'ConditionEnvironment' in section 'Unit', ignoring.

Now restart. You will see it will return a failure:

root@ip-SOME-IP-ADDRESS:~# systemctl restart cloud-init
Job for cloud-init.service failed because the control process exited with error code.
See "systemctl status cloud-init.service" and "journalctl -xe" for details.
root@ip-SOME-IP-ADDRESS:~# systemctl status cloud-init
● cloud-init.service - Initial cloud-init job (metadata service crawler)
     Loaded: loaded (/lib/systemd/system/cloud-init.service; enabled; vendor preset: enabled)
     Active: failed (Result: exit-code) since Thu 2024-05-16 22:32:18 EDT; 2s ago
    Process: 413683 ExecStart=/usr/bin/cloud-init init (code=exited, status=1/FAILURE)
   Main PID: 413683 (code=exited, status=1/FAILURE)

May 16 22:32:18 ip-SOME-IP-ADDRESS cloud-init[413683]: File "/usr/lib/python3/dist-packages/cloudinit/stages.py", line 34, in <module>
May 16 22:32:18 ip-SOME-IP-ADDRESS cloud-init[413683]: from cloudinit.handlers.jinja_template import JinjaTemplatePartHandler
May 16 22:32:18 ip-SOME-IP-ADDRESS cloud-init[413683]: File "/usr/lib/python3/dist-packages/cloudinit/handlers/jinja_template.py", line 14, in <module>
May 16 22:32:18 ip-SOME-IP-ADDRESS cloud-init[413683]: from cloudinit.templater import (
May 16 22:32:18 ip-SOME-IP-ADDRESS cloud-init[413683]: File "/usr/lib/python3/dist-packages/cloudinit/templater.py", line 21, in <module>
May 16 22:32:18 ip-SOME-IP-ADDRESS cloud-init[413683]: from jinja2 import TemplateSyntaxError
May 16 22:32:18 ip-SOME-IP-ADDRESS cloud-init[413683]: ModuleNotFoundError: No module named 'jinja2'
May 16 22:32:18 ip-SOME-IP-ADDRESS systemd[1]: cloud-init.service: Main process exited, code=exited, status=1/FAILURE
May 16 22:32:18 ip-SOME-IP-ADDRESS systemd[1]: cloud-init.service: Failed with result 'exit-code'.
May 16 22:32:18 ip-SOME-IP-ADDRESS systemd[1]: Failed to start Initial cloud-init job (metadata service crawler).
root@ip-SOME-IP-ADDRESS:~# dpkg --list | grep cloud-init
ii cloud-init 24.1.3-0ubuntu1~20.04.1 all initialization and customization tool for cloud instances
ii cloud-initramfs-copymods 0.45ubuntu2 all copy initramfs modules into root filesystem for later use
ii cloud-initramfs-dyn-netconf 0.45ubuntu2 all write a network interface file in /run for BOOTIF

Workaround:

We downgraded to 23.4.4-0ubuntu0~20.04.1 and put the package on hold (pinned ubuntu version)

Actual Behavior: cloud-init did not, in fact, (re)start up successfully after an update.

[Rilindo Foster (fosterr)]

Note: We are running off the official Ubuntu provided image on AWS. Here is the URL and AMI

https://console.aws.amazon.com/ec2/home?region=us-east-1#launchAmi=ami-0e3a6d8ff4c8fe246

[James Falcon (falcojr)]

How are you running Python 3.9 in Focal? Are you using the cloud-init package provided by Apt? Your error shows a crash due to the jinja2 library not existing, but jinja2 is a dependency of cloud-init. The python3-jinja2 package should have been installed when you installed cloud-init. Up until now, cloud-init could still run without this dependency installed, but that doesn't change that it has been a dependency, so I don't see evidence of a problem here.

[Rilindo Foster (fosterr)]

To answer:

> How are you running Python 3.9 in Focal?

We installed Python 3.9 from Focal's upstream. No third party.

> Are you using the cloud-init package provided by Apt?

Yes, because we started to see the issue after the OS update. We switch AMIs, thinking that the OS update was problematic (which is was, but not the way we thought)

> Your error shows a crash due to the jinja2 library not existing, but jinja2 is a dependency of cloud-init. The python3-jinja2 package should have been installed when you installed cloud-init. Up until now, cloud-init could still run without this dependency installed, but that doesn't change that it has been a dependency, so I don't see evidence of a problem here.

We wouldn't know that python3-jinja2 is required, as we don't usually manage cloud-init - we generally left it alone - at least until the issue began. We can test to see if installing python3-jinja2 moved us forward. Standby.

[James Falcon (falcojr)]

"We can test to see if installing python3-jinja2 moved us forward. Standby."

That's good if that works, but I'm still not sure how this situation happened. If I run `apt depends cloud-init`, I see `Depends: python3-jinja2` as one of the dependencies. That means that even if python3-jinja2 wasn't previously installed, it should get installed by apt when upgrading cloud-init, and it is already included when launching an EC2 Focal instance. The library should get written to /usr/lib/python3/dist-packages/jinja2, so even if you've installed python3.9 over the default system python, it should still be found regardless of the python version used.

Do you have the system `python3` or `python` pointing directly to python3.9? If so, how did it get setup? Is there any other customization of your environment that you think could be affecting this?

[Rilindo Foster (fosterr)]

As it turns out, python3-jinja2 is installed. This is output after the upgrade to cloud-init

root@IP-INSTANCE-REDACT:~# systemctl status cloud-init
● cloud-init.service - Initial cloud-init job (metadata service crawler)
     Loaded: loaded (/lib/systemd/system/cloud-init.service; enabled; vendor preset: enabled)
     Active: failed (Result: exit-code) since Tue 2024-05-21 15:41:26 EDT; 5s ago
    Process: 523670 ExecStart=/usr/bin/cloud-init init (code=exited, status=1/FAILURE)
   Main PID: 523670 (code=exited, status=1/FAILURE)

May 21 15:41:26 IP-INSTANCE-REDACT cloud-init[523670]: File "/usr/lib/python3/dist-packages/cloudinit/stages.py", line 34, in <module>
May 21 15:41:26 IP-INSTANCE-REDACT cloud-init[523670]: from cloudinit.handlers.jinja_template import JinjaTemplatePartHandler
May 21 15:41:26 IP-INSTANCE-REDACT cloud-init[523670]: File "/usr/lib/python3/dist-packages/cloudinit/handlers/jinja_template.py", line 14, in <module>
May 21 15:41:26 IP-INSTANCE-REDACT cloud-init[523670]: from cloudinit.templater import (
May 21 15:41:26 IP-INSTANCE-REDACT cloud-init[523670]: File "/usr/lib/python3/dist-packages/cloudinit/templater.py", line 21, in <module>
May 21 15:41:26 IP-INSTANCE-REDACT cloud-init[523670]: from jinja2 import TemplateSyntaxError
May 21 15:41:26 IP-INSTANCE-REDACT cloud-init[523670]: ModuleNotFoundError: No module named 'jinja2'
May 21 15:41:26 IP-INSTANCE-REDACT systemd[1]: cloud-init.service: Main process exited, code=exited, status=1/FAILURE
May 21 15:41:26 IP-INSTANCE-REDACT systemd[1]: cloud-init.service: Failed with result 'exit-code'.
May 21 15:41:26 IP-INSTANCE-REDACT systemd[1]: Failed to start Initial cloud-init job (metadata service crawler).
root@IP-INSTANCE-REDACT:~# apt install python3-jinja2
Reading package lists... Done
Building dependency tree
Reading state information... Done
python3-jinja2 is already the newest version (2.10.1-2ubuntu0.2).
0 upgraded, 0 newly installed, 0 to remove and 2 not upgraded.
root@IP-INSTANCE-REDACT:~# dpkg --list | grep cloud-init
ii cloud-init 24.1.3-0ubuntu1~20.04.1 all initialization and customization tool for cloud instances
ii cloud-initramfs-copymods 0.45ubuntu2 all copy initramfs modules into root filesystem for later use
ii cloud-initramfs-dyn-netconf 0.45ubuntu2 all write a network interface file in /run for BOOTIF

By way of comparison, I upgrade cloud-init on a machine *without* python3.9 and that restarted successfully:

root@IP-INSTANCE-REDACT:~# dpkg --list | grep cloud-init
ii cloud-init 23.3.3-0ubuntu0~20.04.1 all initialization and customization tool for cloud instances
ii cloud-initramfs-copymods 0.45ubuntu2 all copy initramfs modules into root filesystem for later use
ii cloud-initramfs-dyn-netconf 0.45ubuntu2 all write a network interface file in /run for BOOTIF
root@IP-INSTANCE-REDACT:~# install ^C
You have new mail in /var/mail/root
root@IP-INSTANCE-REDACT:~# apt install cloud-init
Reading p...

[Rilindo Foster (fosterr)]

To answer your question, we usually installed python3.9 on Ubuntu 20.04 like so:

    DEBIAN_FRONTEND=noninteractive apt-get -y install -m -f python3.9 python3.9-distutils
    update-alternatives --install /usr/bin/python python /usr/bin/python3.9 10
    curl https://bootstrap.pypa.io/get-pip.py -o get-pip.py
    python get-pip.py

After the issue was discovered, we work around the issue as follows:

    DEBIAN_FRONTEND=noninteractive apt-get install -y cloud-init=23.1.2-0ubuntu0~20.04.2 --allow-downgrades
    apt-mark hold cloud-init
    DEBIAN_FRONTEND=noninteractive apt-get -y install -m -f python3.9 python3.9-distutils
    update-alternatives --install /usr/bin/python python /usr/bin/python3.9 10
    curl https://bootstrap.pypa.io/get-pip.py -o get-pip.py
    python3.9 get-pip.py

[Rilindo Foster (fosterr)]

TLDR; when we install python3.9, we point /usr/bin/python to 3.9, but not /usr/bin/python3

[James Falcon (falcojr)]

"when we install python3.9, we point /usr/bin/python to 3.9, but not /usr/bin/python3"

cloud-init does use `python3` and not `python`, though I'm not sure that would change anything.

$ head -1 /usr/bin/cloud-init
#!/usr/bin/python3

Since we can launch the AMI and cloud-init works ok out of the box using the supported version of python, this appears to be an issue with how the environment is getting customized. Since we're still not entirely sure of the root cause, I'll leave the bug state as Incomplete, but unless we can get more information as to why the python3-jinja2 package isn't being seen in your cloud-init environment and that the cloud-init package is doing something wrong here, it doesn't look like there's anything to fix.

[Rilindo Foster (fosterr)]

What is considered a supported version of Python? Would Python3.9 from upstream be considered a supported version?

That said, I re-tested today and it appears that the issue no longer exists. Interestingly enough, there was a new image that was released yesterday - ami-03e9149278a6f457c (Date 20240521)

root@ip-IP-MASKED:~# apt-cache search python3.9
python3-distutils - distutils package for Python 3.x
python3-gdbm - GNU dbm database support for Python 3.x
python3-lib2to3 - Interactive high-level object-oriented language (lib2to3)
python3-tk - Tkinter - Writing Tk applications with Python 3.x
idle-python3.9 - IDE for Python (v3.9) using Tkinter
libpython3.9 - Shared Python runtime library (version 3.9)
libpython3.9-dbg - Debug Build of the Python Interpreter (version 3.9)
libpython3.9-dev - Header files and a static library for Python (v3.9)
libpython3.9-minimal - Minimal subset of the Python language (version 3.9)
libpython3.9-stdlib - Interactive high-level object-oriented language (standard library, version 3.9)
libpython3.9-testsuite - Testsuite for the Python standard library (v3.9)
python3.9 - Interactive high-level object-oriented language (version 3.9)
python3.9-dbg - Debug Build of the Python Interpreter (version 3.9)
python3.9-dev - Header files and a static library for Python (v3.9)
python3.9-doc - Documentation for the high-level object-oriented language Python (v3.9)
python3.9-examples - Examples for the Python language (v3.9)
python3.9-full - Python Interpreter with complete class library (version 3.9)
python3.9-minimal - Minimal subset of the Python language (version 3.9)
python3.9-venv - Interactive high-level object-oriented language (pyvenv binary, version 3.9)
root@ip-IP-MASKED:~# systemctl status cloud-init
● cloud-init.service - Initial cloud-init job (metadata service crawler)
     Loaded: loaded (/lib/systemd/system/cloud-init.service; enabled; vendor preset: enabled)
     Active: active (exited) since Wed 2024-05-22 15:52:27 UTC; 3min 58s ago
   Main PID: 433 (code=exited, status=0/SUCCESS)
      Tasks: 0 (limit: 4618)
     Memory: 0B
     CGroup: /system.slice/cloud-init.service

May 22 15:52:27 ip-IP-MASKED cloud-init[437]: | . . +|
May 22 15:52:27 ip-IP-MASKED cloud-init[437]: | . .So.. o+o|
May 22 15:52:27 ip-IP-MASKED cloud-init[437]: | + o+..o o+o|
May 22 15:52:27 ip-IP-MASKED cloud-init[437]: | o oB.+o o+=.|
May 22 15:52:27 ip-IP-MASKED cloud-init[437]: | =ooX*..oo+=|
May 22 15:52:27 ip-IP-MASKED cloud-init[437]: | =@O. oo.=|
May 22 15:52:27 ip-IP-MASKED cloud-init[437]: +----[SHA256]-----+
May 22 15:52:27 ip-IP-MASKED systemd[1]: Finished Initial cloud-init job (metadata service crawler).
May 22 15:52:30 ip-IP-MASKED systemd[1]: /lib/systemd/system/cloud-init.service:19: Unknown key name 'ConditionEnvironment' in section 'Unit', ignoring.
May 22 15:52:32 ip-IP-MASKED systemd[1]: /lib/systemd/system/cloud-init.service:19: Unknown key name 'ConditionEnvironment' in section 'Unit', ignoring.
root@ip-IP-MASKED:~# apt install python3.9
Reading package lists... Done
Building dependency tree
Reading state information... Done
The following additional packages will be installed:
  ...

[James Falcon (falcojr)]

The version of Python that is shipped with Ubuntu is what is supported for the system. In the case of Focal, that is 3.8. It is fine to install and use Python 3.9 for user applications, but when you run `update-alternatives` to replace the default version of Python, you are now forcing packages that were expecting to use Python 3.8 to instead use Python 3.9.

[Rilindo Foster (fosterr)]

I think that make sense. I think we don't actual need to make the python3.9 the default for what we are trying to do originally. That said, even when we didn't make python3.9 the default, it was still breaking. :confused:

At any event, I'll going to revert the change at some point and get back to you. Of note that when we manually went through the process of performing the initial customization, we have not been able to reproduce the issue either.