[Focal] cloud-init service never get nework actived during MaaS deploy.

[ubuntu-server-builder]

This bug was originally filed in Launchpad as LP: #1869181

Launchpad details

affected_projects = ['oem-priority']
assignee = None
assignee_name = None
date_closed = None
date_created = 2020-03-26T11:09:18.855722+00:00
date_fix_committed = 2020-04-08T15:29:51.126221+00:00
date_fix_released = 2020-04-08T15:29:51.126221+00:00
id = 1869181
importance = undecided
is_complete = False
lp_url = https://bugs.launchpad.net/cloud-init/+bug/1869181
milestone = None
owner = alextu
owner_name = Alex Tu
private = False
status = incomplete
submitter = alextu
submitter_name = Alex Tu
tags = ['oem-priority']
duplicates = [1880089]

Launchpad user Alex Tu(alextu) wrote on 2020-03-26T11:09:18.855722+00:00

MaaS server used to wait for cloud-init on target reporting status.
It works well on Bionic desktop but failed on Focal desktop.
It might be caused by the ordering of systemd service because the network service always is started after the cloud-init service.

Journalctl:
三 26 18:34:18 CANONICALID cloud-init[816]: Cloud-init v. 20.1-10-g71af48df-0ubuntu2 running 'init' at Thu, 26 Mar 2020 10:34:18 +0000. Up 6.59 seconds.
三 26 18:34:18 CANONICALID cloud-init[816]: ci-info: ++++++++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++++++++
三 26 18:34:18 CANONICALID cloud-init[816]: ci-info: +-----------------+-------+-----------+-----------+-------+-------------------+
三 26 18:34:18 CANONICALID cloud-init[816]: ci-info: | Device | Up | Address | Mask | Scope | Hw-Address |
三 26 18:34:18 CANONICALID cloud-init[816]: ci-info: +-----------------+-------+-----------+-----------+-------+-------------------+
三 26 18:34:18 CANONICALID cloud-init[816]: ci-info: | enx00e04c70045f | False | . | . | . | 00:e0:4c:70:04:5f |
三 26 18:34:18 CANONICALID cloud-init[816]: ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | host | . |
三 26 18:34:18 CANONICALID cloud-init[816]: ci-info: | lo | True | ::1/128 | . | host | . |
三 26 18:34:18 CANONICALID cloud-init[816]: ci-info: | wlp2s0 | False | . | . | . | 9c:b6:d0:8e:90:81 |
三 26 18:34:18 CANONICALID cloud-init[816]: ci-info: +-----------------+-------+-----------+-----------+-------+-------------------+
.....[skip]....
三 26 18:34:18 CANONICALID cloud-init[816]: 2020-03-26 10:34:18,361 - handlers.py[WARNING]: failed posting event: start: init-network/check-cache: attempting to read from cache [trust]
.....[skip]....
三 26 18:36:25 CANONICALID systemd[1]: Starting Network Manager...

[ubuntu-server-builder]

Launchpad user Paride Legovini(paride) wrote on 2020-03-27T13:43:25.983743+00:00

Hello Alex, is it possible for you to collect the full cloud-init logs (using the cloud-init collect-logs command) and the full NetworkManager logs, and attach them to this report? Thanks!

[ubuntu-server-builder]

Launchpad user Paul Larson(pwlars) wrote on 2020-03-30T17:19:50.568875+00:00

I had this problem with the stock image for both eoan and focal as well. I don't think it's really the "recommended" solution, but the only way to fix it that I've found is to remove "Before=sysinit.target" from /lib/systemd/system/cloud-init.service in the target install. I haven't seen any negative effects from this so far.

[ubuntu-server-builder]

Launchpad user Dan Watkins(oddbloke) wrote on 2020-03-31T15:49:16.218699+00:00

Marking this as Incomplete as we're waiting on the logs requested in comment #1.

[ubuntu-server-builder]

Launchpad user Alex Tu(alextu) wrote on 2020-04-08T07:36:37.050154+00:00

Launchpad attachments: cloud-init.tar.gz

[ubuntu-server-builder]

Launchpad user Alex Tu(alextu) wrote on 2020-04-08T07:37:22.508833+00:00

the NetworkManager logs are covered by journalctl log.
Launchpad attachments: journalctl.log

[ubuntu-server-builder]

Launchpad user Alex Tu(alextu) wrote on 2020-04-08T07:39:21.402027+00:00

Sorry fo reply late due to busy days after vocation.
I provided the logs and changed the state to New for notice.

[ubuntu-server-builder]

Launchpad user Ryan Harper(raharper) wrote on 2020-04-08T15:22:13.823122+00:00

Something related to NetworkManager is preventing systemd-networkd from starting.

networkd-dispatcher[1163]: WARNING: systemd-networkd is not running, output will be incomplete.

Normally after network-pre.target, systemd-networkd-wait-online.service runs
and blocks until systemd-networkd has brough up configured interfaces.
systemd-networkd did not start so when cloud-init.service runs network is
not up like it expects.

systemd[1]: Finished Initial cloud-init job (pre-networking).
systemd[1]: Reached target Network (Pre).
systemd[1]: Starting Initial cloud-init job (metadata service crawler)...
cloud-init[931]: Cloud-init v. 20.1-10-g71af48df-0ubuntu2 running 'init' at Wed, 08 Apr 2020 05:45:26 +0000. Up 31.04 seconds.
cloud-init[931]: ci-info: +++++++++++++++++++++++++++++Net device info+++++++++++++++++++++++++++++
cloud-init[931]: ci-info: +-----------+-------+-----------+-----------+-------+-------------------+
cloud-init[931]: ci-info: | Device | Up | Address | Mask | Scope | Hw-Address |
cloud-init[931]: ci-info: +-----------+-------+-----------+-----------+-------+-------------------+
cloud-init[931]: ci-info: | enp2s0 | False | . | . | . | 6c:2b:59:59:9d:ca |

Notice later, NetworkManager takes over the ethernet device:

kernel: r8169 0000:02:00.0 enp2s0: Link is Up - 1Gbps/Full - flow control rx/tx
kernel: IPv6: ADDRCONF(NETDEV_CHANGE): enp2s0: link becomes ready
NetworkManager[1035]: [1586324867.0369] device (enp2s0): carrier: link connected
NetworkManager[1035]: [1586324867.0380] device (enp2s0): state change: unavailable -> disconnected (reason 'carrier-changed', sys-iface-state: 'managed')
NetworkManager[1035]: [1586324867.0403] policy: auto-activating connection 'netplan-enp2s0' (7ea6f90b-3495-3533-948a-ef0035687c34)
NetworkManager[1035]: [1586324867.0425] device (enp2s0): Activation: starting connection 'netplan-enp2s0' (7ea6f90b-3495-3533-948a-ef0035687c34)
NetworkManager[1035]: [1586324867.0430] device (enp2s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
NetworkManager[1035]: [1586324867.0445] manager: NetworkManager state is now CONNECTING
NetworkManager[1035]: [1586324867.0454] device (enp2s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
NetworkManager[1035]: [1586324867.0470] device (enp2s0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
avahi-daemon[1011]: Joining mDNS multicast group on interface enp2s0.IPv4 with address 192.168.101.86.

The network config maas sends is for Ubuntu Server, which defaults ethernet
devices to be controlled by systemd-networkd; I suspect Desktop has a
different policy in place which puts all network devices in NetworkManager
control, so this config that MAAS sends (also, this MAAS looks old, it's
sending network config v1 (not v2, netplan)).

network:
config:
- id: enp2s0
mac_address: 6c:2b:59:59:9d:ca
mtu: 1500
name: enp2s0
subnets:
- address: 192.168.101.86/24
dns_nameservers:
- 192.168.101.1
dns_search:
- maas
gateway: 192.168.101.1
routes:
- destination: 10.101.46.0/24
gateway: 192.168.101.1
metric: 200
type: static
type: physical
- address:
- 192.168.101.1
search:
- maas
type: nameserver
version: 1

On Focal desktops, this file is now present:

% cat /etc/netplan/01-network-manager-all.yaml

Let NetworkManager manage all devices on this system

network:
version: 2
renderer: NetworkManager

You will need to use a script/preseed to modify this value to
be networkd like this:

network:
version: 2
renderer: networkd

[ubuntu-server-builder]

Launchpad user Ryan Harper(raharper) wrote on 2020-04-08T15:29:50.186166+00:00

Please confirm if such a file is present in the desktop image.

[ubuntu-server-builder]

Launchpad user Alex Tu(alextu) wrote on 2020-04-10T07:29:47.285376+00:00

Thanks a lot! it works with the change of #7.

I can have preseed/script for that change, but also wondering if it is possible to make could-init also natively compatible with the environment that installed NetworkManager.

[ubuntu-server-builder]

Launchpad user Ryan Harper(raharper) wrote on 2020-04-10T15:13:51.341680+00:00

Possibly; what's the origin of the image? Is there an "official" Ubuntu Desktop image? And if so, does it only have network-manager? or both? Can we get the tarball of the image you're deploying?

I suspect there is a netplan bug here for network-manager renderer where it does not add the network-manager-wait-online.service into the correct targets (they should run before network-online.target) so that NM can bring up networking before the target).

[ubuntu-server-builder]

Launchpad user Alex Tu(alextu) wrote on 2020-04-14T12:34:57.726239+00:00

I would like to revise #9, the steps of original test I did is:

1. trigger the maas deploy and wait until 1st login after provision done.
2. MaaS still show deploying when I manually login to target machine.
3. manually apply the change of Travis lint #7 then reboot.
4. this reboot responded MaaS and the status be changed to deployed on MaaS.

But when I just inject the change of #7 into MaaS image to let the change is there before 1st login, the network will never up. So, I can not just use the change of #7 so far.

The origin of the image is OEM image which is almost the same as stock Ubuntu Focal but added dell-recovery. And we just let the deployed machine to 1st boot into recovery mode to install cloud-init related packages then target machine can response to MaaS server in next boot.(which way learned from certification team SRU process)

For the question: "And if so, does it only have network-manager? or both?"
Just have a check that both networkd-dispatcher and network-manager be installed (which is same as stock Ubuntu desktop)

• dpkg -l : https://paste.ubuntu.com/p/5m5wsq9y5g/

I can share the tarball but it is 3GB. I'm not sure if I can attach so big file on launchpad. I will try. BTW, the nature of dell-recovery will block out machines not produced by Dell. I am afraid you can not test it if you don't have a Dell laptop.

For MaaS image converted from official stock Ubuntu desktop, pwlars might have more experience to me because the certification team used to need it for SRU as well.

[ubuntu-server-builder]

Launchpad user Ryan Harper(raharper) wrote on 2020-04-14T15:42:13.560411+00:00

Thanks for the additional details.

From the logs and some local testing, the best choice for
getting things to work with the desktop image via MAAS is

to remove the 01-network-manager-all.yaml file before rebooting into the
target. This will allow networking to be fully managed by networkd.

We will likely need to file some bugs to get NetworkManager and cloud-init
and netplan to work together.

1. NetworkManager.service and NetworkManager-wait-online.service run too late
   to work with cloud-init, This can be fixed by

   a) Adding DefaultDependencies=no to both NM service files
   b) cloud-init.service also adds a After=NetworkManager-wait-online.service

   Note, both of these changes can be done via systemd-drop in files but
   ideally they would go into the package itself.

2. The rendered NM configuration is not complete enough to auto enable
   the configuration.

cloud-init writes a netplan config file and calls netplan generate which
with NetworkManager renderer populates /run/NetworkManager with config

find /run/NetworkManager/ -type f

/run/NetworkManager/resolv.conf
/run/NetworkManager/no-stub-resolv.conf
/run/NetworkManager/devices/30
/run/NetworkManager/conf.d/10-globally-managed-devices.conf
/run/NetworkManager/system-connections/netplan-eth0.nmconnection

NetworkManager.service comes up and it can "see" an 'eth0' connection
and a 'netplan-eth0' connection. The 'eth0' connection is enabled.

nmcli conn

NAME UUID TYPE DEVICE
eth0 e8ffebad-dba7-4035-a9a8-29d9e004e6c1 ethernet eth0
netplan-eth0 626dd384-8b3d-3690-9511-192b2c79b3fd ethernet --

eth0 has no IP (it's configured for dhcp)

After running netplan apply, we can see this change

netplan --debug apply

** (generate:476): DEBUG: 15:39:02.332: Processing input file /etc/netplan/01-network-manager-all.yaml..
** (generate:476): DEBUG: 15:39:02.332: starting new processing pass
** (generate:476): DEBUG: 15:39:02.332: Processing input file /etc/netplan/50-cloud-init.yaml..
** (generate:476): DEBUG: 15:39:02.332: starting new processing pass
** (generate:476): DEBUG: 15:39:02.332: eth0: setting default backend to 2
** (generate:476): DEBUG: 15:39:02.332: Configuration is valid
** (generate:476): DEBUG: 15:39:02.332: Generating output files..
** (generate:476): DEBUG: 15:39:02.332: networkd: definition eth0 is not for us (backend 2)
(generate:476): GLib-DEBUG: 15:39:02.332: posix_spawn avoided (fd close requested)
DEBUG:netplan generated networkd configuration changed, restarting networkd
DEBUG:netplan generated NM configuration changed, restarting NM
DEBUG:eth0 not found in {}
DEBUG:Merged config:
network:
bonds: {}
bridges: {}
ethernets:
eth0:
dhcp4: true
match:
macaddress: 00:16:3e:0d:4c:a7
set-name: eth0
vlans: {}
wifis: {}

DEBUG:Skipping non-physical interface: lo
DEBUG:device eth0 operstate is up, not changing
DEBUG:{}
DEBUG:netplan triggering .link rules for lo
DEBUG:netplan triggering .link rules for eth0

nmcli conn

NAME UUID TYPE DEVICE
netplan-eth0 626dd384-8b3d-3690-9511-192b2c79b3fd ethernet eth0

Looking into NM logs, there is a auto-enable policy that netplan apply
triggers that does not seem to happen with just restarting NM.

journalctl -o short-precise -b -u NetworkManager.service | grep policy

Apr 14 15:39:02.871859 f6 NetworkManager[520]: [1586878742.8718] policy: auto-activating connection 'netplan-eth0' (626dd384-8b3d-3690-9511-192b2c79b3fd)
Apr 14 15:39:02.887910 f6 NetworkManager[520]: [1586878742.8878] policy: set 'netplan-eth0' (eth0) as default for IPv4 routing and DNS

I don't think cloud-init itself should have to run 'netplan apply'; we don't
do this for networkd backend.