[Bug 2008952] Re: DNS failure while trying to fetch user-data

Chad Smith 2008952 at bugs.launchpad.net
Tue Mar 14 23:38:36 UTC 2023 

TLDR: My earlier suggestion to retry in cloud-init.service while
awaiting DNS is not viable when thinking about NetworkManager.
NetworkManager.service is After=sysinit.target due to After=dbus.service
and cloud-init.service is Before=sysinit.target. NetworkManager is the
only service bringing up the primary NIC in desktop images which gives
cloud-init access to a functional DNS. Unless we can move
NetworkManager.service before sysinit.target, I don't think we don't
think we can leverage DNS.


In review of a KVM live desktop boot in which cloud-init.service defines After=systemd-resolved.service We can see that cloud-init.service still blocks start of NetworkManager (due to After=sysinit.target) and DNS is not active until enp1s0 is actually brought up by NetworkManager.


Here are snippets of the journalctl logs on a local KVM boot where we can see systemd-resolved coming up, then cloud-init.service with 30 retries and finally NetworkManager.service starting after cloud-init.service failed to download the metadata due to DNS resolution errors:

1. systemd-resolved "starts" @22:14:42.302181, which unblocks cloud-init.service
2. cloud-init.service @22:14:42.690949 (which emits that enp1s0's link is not actually up yet so no viable DNS at that time)
3. NetworkManager.service starting @22:15:16.012686up only after cloud-init.service finishes 30 seconds of retries @22:15:16.012686
4. systemd-resolved finally getting a viable DNS route through enp1s0 @22:15:19.630090 ubuntu systemd-resolved[1136]: enp1s0: Bus client set DNS server list to: 192.168.122.1
5. Network manager finally sees enp1s0 device activated @22:15:19.632846
6. NetworkManager-wait-online.service finally gets to CONNECTED status @22:15:19.637543


--- journalctl -b 0 -o short-precise | egrep 'enp1s0|resolved|NetworkManager|ci-info'
Mar 14 22:14:39.167190 ubuntu kernel: virtio_net virtio0 enp1s0: renamed from eth0
Mar 14 22:14:41.451373 ubuntu systemd[1]: Starting systemd-resolved.service - Network Name Resolution...
Mar 14 22:14:42.253268 ubuntu systemd-resolved[1136]: Positive Trust Anchors:
Mar 14 22:14:42.253583 ubuntu systemd-resolved[1136]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d
Mar 14 22:14:42.253685 ubuntu systemd-resolved[1136]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa corp home internal intranet lan local private test
Mar 14 22:14:42.300435 ubuntu systemd-resolved[1136]: Using system hostname 'ubuntu'.
Mar 14 22:14:42.302181 ubuntu systemd[1]: Started systemd-resolved.service - Network Name Resolution.
### cloud-init noticing enp1s0 has no link
Mar 14 22:14:42.690949 ubuntu cloud-init[1341]: ci-info: | enp1s0 | False |     .     |     .     |   .   | 52:54:00:5b:ba:d5 |
Mar 14 22:15:16.012686 ubuntu systemd[1]: Starting NetworkManager.service - Network Manager...
Mar 14 22:15:16.285604 ubuntu NetworkManager[1546]: <info>  [1678832116.2854] NetworkManager (version 1.40.12) is starting... (boot:1f3e11ab-fea1-4f3e-a6ef-fb9d48b0c4d6)
Mar 14 22:15:16.285972 ubuntu NetworkManager[1546]: <info>  [1678832116.2859] Read config: /etc/NetworkManager/NetworkManager.conf (lib: 10-dns-resolved.conf, 20-connectivity-ubuntu.conf, no-mac-addr-change.conf) (run: 10-globally-managed-devices.conf) (etc: default-wifi-powersave-on.conf)
Mar 14 22:15:16.302542 ubuntu systemd[1]: Started NetworkManager.service - Network Manager.
Mar 14 22:15:16.303605 ubuntu NetworkManager[1546]: <info>  [1678832116.3035] bus-manager: acquired D-Bus service "org.freedesktop.NetworkManager"
Mar 14 22:15:16.316514 ubuntu systemd[1]: Starting NetworkManager-wait-online.service - Network Manager Wait Online...
Mar 14 22:15:16.354249 ubuntu NetworkManager[1546]: <info>  [1678832116.3542] manager[0x5629cd53f000]: monitoring kernel firmware directory '/lib/firmware'.
Mar 14 22:15:16.354423 ubuntu NetworkManager[1546]: <info>  [1678832116.3544] monitoring ifupdown state file '/run/network/ifstate'.
Mar 14 22:15:16.356985 ubuntu dbus-daemon[1490]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.14' (uid=0 pid=1546 comm="/usr/sbin/NetworkManager --no-daemon" label="unconfined")
Mar 14 22:15:16.527848 ubuntu NetworkManager[1546]: <info>  [1678832116.5278] hostname: hostname: using hostnamed
Mar 14 22:15:16.527869 ubuntu NetworkManager[1546]: <info>  [1678832116.5278] hostname: static hostname changed from (none) to "ubuntu"
Mar 14 22:15:16.528346 ubuntu NetworkManager[1546]: <info>  [1678832116.5283] dns-mgr: init: dns=systemd-resolved rc-manager=unmanaged (auto), plugin=systemd-resolved
Mar 14 22:15:16.531098 ubuntu NetworkManager[1546]: <info>  [1678832116.5310] manager[0x5629cd53f000]: rfkill: Wi-Fi hardware radio set enabled
Mar 14 22:15:16.531208 ubuntu NetworkManager[1546]: <info>  [1678832116.5311] manager[0x5629cd53f000]: rfkill: WWAN hardware radio set enabled
Mar 14 22:15:16.536471 ubuntu NetworkManager[1546]: <info>  [1678832116.5364] Loaded device plugin: NMAtmManager (/usr/lib/x86_64-linux-gnu/NetworkManager/1.40.12/libnm-device-plugin-adsl.so)
Mar 14 22:15:16.546189 ubuntu NetworkManager[1546]: <info>  [1678832116.5461] Loaded device plugin: NMBluezManager (/usr/lib/x86_64-linux-gnu/NetworkManager/1.40.12/libnm-device-plugin-bluetooth.so)
Mar 14 22:15:16.551128 ubuntu NetworkManager[1546]: <info>  [1678832116.5511] Loaded device plugin: NMTeamFactory (/usr/lib/x86_64-linux-gnu/NetworkManager/1.40.12/libnm-device-plugin-team.so)
Mar 14 22:15:16.553375 ubuntu NetworkManager[1546]: <info>  [1678832116.5533] Loaded device plugin: NMWifiFactory (/usr/lib/x86_64-linux-gnu/NetworkManager/1.40.12/libnm-device-plugin-wifi.so)
Mar 14 22:15:16.553688 ubuntu NetworkManager[1546]: <info>  [1678832116.5536] Loaded device plugin: NMWwanFactory (/usr/lib/x86_64-linux-gnu/NetworkManager/1.40.12/libnm-device-plugin-wwan.so)
Mar 14 22:15:16.554369 ubuntu NetworkManager[1546]: <info>  [1678832116.5543] manager: rfkill: Wi-Fi enabled by radio killswitch; enabled by state file
Mar 14 22:15:16.554716 ubuntu NetworkManager[1546]: <info>  [1678832116.5547] manager: rfkill: WWAN enabled by radio killswitch; enabled by state file
Mar 14 22:15:16.555036 ubuntu NetworkManager[1546]: <info>  [1678832116.5550] manager: Networking is enabled by state file
Mar 14 22:15:16.556335 ubuntu dbus-daemon[1490]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.14' (uid=0 pid=1546 comm="/usr/sbin/NetworkManager --no-daemon" label="unconfined")
Mar 14 22:15:16.557609 ubuntu NetworkManager[1546]: <info>  [1678832116.5575] settings: Loaded settings plugin: ifupdown ("/usr/lib/x86_64-linux-gnu/NetworkManager/1.40.12/libnm-settings-plugin-ifupdown.so")
Mar 14 22:15:16.557936 ubuntu NetworkManager[1546]: <info>  [1678832116.5579] settings: Loaded settings plugin: keyfile (internal)
Mar 14 22:15:16.558552 ubuntu NetworkManager[1546]: <info>  [1678832116.5585] ifupdown: management mode: unmanaged
Mar 14 22:15:16.558849 ubuntu NetworkManager[1546]: <info>  [1678832116.5588] ifupdown: interfaces file /etc/network/interfaces doesn't exist
Mar 14 22:15:16.562187 ubuntu NetworkManager[1546]: <info>  [1678832116.5621] dhcp: init: Using DHCP client 'internal'
Mar 14 22:15:16.562326 ubuntu NetworkManager[1546]: <info>  [1678832116.5623] device (lo): carrier: link connected
Mar 14 22:15:16.562921 ubuntu NetworkManager[1546]: <info>  [1678832116.5629] manager: (lo): new Generic device (/org/freedesktop/NetworkManager/Devices/1)
Mar 14 22:15:16.565623 ubuntu NetworkManager[1546]: <info>  [1678832116.5656] manager: (enp1s0): new Ethernet device (/org/freedesktop/NetworkManager/Devices/2)
Mar 14 22:15:16.566802 ubuntu NetworkManager[1546]: <info>  [1678832116.5667] device (enp1s0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
# enp1s0 Link is finally UP
Mar 14 22:15:16.567801 ubuntu systemd-networkd[1445]: enp1s0: Link UP
Mar 14 22:15:16.567808 ubuntu systemd-networkd[1445]: enp1s0: Gained carrier
Mar 14 22:15:16.576312 ubuntu systemd[1]: Starting NetworkManager-dispatcher.service - Network Manager Script Dispatcher Service...
Mar 14 22:15:16.593064 ubuntu NetworkManager[1546]: <info>  [1678832116.5930] failed to open /run/network/ifstate
Mar 14 22:15:16.594050 ubuntu systemd[1]: Started NetworkManager-dispatcher.service - Network Manager Script Dispatcher Service.
Mar 14 22:15:16.603054 ubuntu NetworkManager[1546]: <info>  [1678832116.6029] modem-manager: ModemManager available
# NM sees link is connected
Mar 14 22:15:16.603995 ubuntu NetworkManager[1546]: <info>  [1678832116.6038] device (enp1s0): carrier: link connected
Mar 14 22:15:16.605979 ubuntu NetworkManager[1546]: <info>  [1678832116.6059] device (enp1s0): state change: unavailable -> disconnected (reason 'carrier-changed', sys-iface-state: 'managed')
Mar 14 22:15:16.615688 ubuntu NetworkManager[1546]: <info>  [1678832116.6156] policy: auto-activating connection 'netplan-enp1s0' (cac41fbe-bc18-3d87-bba7-af2af7f8ffab)
Mar 14 22:15:16.616090 ubuntu NetworkManager[1546]: <info>  [1678832116.6160] device (enp1s0): Activation: starting connection 'netplan-enp1s0' (cac41fbe-bc18-3d87-bba7-af2af7f8ffab)
Mar 14 22:15:16.616159 ubuntu NetworkManager[1546]: <info>  [1678832116.6161] device (enp1s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Mar 14 22:15:16.616301 ubuntu NetworkManager[1546]: <info>  [1678832116.6162] manager: NetworkManager state is now CONNECTING
Mar 14 22:15:16.616404 ubuntu NetworkManager[1546]: <info>  [1678832116.6163] device (enp1s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Mar 14 22:15:16.616904 ubuntu NetworkManager[1546]: <info>  [1678832116.6168] device (enp1s0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Mar 14 22:15:16.617119 ubuntu NetworkManager[1546]: <info>  [1678832116.6171] dhcp4 (enp1s0): activation: beginning transaction (timeout in 45 seconds)
Mar 14 22:15:18.020005 ubuntu avahi-daemon[1489]: Joining mDNS multicast group on interface enp1s0.IPv6 with address fe80::5054:ff:fe5b:bad5.
Mar 14 22:15:18.020209 ubuntu systemd-networkd[1445]: enp1s0: Gained IPv6LL
Mar 14 22:15:18.020103 ubuntu avahi-daemon[1489]: New relevant interface enp1s0.IPv6 for mDNS.
Mar 14 22:15:18.020113 ubuntu avahi-daemon[1489]: Registering new address record for fe80::5054:ff:fe5b:bad5 on enp1s0.*.
Mar 14 22:15:19.622278 ubuntu NetworkManager[1546]: <info>  [1678832119.6222] dhcp4 (enp1s0): state changed new lease, address=192.168.122.87
Mar 14 22:15:19.622596 ubuntu NetworkManager[1546]: <info>  [1678832119.6225] policy: set 'netplan-enp1s0' (enp1s0) as default for IPv4 routing and DNS
Mar 14 22:15:19.623291 ubuntu avahi-daemon[1489]: Joining mDNS multicast group on interface enp1s0.IPv4 with address 192.168.122.87.
Mar 14 22:15:19.623380 ubuntu avahi-daemon[1489]: New relevant interface enp1s0.IPv4 for mDNS.
Mar 14 22:15:19.623395 ubuntu avahi-daemon[1489]: Registering new address record for 192.168.122.87 on enp1s0.IPv4.
Mar 14 22:15:19.628244 ubuntu systemd-resolved[1136]: enp1s0: Bus client set default route setting: yes
Mar 14 22:15:19.630090 ubuntu systemd-resolved[1136]: enp1s0: Bus client set DNS server list to: 192.168.122.1
Mar 14 22:15:19.630505 ubuntu NetworkManager[1546]: <info>  [1678832119.6304] device (enp1s0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Mar 14 22:15:19.632315 ubuntu NetworkManager[1546]: <info>  [1678832119.6322] device (enp1s0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Mar 14 22:15:19.632447 ubuntu NetworkManager[1546]: <info>  [1678832119.6324] device (enp1s0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Mar 14 22:15:19.632671 ubuntu NetworkManager[1546]: <info>  [1678832119.6326] manager: NetworkManager state is now CONNECTED_SITE
Mar 14 22:15:19.632846 ubuntu NetworkManager[1546]: <info>  [1678832119.6328] device (enp1s0): Activation: successful, device activated.
Mar 14 22:15:19.633170 ubuntu NetworkManager[1546]: <info>  [1678832119.6331] manager: startup complete
Mar 14 22:15:19.637543 ubuntu systemd[1]: Finished NetworkManager-wait-online.service - Network Manager Wait Online.
Mar 14 22:15:19.863983 ubuntu NetworkManager[1546]: <info>  [1678832119.8639] manager: NetworkManager state is now CONNECTED_GLOBAL
Mar 14 22:15:29.879294 ubuntu systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Mar 14 22:15:56.584613 ubuntu NetworkManager[1546]: <info>  [1678832156.5845] agent-manager: agent[c06ac3176022f796,:1.47/org.gnome.Shell.NetworkAgent/1000]: agent registered

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to systemd in Ubuntu.
https://bugs.launchpad.net/bugs/2008952

Title:
  DNS failure while trying to fetch user-data

Status in cloud-init:
  Triaged
Status in netplan:
  Invalid
Status in subiquity:
  New
Status in systemd package in Ubuntu:
  New

Bug description:
  In testing netboot + autoinstall of the new ubuntu desktop subiquity
  based installer for 23.04 I found cloud-init is failing to retrieve
  user-data because it can't resolved the hostname in the URL.  This
  same configuration does work for 22.04 based subiquity, so seems a
  regression.

  From the ipxe config:

  imgargs vmlinuz initrd=initrd \
   ip=dhcp \
   iso-url=http://cdimage.ubuntu.com/daily-live/pending/lunar-desktop-amd64.iso \
   fsck.mode=skip \
   layerfs-path=minimal.standard.live.squashfs \
   autoinstall \
   'ds=nocloud-net;s=http://boot.linuxgroove.com/ubuntu/23.04/' \

  That fails, but if we replace boot.linuxgroove.com with the IP it
  works.

To manage notifications about this bug go to:
https://bugs.launchpad.net/cloud-init/+bug/2008952/+subscriptions

More information about the foundations-bugs mailing list