yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1873667] [NEW] NoCloud/network misordering network tasks

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Amine KHERBOUCHE <1873667@xxxxxxxxxxxxxxxxxx>
Date: Sun, 19 Apr 2020 15:32:55 -0000
Reply-to: Bug 1873667 <1873667@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Hello, I'm using the NoCloud data source to spawn a ubuntu cloud image
locally with KVM. Unfortunattely the network configuration fails because
cloud-init pre-networking tasks try to find and match some netdevs but
fails because the netdevs aren't yet available in udev/kernel. So Here
is my configurations

# cat nocloud/meta-data
dsmode: local
instance-id: 2
local-hostname: vm1
public-keys:
  - ssh-rsa AAAAB3NzaC1yc2EA....

# cat nocloud/user-data
#cloud-config
password: pass
chpasswd: { expire: False }
ssh_pwauth: True

cat nocloud/network-config
---
version: 2
ethernets:
  ens2:
    match:
      macaddress: 52:54:00:10:00:02
    set-name: ens2
    dhcp4: false
    addresses:
      - 172.16.0.2/24
    gateway4: 172.16.0.1
    nameservers:
      addresses: [1.1.1.1]
routes:
 - to: 0.0.0.0/0
   via: 172.16.0.1

Then I generate a seed iso file with:
# cloud-localds -N nocloud/network-config /var/lib/libvirt/qemu/images/${NAME}_seed.iso nocloud/user-data nocloud/meta-data

After then I boot my cloud IMG with the following cmd:
# virt-install -n vm1 \
    -r 2048 \
    --disk /var/lib/libvirt/qemu/images/vm1.img,format=qcow2,bus=virtio \
    --disk path=/var/lib/libvirt/qemu/images/vm1_seed.iso,device=cdrom,format=raw \
    --vcpus 2 \
    --network network=mgmt,model=virtio,mac=52:54:00:10:00:02 \
   --console pty,target_type=serial \
   --graphics none \
   --os-type Linux \
   --virt-type kvm

The boot process starts and fails in at:
Starting Initial cloud-init job (pre-networking)...
[   10.576931] cloud-init[505]: Cloud-init v. 19.4-33-gbb4131a2-0ubuntu1~19.10.1 running 'init-local' at Sun, 19 Apr 2020 14:58:04 +0000. Up 10.25 seconds.
[   10.596843] cloud-init[505]: 2020-04-19 14:58:04,934 - __init__.py[WARNING]: Not all expected physical devices present: {41135076002}
[   10.610726] cloud-init[505]: 2020-04-19 14:58:04,934 - util.py[WARNING]: failed stage init-local
[   10.621881] cloud-init[505]: failed run of stage init-local
[   10.628546] cloud-init[505]: ------------------------------------------------------------
[   10.637686] cloud-init[505]: Traceback (most recent call last):
[   10.645067] cloud-init[505]:   File "/usr/lib/python3/dist-packages/cloudinit/cmd/main.py", line 653, in status_wrapper
[   10.656896] cloud-init[FAILED] Failed to start Initial cloud-init job (pre-networking).
See 'systemctl status cloud-init-local.service' for details.
[  OK  ] Reached target Network (Pre).
         Starting Network Service...
[505]:     ret = functor(name, args)
[   10.685958] cloud-init[505]:   File "/usr/lib/python3/dist-packages/cloudinit/cmd/main.py", line 362, in main_init
[   10.696814] cloud-init[505]:     init.apply_network_config(bring_up=bool(mode != sources.DSMODE_LOCAL))
[   10.707178] cloud-init[505]:   File "/usr/lib/python3/dist-packages/cloudinit/stages.py", line 701, in apply_network_config
[   10.720032] cloud-init[505]:     net.wait_for_physdevs(netcfg)
[   10.727486] cloud-init[505]:   File "/usr/lib/python3/dist-packages/cloudinit/net/__init__.py", line 545, in wait_for_physdevs
[   10.739150] cloud-init[505]:     raise RuntimeError(msg)
[   10.745586] cloud-init[505]: RuntimeError: Not all expected physical devices present: {41135076002}
[   10.753007] cloud-init[505]: ------------------------------------------------------------
[  OK  ] Started Network Service.
         Starting Wait for Network to be Configured...
         Starting Network Name Resolution...
[  OK  ] Started Wait for Network to be Configured.
         Starting Initial cloud-ini… (metadata service crawler)...
[  OK  ] Started Network Name Resolution.
[  OK  ] Reached target Network.
[  OK  ] Reached target Host and Network Name Lookups.

Then cloud-init detects the available interfaces:
[   11.723035] cloud-init[532]: Cloud-init v. 19.4-33-gbb4131a2-0ubuntu1~19.10.1 running 'init' at Sun, 19 Apr 2020 14:58:05 +0000. Up 11.62 seconds.
[   11.740394] cloud-init[532]: ci-info: +++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++++
[   11.749182] cloud-init[532]: ci-info: +--------+-------+-----------+-----------+-------+-------------------+
[   11.757170] cloud-init[532]: ci-info: | Device |   Up  |  Address  |    Mask   | Scope |     Hw-Address    |
[   11.765835] cloud-init[532]: ci-info: +--------+-------+-----------+-----------+-------+-------------------+
[   11.775842] cloud-init[532]: ci-info: |  ens2  | False |     .     |     .     |   .   | 52:54:00:10:00:02 |
[   11.785441] cloud-init[532]: ci-info: |   lo   |  True | 127.0.0.1 | 255.0.0.0 |  host |         .         |
[   11.794634] cloud-init[532]: ci-info: |   lo   |  True |  ::1/128  |     .     |  host |         .         |
[   11.805821] cloud-init[532]: ci-info: +--------+-------+-----------+-----------+-------+-------------------+
[   11.815098] cloud-init[532]: ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++
[   11.823037] cloud-init[532]: ci-info: +-------+-------------+---------+-----------+-------+
[   11.829430] cloud-init[532]: ci-info: | Route | Destination | Gateway | Interface | Flags |
[   11.834809] cloud-init[532]: ci-info: +-------+-------------+---------+-----------+-------+
[   11.841174] cloud-init[532]: ci-info: +-------+-------------+---------+-----------+-------+
[  OK  ] Started Initial cloud-init…ob (metadata service crawler).
[  OK  ] Reached target Cloud-config availability.
[  OK  ] Reached target Network is Online.
         Starting Availability of block devices...
...


So clearly the pre-networking task is trying to match the configuration given in network-config file with the existing (not existing yet netdevs) configuration. Then cloud-init detects the net devices and displays them.
So I'm I missing something else in the configuration or it's just a resynchronization in the network configuration steps??

NB: I tested the 18.04 and 19.04 releases and It's the same behavior
since the version of cloud init is the same v19.4

Can you please tell me where is the issue?

Another thing, the user configuration when using dsmode: local is not set, I have the following error:
[   78.312233] cloud-init[1423]: Cloud-init v. 19.4-33-gbb4131a2-0ubuntu1~19.10.1 running 'modules:config' at Sun, 19 Apr 2020 14:59:12 +0000. Up 77.69 seconds.
[  OK  ] Started Apply the settings specified in cloud-config.
         Starting Execute cloud user/final scripts...
[   78.882740] cloud-init[1439]: Cloud-init v. 19.4-33-gbb4131a2-0ubuntu1~19.10.1 running 'modules:final' at Sun, 19 Apr 2020 14:59:13 +0000. Up 78.77 seconds.
[   78.887238] cloud-init[1439]: 2020-04-19 14:59:13,239 - util.py[WARNING]: Running module ssh-authkey-fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ssh_authkey_fingerprints.py'>) failed
<14>Apr 19 14:59:13 ec2:
<14>Apr 19 14:59:13 ec2: #############################################################
<14>Apr 19 14:59:13 ec2: -----BEGIN SSH HOST KEY FINGERPRINTS-----
<14>Apr 19 14:59:13 ec2: -----END SSH HOST KEY FINGERPRINTS-----
<14>Apr 19 14:59:13 ec2: #############################################################
-----BEGIN SSH HOST KEY KEYS-----
-----END SSH HOST KEY KEYS-----
[   78.965802] cloud-init[1439]: Cloud-init v. 19.4-33-gbb4131a2-0ubuntu1~19.10.1 finished at Sun, 19 Apr 2020 14:59:13 +0000. Datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=local].  Up 78.95 seconds
[FAILED] Failed to start Execute cloud user/final scripts.


Which has not been seen on dsmode: net (the default one).


Best,

Amine

** Affects: cloud-init
     Importance: Undecided
         Status: New


** Tags: network-config networking nocloud

** Summary changed:

- NoCloud race condition on expected physical
+ NoCloud/network misordering network tasks

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to cloud-init.
https://bugs.launchpad.net/bugs/1873667

Title:
  NoCloud/network misordering network tasks

Status in cloud-init:
  New

Bug description:
  Hello, I'm using the NoCloud data source to spawn a ubuntu cloud image
  locally with KVM. Unfortunattely the network configuration fails
  because cloud-init pre-networking tasks try to find and match some
  netdevs but fails because the netdevs aren't yet available in
  udev/kernel. So Here is my configurations

  # cat nocloud/meta-data
  dsmode: local
  instance-id: 2
  local-hostname: vm1
  public-keys:
    - ssh-rsa AAAAB3NzaC1yc2EA....

  # cat nocloud/user-data
  #cloud-config
  password: pass
  chpasswd: { expire: False }
  ssh_pwauth: True

  cat nocloud/network-config
  ---
  version: 2
  ethernets:
    ens2:
      match:
        macaddress: 52:54:00:10:00:02
      set-name: ens2
      dhcp4: false
      addresses:
        - 172.16.0.2/24
      gateway4: 172.16.0.1
      nameservers:
        addresses: [1.1.1.1]
  routes:
   - to: 0.0.0.0/0
     via: 172.16.0.1

  Then I generate a seed iso file with:
  # cloud-localds -N nocloud/network-config /var/lib/libvirt/qemu/images/${NAME}_seed.iso nocloud/user-data nocloud/meta-data

  After then I boot my cloud IMG with the following cmd:
  # virt-install -n vm1 \
      -r 2048 \
      --disk /var/lib/libvirt/qemu/images/vm1.img,format=qcow2,bus=virtio \
      --disk path=/var/lib/libvirt/qemu/images/vm1_seed.iso,device=cdrom,format=raw \
      --vcpus 2 \
      --network network=mgmt,model=virtio,mac=52:54:00:10:00:02 \
     --console pty,target_type=serial \
     --graphics none \
     --os-type Linux \
     --virt-type kvm

  The boot process starts and fails in at:
  Starting Initial cloud-init job (pre-networking)...
  [   10.576931] cloud-init[505]: Cloud-init v. 19.4-33-gbb4131a2-0ubuntu1~19.10.1 running 'init-local' at Sun, 19 Apr 2020 14:58:04 +0000. Up 10.25 seconds.
  [   10.596843] cloud-init[505]: 2020-04-19 14:58:04,934 - __init__.py[WARNING]: Not all expected physical devices present: {41135076002}
  [   10.610726] cloud-init[505]: 2020-04-19 14:58:04,934 - util.py[WARNING]: failed stage init-local
  [   10.621881] cloud-init[505]: failed run of stage init-local
  [   10.628546] cloud-init[505]: ------------------------------------------------------------
  [   10.637686] cloud-init[505]: Traceback (most recent call last):
  [   10.645067] cloud-init[505]:   File "/usr/lib/python3/dist-packages/cloudinit/cmd/main.py", line 653, in status_wrapper
  [   10.656896] cloud-init[FAILED] Failed to start Initial cloud-init job (pre-networking).
  See 'systemctl status cloud-init-local.service' for details.
  [  OK  ] Reached target Network (Pre).
           Starting Network Service...
  [505]:     ret = functor(name, args)
  [   10.685958] cloud-init[505]:   File "/usr/lib/python3/dist-packages/cloudinit/cmd/main.py", line 362, in main_init
  [   10.696814] cloud-init[505]:     init.apply_network_config(bring_up=bool(mode != sources.DSMODE_LOCAL))
  [   10.707178] cloud-init[505]:   File "/usr/lib/python3/dist-packages/cloudinit/stages.py", line 701, in apply_network_config
  [   10.720032] cloud-init[505]:     net.wait_for_physdevs(netcfg)
  [   10.727486] cloud-init[505]:   File "/usr/lib/python3/dist-packages/cloudinit/net/__init__.py", line 545, in wait_for_physdevs
  [   10.739150] cloud-init[505]:     raise RuntimeError(msg)
  [   10.745586] cloud-init[505]: RuntimeError: Not all expected physical devices present: {41135076002}
  [   10.753007] cloud-init[505]: ------------------------------------------------------------
  [  OK  ] Started Network Service.
           Starting Wait for Network to be Configured...
           Starting Network Name Resolution...
  [  OK  ] Started Wait for Network to be Configured.
           Starting Initial cloud-ini… (metadata service crawler)...
  [  OK  ] Started Network Name Resolution.
  [  OK  ] Reached target Network.
  [  OK  ] Reached target Host and Network Name Lookups.

  Then cloud-init detects the available interfaces:
  [   11.723035] cloud-init[532]: Cloud-init v. 19.4-33-gbb4131a2-0ubuntu1~19.10.1 running 'init' at Sun, 19 Apr 2020 14:58:05 +0000. Up 11.62 seconds.
  [   11.740394] cloud-init[532]: ci-info: +++++++++++++++++++++++++++Net device info++++++++++++++++++++++++++++
  [   11.749182] cloud-init[532]: ci-info: +--------+-------+-----------+-----------+-------+-------------------+
  [   11.757170] cloud-init[532]: ci-info: | Device |   Up  |  Address  |    Mask   | Scope |     Hw-Address    |
  [   11.765835] cloud-init[532]: ci-info: +--------+-------+-----------+-----------+-------+-------------------+
  [   11.775842] cloud-init[532]: ci-info: |  ens2  | False |     .     |     .     |   .   | 52:54:00:10:00:02 |
  [   11.785441] cloud-init[532]: ci-info: |   lo   |  True | 127.0.0.1 | 255.0.0.0 |  host |         .         |
  [   11.794634] cloud-init[532]: ci-info: |   lo   |  True |  ::1/128  |     .     |  host |         .         |
  [   11.805821] cloud-init[532]: ci-info: +--------+-------+-----------+-----------+-------+-------------------+
  [   11.815098] cloud-init[532]: ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++
  [   11.823037] cloud-init[532]: ci-info: +-------+-------------+---------+-----------+-------+
  [   11.829430] cloud-init[532]: ci-info: | Route | Destination | Gateway | Interface | Flags |
  [   11.834809] cloud-init[532]: ci-info: +-------+-------------+---------+-----------+-------+
  [   11.841174] cloud-init[532]: ci-info: +-------+-------------+---------+-----------+-------+
  [  OK  ] Started Initial cloud-init…ob (metadata service crawler).
  [  OK  ] Reached target Cloud-config availability.
  [  OK  ] Reached target Network is Online.
           Starting Availability of block devices...
  ...

  
  So clearly the pre-networking task is trying to match the configuration given in network-config file with the existing (not existing yet netdevs) configuration. Then cloud-init detects the net devices and displays them.
  So I'm I missing something else in the configuration or it's just a resynchronization in the network configuration steps??

  NB: I tested the 18.04 and 19.04 releases and It's the same behavior
  since the version of cloud init is the same v19.4

  Can you please tell me where is the issue?

  Another thing, the user configuration when using dsmode: local is not set, I have the following error:
  [   78.312233] cloud-init[1423]: Cloud-init v. 19.4-33-gbb4131a2-0ubuntu1~19.10.1 running 'modules:config' at Sun, 19 Apr 2020 14:59:12 +0000. Up 77.69 seconds.
  [  OK  ] Started Apply the settings specified in cloud-config.
           Starting Execute cloud user/final scripts...
  [   78.882740] cloud-init[1439]: Cloud-init v. 19.4-33-gbb4131a2-0ubuntu1~19.10.1 running 'modules:final' at Sun, 19 Apr 2020 14:59:13 +0000. Up 78.77 seconds.
  [   78.887238] cloud-init[1439]: 2020-04-19 14:59:13,239 - util.py[WARNING]: Running module ssh-authkey-fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ssh_authkey_fingerprints.py'>) failed
  <14>Apr 19 14:59:13 ec2:
  <14>Apr 19 14:59:13 ec2: #############################################################
  <14>Apr 19 14:59:13 ec2: -----BEGIN SSH HOST KEY FINGERPRINTS-----
  <14>Apr 19 14:59:13 ec2: -----END SSH HOST KEY FINGERPRINTS-----
  <14>Apr 19 14:59:13 ec2: #############################################################
  -----BEGIN SSH HOST KEY KEYS-----
  -----END SSH HOST KEY KEYS-----
  [   78.965802] cloud-init[1439]: Cloud-init v. 19.4-33-gbb4131a2-0ubuntu1~19.10.1 finished at Sun, 19 Apr 2020 14:59:13 +0000. Datasource DataSourceNoCloud [seed=/dev/sr0][dsmode=local].  Up 78.95 seconds
  [FAILED] Failed to start Execute cloud user/final scripts.

  
  Which has not been seen on dsmode: net (the default one).

  
  Best,

  Amine

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

[Bug 1873667] Re: NoCloud/network misordering network tasks
From: Launchpad Bug Tracker, 2020-06-24